One of the reasons issue #243 was hard to track down was because it was NOT obvious what was going on. There was no obvious error about the variable being asked for didn't exist on the file. I don't think all of the output was flushed, so it was hard to tell even how far it got.
An example for #243 has this:
atm.log:
successfully initialized sdat
(shr_orb_params) ------ Computed Orbital Parameters ------
(shr_orb_params) Eccentricity = 1.670366E-02
(shr_orb_params) Obliquity (deg) = 2.343977E+01
(shr_orb_params) Obliquity (rad) = 4.091011E-01
(shr_orb_params) Long of perh(deg) = 1.028955E+02
(shr_orb_params) Long of perh(rad) = 4.937458E+00
(shr_orb_params) Long at v.e.(rad) = -3.247250E-02
(shr_orb_params) -----------------------------------------
(dshr_addfield_add) using stream field strm_Faxa_bcphidry for 2d Faxa_bcph
(dshr_addfield_add) using stream field strm_Faxa_bcphodry for 2d Faxa_bcph
(dshr_addfield_add) using stream field strm_Faxa_bcphiwet for 2d Faxa_bcph
(dshr_addfield_add) setting pointer for export state Faxa_bcph
(dshr_addfield_add) using stream field strm_Faxa_dstdry1 for 2d Faxa_dstdry
(dshr_addfield_add) using stream field strm_Faxa_dstdry2 for 2d Faxa_dstdry
(dshr_addfield_add) using stream field strm_Faxa_dstdry3 for 2d Faxa_dstdry
(dshr_addfield_add) using stream field strm_Faxa_dstdry4 for 2d Faxa_dstdry
(dshr_addfield_add) setting pointer for export state Faxa_dstdry
(dshr_addfield_add) using stream field strm_Faxa_dstwet1 for 2d Faxa_dstwet
(dshr_addfield_add) using stream field strm_Faxa_dstwet2 for 2d Faxa_dstwet
(dshr_addfield_add) using stream field strm_Faxa_dstwet3 for 2d Faxa_dstwet
(dshr_addfield_add) using stream field strm_Faxa_dstwet4 for 2d Faxa_dstwet
(dshr_addfield_add) setting pointer for export state Faxa_dstwet
(dshr_addfield_add) setting pointer for export state Faxa_lwdn
(dshr_addfield_add) using stream field strm_Faxa_ocphidry for 2d Faxa_ocph
(dshr_addfield_add) using stream field strm_Faxa_ocphodry for 2d Faxa_ocph
(dshr_addfield_add) using stream field strm_Faxa_ocphiwet for 2d Faxa_ocph
(dshr_addfield_add) setting pointer for export state Faxa_ocph
(dshr_addfield_add) setting pointer for export state Faxa_rainc
(dshr_addfield_add) setting pointer for export state Faxa_rainl
(dshr_addfield_add) setting pointer for export state Faxa_snowc
(dshr_addfield_add) setting pointer for export state Faxa_snowl
(dshr_addfield_add) setting pointer for export state Faxa_swdn
(dshr_addfield_add) setting pointer for export state Faxa_swndf
(dshr_addfield_add) setting pointer for export state Faxa_swndr
(dshr_addfield_add) setting pointer for export state Faxa_swnet
(dshr_addfield_add) setting pointer for export state Faxa_swvdf
(dshr_addfield_add) setting pointer for export state Faxa_swvdr
(dshr_addfield_add) setting pointer for export state Sa_dens
(dshr_addfield_add) setting pointer for export state Sa_pbot
(dshr_addfield_add) setting pointer for export state Sa_pslv
(dshr_addfield_add) setting pointer for export state Sa_ptem
(dshr_addfield_add) setting pointer for export state Sa_shum
cesm.log:
Without DEBUG on, not much showed up.
With DEBUG on ...
Completion(send) value=1 tag=1
Completion(send) value=1 tag=2
Completion(send) value=1 tag=3
Completion(send) value=1 tag=4
Completion(send) value=0 tag=1
Completion(send) value=0 tag=2
Completion(send) value=0 tag=3
Completion(send) value=0 tag=4
Abort with message NetCDF: Variable not found in file /glade/scratch/vanderwb/hpci-stack/221216-1550/10797/pio-2.5.10/src/clib/pio_nc.c at line 1164
Obtained 10 stack frames.
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0x11b8513]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0x11b8617]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0x11b89a2]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0x11b8764]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe(PIOc_inq_varid+0x315) [0x11d8a5c]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0x11609dd]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0x1160a88]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0xfe7f82]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0xfeb5d0]
/glade/scratch/erik/SMS_Ld12_Mmpi-serial.1x1_urbanc_alpha.I1PtClm50SpRs.cheyenne_gnu.clm-output_sp_highfreq.GC.ctsm51d12552chlist/bld/cesm.exe() [0xff1ac6]
Program received signal SIGABRT: Process abort signal.
Backtrace for this error:
#0 0x2afd9890831f in ???
at /usr/src/debug/glibc-2.22/signal/../sysdeps/unix/sysv/linux/x86_64/sigaction.c:0
#1 0x2afd989082a7 in __GI_raise
at ../sysdeps/unix/sysv/linux/raise.c:55
#2 0x2afd98909679 in __GI_abort
at /usr/src/debug/glibc-2.22/stdlib/abort.c:78
#3 0x11b861b in piodie
at /glade/scratch/vanderwb/hpci-stack/221216-1550/10797/pio-2.5.10/src/clib/pioc_support.c:561
#4 0x11b89a1 in check_netcdf2
at /glade/scratch/vanderwb/hpci-stack/221216-1550/10797/pio-2.5.10/src/clib/pioc_support.c:683
#5 0x11b8763 in check_netcdf
at /glade/scratch/vanderwb/hpci-stack/221216-1550/10797/pio-2.5.10/src/clib/pioc_support.c:632
#6 0x11d8a5b in PIOc_inq_varid
at /glade/scratch/vanderwb/hpci-stack/221216-1550/10797/pio-2.5.10/src/clib/pio_nc.c:1164
#7 0x11609dc in __pio_nf_MOD_inq_varid_id
at /glade/scratch/vanderwb/hpci-stack/221216-1550/10797/pio-2.5.10/src/flib/pio_nf.F90:1582
#8 0x1160a87 in __pio_nf_MOD_inq_varid_desc
at /glade/scratch/vanderwb/hpci-stack/221216-1550/10797/pio-2.5.10/src/flib/pio_nf.F90:1543
#9 0xfe7f81 in shr_strdata_readstrm
at /glade/work/erik/ctsm_worktrees/ctsm5.2.mksurfdata/components/cdeps/streams/dshr_strdata_mod.F90:1551
#10 0xfeb5cf in shr_strdata_readlbub
at /glade/work/erik/ctsm_worktrees/ctsm5.2.mksurfdata/components/cdeps/streams/dshr_strdata_mod.F90:1370
#11 0xff1ac5 in __dshr_strdata_mod_MOD_shr_strdata_advance
at /glade/work/erik/ctsm_worktrees/ctsm5.2.mksurfdata/components/cdeps/streams/dshr_strdata_mod.F90:934
#12 0x55e01a in datm_comp_run
at /glade/work/erik/ctsm_worktrees/ctsm5.2.mksurfdata/components/cdeps/datm/atm_comp_nuopc.F90:659
#13 0x55f7f0 in initializerealize
at /glade/work/erik/ctsm_worktrees/ctsm5.2.mksurfdata/components/cdeps/datm/atm_comp_nuopc.F90:463
So there is an error in PIO that says a variable was not found. But, it's not obvious from which file, or what variable couldn't be read. And I'm not sure I even saw the PIO error at first when I looked at this.
One of the reasons issue #243 was hard to track down was because it was NOT obvious what was going on. There was no obvious error about the variable being asked for didn't exist on the file. I don't think all of the output was flushed, so it was hard to tell even how far it got.
An example for #243 has this:
atm.log:
cesm.log:
Without DEBUG on, not much showed up.
With DEBUG on ...
So there is an error in PIO that says a variable was not found. But, it's not obvious from which file, or what variable couldn't be read. And I'm not sure I even saw the PIO error at first when I looked at this.