jedwards4b
commented
5 years ago I'm not sure what happens if you initialize gptl twice - is that going to be a problem?
Closed edhartnett closed 5 years ago
jedwards4b
commented
5 years ago I'm not sure what happens if you initialize gptl twice - is that going to be a problem?
edhartnett
commented
5 years ago 
edhartnett
commented
5 years ago To answer your question, GPTL helpfully segfaults when initialized twice:
GPTL error:GPTLinitialize: has already been called
GPTL error:GPTLinitialize: has already been called
GPTL error:GPTLinitialize: has already been called
GPTL error:GPTLinitialize: has already been called
Obtained 10 stack frames.
./pioperf(+0x3fb0d) [0x55ad40e50b0d]
./pioperf(+0x40213) [0x55ad40e51213]
./pioperf(+0x35c84) [0x55ad40e46c84]
./pioperf(+0x3c42f) [0x55ad40e4d42f]
./pioperf(+0x2209f) [0x55ad40e3309f]
./pioperf(+0x2185e) [0x55ad40e3285e]
./pioperf(+0xa370) [0x55ad40e1b370]
Obtained 10 stack frames.
./pioperf(+0x3fb0d) [0x559ee2069b0d]GPTL has many, many issues. I had hoped to transition it to modern development practices and then resolve the issues, but apparently that exceeds my powers of persuasion and diplomacy. And every interaction I have with GPTL makes me more annoyed with it.
Does it really provide superior timing to just using MPI_time?
edhartnett
commented
5 years ago OK, I can eliminate this in all the C code, but it won't help, because you guys are calling GPTL_initialize() from your model code, and then calling PIO. So if PIO then calls GPTL_initialize() it will print obnoxious error messages to console and crash or exit. So that blows.
There are four ways forward that I can see: 1 - learn to live with it. 2 - remove GPTL entirely from PIO. 3 - fix the external GPTL. 4 - ignore the external GPTL and use the one in the GPTL directory only. Make changes there to fix problems and abandon the idea of every using the externally maintained GPTL library.
Option 1 is just not me. Software teams insterested in learning to live with imperfections in the code should not involve me on their projects.
Option 2 would be easiest, if CESM does not rely on GPTL being used in PIO. I have already spent about 10 times as much effort dealing with GPTL than it would to add some simple timer code to replace it.
Option 3 has already been attempted, but is not working out.
Option 4 would be the most work, and would require that we keep all that GPTL code in our codebase, as well as wade into it and start fixing things. Seems like even option 1 is better than that.
jedwards4b
commented
5 years ago I'm okay with replacing gptl in pio. Option 2.
edhartnett
commented
5 years ago OK, what does GPTL do with the times it measures. Does it print them out somewhere? Can you send me the output or tell me how to find it so I know what the timer code should do?
jedwards4b
commented
5 years ago Here is a typical result from cesm. I'm not sure how you could emulate this without gptl
************ PROCESS 0 ( 0) ************
$Id: gptl.c,v 1.157 2011-03-28 20:55:18 rosinski Exp $
GPTL was built without threading
HAVE_MPI was true
HAVE_COMM_F2C was true
ENABLE_PMPI was false
HAVE_PAPI was false
Underlying timing routine was MPI_Wtime.
Per-call utr overhead est: 2.5242e-08 sec.
If overhead stats are printed, roughly half the estimated number is
embedded in the wallclock stats for each timer.
Print method was most_frequent.
If a '%_of' field is present, it is w.r.t. the first timer for thread 0.
If a 'e6_per_sec' field is present, it is in millions of PAPI counts per sec.
A '*' in column 1 below means the timer had multiple parents, though the
values printed are for all calls.
Further down the listing may be more detailed information about multiple
parents. Look for 'Multiple parent info'
Stats for thread 0:
On Called Recurse Wallclock max min UTR Overhead
"CPL:INIT" - 1 - 126.039558 125.737663 0.301900 0.000000
"CPL:cime_pre_init1" - 1 - 0.183600 0.183600 0.183600 0.000000
"CPL:ESMF_Initialize" - 1 - 0.000000 0.000000 0.000000 0.000000
"CPL:cime_pre_init2" - 1 - 0.118300 0.118300 0.118300 0.000000
"CPL:cime_init" - 1 - 125.737640 125.737640 125.737640 0.000000
"CPL:init_comps" - 1 - 116.780136 116.780136 116.780136 0.000000
"CPL:comp_init_pre_all" - 1 - 0.006979 0.006979 0.006979 0.000000
"CPL:comp_init_cc_atm" - 1 - 18.235235 18.235235 18.235235 0.000000
"a_i:phys_grid_init" - 1 - 0.067827 0.067827 0.067827 0.000000
"CPL:comp_init_cc_lnd" - 1 - 85.048950 85.048950 85.048950 0.000000
"CPL:comp_init_cc_rof" - 1 - 0.772774 0.772774 0.772774 0.000000
"CPL:comp_init_cc_ocn" - 1 - 10.663101 10.663101 10.663101 0.000000
"CPL:comp_init_cc_ice" - 1 - 0.618488 0.618488 0.618488 0.000000
"CPL:comp_init_cc_glc" - 1 - 0.925998 0.925998 0.925998 0.000000
"CPL:comp_init_cc_wav" - 1 - 0.252743 0.252743 0.252743 0.000000
"CPL:comp_init_cc_esp" - 1 - 0.000112 0.000112 0.000112 0.000000
"CPL:comp_init_cx_all" - 1 - 0.255713 0.255713 0.255713 0.000000
"CPL:comp_list_all" - 1 - 0.000003 0.000003 0.000003 0.000000
"CPL:init_maps" - 1 - 4.068587 4.068587 4.068587 0.000000
"CPL:init_aream" - 1 - 0.255870 0.255870 0.255870 0.000000
"CPL:init_domain_check" - 1 - 0.009470 0.009470 0.009470 0.000000
"CPL:init_areacor" - 1 - 0.021354 0.021354 0.021354 0.000000
"CPL:init_fracs" - 1 - 0.008375 0.008375 0.008375 0.000000
"CPL:init_aoflux" - 1 - 0.000102 0.000102 0.000102 0.000000
"CPL:init_atminit" - 6 - 0.002521 0.001295 0.000113 0.000000
"CPL:comp_init_cc_atm2" - 1 - 4.562752 4.562752 4.562752 0.000000
"CPL:init_readrestart" - 1 - 0.000127 0.000127 0.000127 0.000000
"CPL:init_rof2ocn" - 1 - 0.007688 0.007688 0.007688 0.000000
"CPL:init_rof2lnd" - 1 - 0.000618 0.000618 0.000618 0.000000
"CPL:init_gllndnd" - 1 - 0.013970 0.013970 0.013970 0.000000
"CPL:RUN_LOOP_BSTART" - 1 - 0.001886 0.001886 0.001886 0.000000
"CPL:RUN_LOOP" - 960 - 585.163818 7.466401 0.511398 0.000048
"CPL:CLOCK_ADVANCE" - 960 - 0.100442 0.002525 0.000090 0.000048
"CPL:RUN" - 18598 - 12.432140 0.174661 0.000001 0.000939
"CPL:OCNPRE1" - 960 - 0.348239 0.000456 0.000346 0.000048
"CPL:ocnpre1_atm2ocn" - 960 - 0.347127 0.000455 0.000345 0.000048
"CPL:ATMOCN1" - 960 - 7.745967 0.174660 0.000387 0.000048
"CPL:atmocnp_ice2ocn" - 960 - 0.024159 0.000044 0.000021 0.000048
"CPL:atmocnp_wav2ocn" - 960 - 7.472805 0.174367 0.000101 0.000048
"CPL:atmocnp_fluxo" - 960 - 0.013357 0.000280 0.000011 0.000048
"CPL:atmocnp_mrgx2o" - 960 - 0.108145 0.002255 0.000090 0.000048
"CPL:atmocnp_accum" - 960 - 0.061942 0.000121 0.000030 0.000048
"CPL:atmocnp_ocnalb" - 960 - 0.017225 0.000045 0.000004 0.000048
* "CPL:BUDGET" - 4800 - 0.177724 0.000276 0.000006 0.000242
"CPL:BUDGET1" - 960 - 0.052373 0.000150 0.000049 0.000048
"CPL:BUDGET2" - 960 - 0.052846 0.000102 0.000030 0.000048
"CPL:BUDGET3" - 960 - 0.019392 0.000042 0.000007 0.000048
"CPL:BUDGETF" - 960 - 0.008343 0.000275 0.000005 0.000048
"CPL:LNDPREP" - 960 - 0.037479 0.000289 0.000025 0.000048
"CPL:lndprep_atm2lnd" - 960 - 0.018272 0.000034 0.000015 0.000048
"CPL:lndprep_mrgx2l" - 960 - 0.017213 0.000268 0.000008 0.000048
"CPL:ICEPREP" - 960 - 0.114373 0.001266 0.000068 0.000048
"CPL:iceprep_ocn2ice" - 960 - 0.023085 0.000686 0.000015 0.000048
"CPL:iceprep_atm2ice" - 960 - 0.029121 0.000359 0.000018 0.000048
"CPL:iceprep_mrgx2i" - 960 - 0.055835 0.000216 0.000031 0.000048
"CPL:WAVPREP" - 960 - 1.127999 0.001592 0.000869 0.000048
"CPL:wavprep_atm2wav" - 960 - 0.904829 0.001220 0.000196 0.000048
"CPL:wavprep_ocn2wav" - 960 - 0.060817 0.001005 0.000053 0.000048
"CPL:wavprep_ice2wav" - 960 - 0.156688 0.000346 0.000148 0.000048
"CPL:wavprep_mrgx2w" - 960 - 0.001897 0.000055 0.000001 0.000048
"CPL:ROFPREP" - 160 - 0.199999 0.002527 0.001073 0.000008
"CPL:rofprep_l2xavg" - 160 - 0.000176 0.000002 0.000000 0.000008
"CPL:rofprep_lnd2rof" - 160 - 0.198416 0.002480 0.001065 0.000008
"CPL:rofprep_mrgx2r" - 160 - 0.000974 0.000042 0.000004 0.000008
"CPL:LNDPOST" - 960 - 0.053594 0.000082 0.000027 0.000048
"CPL:lndpost_accl2r" - 960 - 0.019423 0.000038 0.000006 0.000048
"CPL:lndpost_accl2g" - 960 - 0.030460 0.000052 0.000016 0.000048
"CPL:ROFPOST" - 160 - 0.119872 0.001962 0.000512 0.000008
"CPL:rofpost_rof2lnd" - 160 - 0.034169 0.000778 0.000107 0.000008
"CPL:rofpost_rof2ocn" - 160 - 0.085065 0.001675 0.000392 0.000008
"DRIVER_ROFPOST" - 960 - 0.000224 0.000007 0.000000 0.000048
"CPL:ICEPOST" - 960 - 0.001041 0.000019 0.000000 0.000048
"CPL:FRACSET" - 960 - 0.090253 0.000163 0.000068 0.000048
"CPL:fracset_fracset" - 960 - 0.087635 0.000162 0.000067 0.000048
"CPL:ATMPREP" - 960 - 2.104540 0.008254 0.001680 0.000048
"CPL:atmprep_xao2atm" - 960 - 0.250181 0.000470 0.000251 0.000048
"CPL:atmprep_ocn2atm" - 960 - 0.166520 0.000329 0.000168 0.000048
"CPL:atmprep_alb2atm" - 960 - 0.110058 0.000217 0.000111 0.000048
"CPL:atmprep_ice2atm" - 960 - 0.289894 0.000370 0.000289 0.000048
"CPL:atmprep_lnd2atm" - 960 - 1.248575 0.007321 0.000513 0.000048
"CPL:atmprep_mrgx2a" - 960 - 0.033802 0.000065 0.000028 0.000048
"CPL:WAVPOST" - 960 - 0.000446 0.000017 0.000000 0.000048
"CPL:ATMPOST" - 960 - 0.000777 0.000018 0.000000 0.000048
"CPL:HISTORY" - 960 - 0.002427 0.000514 0.000001 0.000048
"CPL:TSTAMP_WRITE" - 960 - 0.040402 0.002042 0.000000 0.000048
"CPL:OCNPREP" - 479 - 0.013258 0.000055 0.000026 0.000024
"CPL:ocnprep_avg" - 479 - 0.012743 0.000054 0.000025 0.000024
"CPL:OCNPOST" - 479 - 0.000142 0.000007 0.000000 0.000024
"CPL:GLCPREP" - 20 - 0.000044 0.000007 0.000002 0.000001
"CPL:GLCPOST" - 20 - 0.279361 0.034178 0.008199 0.000001
"CPL:glcpost_glc2lnd" - 20 - 0.279296 0.034175 0.008197 0.000001
"CPL:COMM" - 8998 - 56.726631 6.774249 0.000023 0.000454
"CPL:C2L" - 960 - 1.111506 0.013464 0.000472 0.000048
"CPL:c2l_lndx2lndl" - 960 - 1.088076 0.013425 0.000455 0.000048
"CPL:c2l_infoexch" - 960 - 0.021304 0.000051 0.000012 0.000048
"CPL:C2I" - 960 - 0.065923 0.000093 0.000050 0.000048
"CPL:c2i_icex2icei" - 960 - 0.046326 0.000069 0.000034 0.000048
"CPL:ice_infoexch" - 960 - 0.017660 0.000030 0.000014 0.000048
"CPL:C2W" - 960 - 0.026716 0.000045 0.000026 0.000048
"CPL:c2w_wavx2wavw" - 960 - 0.012109 0.000024 0.000011 0.000048
"CPL:c2w_infoexch" - 960 - 0.013075 0.000021 0.000012 0.000048
"CPL:C2R" - 160 - 0.428707 0.005687 0.002027 0.000008
"CPL:c2r_rofx2rofr" - 160 - 0.424155 0.005668 0.002000 0.000008
"CPL:c2r_infoexch" - 160 - 0.004079 0.000054 0.000016 0.000008
"CPL:L2C" - 960 - 5.472944 0.023911 0.000094 0.000048
"CPL:l2c_lndl2lndx" - 960 - 5.467725 0.023904 0.000089 0.000048
"lnd2cpl_run" - 960 - 0.002614 0.000017 0.000002 0.000048
"CPL:R2C" - 160 - 0.335031 0.004410 0.001386 0.000008
"CPL:r2c_rofr2rofx" - 160 - 0.333880 0.004405 0.001380 0.000008
"CPL:r2c_infoexch" - 160 - 0.000580 0.000019 0.000002 0.000008
"CPL:I2C" - 960 - 33.728951 0.054610 0.001932 0.000048
"CPL:i2c_icei2icex" - 960 - 33.722496 0.054606 0.001921 0.000048
"CPL:i2c_infoexch" - 960 - 0.003265 0.000011 0.000002 0.000048
"CPL:C2A" - 960 - 0.668364 0.003505 0.000079 0.000048
"CPL:c2a_atmx2atmg" - 960 - 0.651004 0.003466 0.000061 0.000048
"CPL:c2a_infoexch" - 960 - 0.015752 0.000040 0.000013 0.000048
"CPL:W2C" - 960 - 0.859642 0.031587 0.000033 0.000048
"CPL:w2c_wavw2wavx" - 960 - 0.855196 0.031581 0.000029 0.000048
"CPL:w2c_infoexch" - 960 - 0.001976 0.000023 0.000002 0.000048
"CPL:A2C" - 960 - 6.653535 0.168428 0.000111 0.000048
"CPL:a2c_atma2atmx" - 960 - 6.630842 0.168415 0.000100 0.000048
"CPL:a2c_infoexch" - 960 - 0.019069 0.000054 0.000008 0.000048
"CPL:C2O" - 479 - 0.036914 0.000096 0.000066 0.000024
"CPL:c2o_ocnx2ocno" - 479 - 0.027645 0.000074 0.000047 0.000024
"CPL:c2o_infoexch" - 479 - 0.008445 0.000036 0.000016 0.000024
"CPL:O2C" - 479 - 7.137749 6.774246 0.000023 0.000024
"CPL:o2c_ocno2ocnx" - 479 - 7.134429 6.774236 0.000017 0.000024
"CPL:o2c_infoexch" - 479 - 0.001978 0.000010 0.000003 0.000024
"CPL:C2G" - 20 - 0.089721 0.005177 0.003149 0.000001
"CPL:c2g_glcx2glcg" - 20 - 0.089076 0.005129 0.003120 0.000001
"CPL:c2g_infoexch" - 20 - 0.000602 0.000046 0.000025 0.000001
"CPL:G2C" - 20 - 0.102462 0.021345 0.000078 0.000001
"CPL:g2c_glcg2glcx" - 20 - 0.102330 0.021340 0.000068 0.000001
"CPL:g2c_infoexch" - 20 - 0.000056 0.000007 0.000001 0.000001
"CPL:LND_RUN" - 960 - 43.036026 0.235975 0.042261 0.000048
"l:lc_lnd_import" - 960 - 0.037510 0.000081 0.000036 0.000048
"l:clm_run" - 961 - 42.714439 0.235639 0.041929 0.000049
"l:shr_orb_decl" - 961 - 0.002001 0.000011 0.000001 0.000049
"l:interpMonthlyVeg" - 961 - 0.194617 0.193335 0.000001 0.000049
"l:readMonthlyVeg" - 1 - 0.193265 0.193265 0.193265 0.000000
"l:PIO:PIO_openfile" - 1 - 0.016070 0.016070 0.016070 0.000000
"l:PIO:PIO_closefile" - 1 - 0.000001 0.000001 0.000001 0.000000
"l:decomp_vert" - 961 - 0.208356 0.000407 0.000181 0.000049
"l:cninit" - 961 - 0.241966 0.000387 0.000103 0.000049
"l:dyn_subgrid" - 961 - 0.879324 0.012660 0.000738 0.000049
"l:dyn_cnbal_patch" - 961 - 0.266957 0.003341 0.000244 0.000049
"l:CNUpdateDynPatch" - 961 - 0.072438 0.000187 0.000055 0.000049
"l:dyn_cnbal_col" - 961 - 0.096911 0.008599 0.000088 0.000049
"l:begwbal" - 961 - 0.027920 0.000046 0.000027 0.000049
"l:begcnbal_col" - 961 - 0.504994 0.000763 0.000392 0.000049
"l:bgc_interp" - 961 - 0.733396 0.043641 0.000043 0.000049
"l:ndepdyn_strd_adv_total" - 961 - 0.027028 0.002231 0.000016 0.000049
"l:ndepdyn_strd_adv_readLBUB" - 961 - 0.006923 0.001611 0.000003 0.000049
"l:ndepdyn_readLBUB_setup" - 961 - 0.001160 0.000003 0.000001 0.000049
"l:ndepdyn_readLBUB_filemgt" - 961 - 0.000171 0.000000 0.000000 0.000049
"l:ndepdyn_readLBUB_fbound" - 1 - 0.000005 0.000005 0.000005 0.000000
"l:ndepdyn_readLBUB_bcast" - 1 - 0.000022 0.000022 0.000022 0.000000
"l:ndepdyn_readLBUB_LB_copy" - 1 - 0.000002 0.000002 0.000002 0.000000
"l:ndepdyn_readLBUB_UB_setup" - 1 - 0.000100 0.000100 0.000100 0.000000
"l:ndepdyn_readLBUB_UB_readpio" - 1 - 0.001462 0.001462 0.001462 0.000000
"l:ndepdyn_strd_adv_tint" - 961 - 0.010838 0.000027 0.000006 0.000049
"l:ndepdyn_strd_adv_rearr" - 1 - 0.000606 0.000606 0.000606 0.000000
"l:hdmdyn_strd_adv_total" - 961 - 0.012919 0.000028 0.000010 0.000049
"l:hdmdyn_strd_adv_readLBUB" - 961 - 0.003444 0.000017 0.000002 0.000049
"l:hdmdyn_readLBUB_setup" - 961 - 0.000469 0.000014 0.000000 0.000049
"l:hdmdyn_readLBUB_filemgt" - 961 - 0.000159 0.000000 0.000000 0.000049
"l:hdmdyn_strd_adv_tint" - 961 - 0.005392 0.000010 0.000004 0.000049
"l:lnfmdyn_strd_adv_total" - 961 - 0.685074 0.043577 0.000009 0.000049
"l:lnfmdyn_strd_adv_readLBUB" - 961 - 0.372068 0.041726 0.000002 0.000049
"l:lnfmdyn_readLBUB_setup" - 961 - 0.000447 0.000002 0.000000 0.000049
"l:lnfmdyn_readLBUB_filemgt" - 961 - 0.000188 0.000001 0.000000 0.000049
"l:lnfmdyn_readLBUB_fbound" - 160 - 0.001172 0.000019 0.000004 0.000008
"l:lnfmdyn_readLBUB_bcast" - 160 - 0.004515 0.000041 0.000019 0.000008
"l:lnfmdyn_readLBUB_LB_copy" - 160 - 0.000198 0.000013 0.000001 0.000008
"l:lnfmdyn_readLBUB_UB_setup" - 160 - 0.018995 0.000164 0.000094 0.000008
"l:lnfmdyn_readLBUB_UB_readpio" - 160 - 0.341795 0.041535 0.001302 0.000008
* "l:PIO:pio_read_darray" - 169 - 0.277755 0.041322 0.000229 0.000009
"l:PIO:pio_read_nf" - 169 - 0.000210 0.000002 0.000000 0.000009
"l:PIO:pio_read_nfdarray_double" - 169 - 0.000060 0.000001 0.000000 0.000009
"l:PIO:pio_rearrange_read" - 169 - 0.276652 0.041319 0.000224 0.000009
"l:PIO:pio_rearrange_io2comp_double" - 169 - 0.276385 0.041318 0.000223 0.000009
"l:PIO:swapm_box_rear_io2comp_double" - 169 - 0.273644 0.041313 0.000205 0.000009
"l:lnfmdyn_strd_adv_tint" - 961 - 0.007000 0.000027 0.000004 0.000049
"l:lnfmdyn_strd_adv_map" - 160 - 0.301284 0.002690 0.001796 0.000008
"l:urbantvdyn_strd_adv_total" - 961 - 0.068941 0.000121 0.000067 0.000049
"l:urbantvdyn_strd_adv_readLBUB" - 961 - 0.002913 0.000011 0.000002 0.000049
"l:urbantvdyn_readLBUB_setup" - 961 - 0.000472 0.000008 0.000000 0.000049
"l:urbantvdyn_readLBUB_filemgt" - 961 - 0.000150 0.000000 0.000000 0.000049
"l:urbantvdyn_strd_adv_tint" - 961 - 0.062381 0.000110 0.000062 0.000049
"l:drvinit" - 961 - 0.073232 0.001249 0.000054 0.000049
"l:canhydro" - 961 - 0.141888 0.016746 0.000112 0.000049
"l:surfrad" - 961 - 0.260340 0.000399 0.000240 0.000049
"l:bgp1" - 961 - 0.201406 0.003084 0.000164 0.000049
"l:bgflux" - 961 - 0.225569 0.008075 0.000182 0.000049
"l:canflux" - 961 - 5.834229 0.020530 0.004682 0.000049
"l:can_iter" - 961 - 5.195718 0.015825 0.004071 0.000049
"l:LUNA" - 21 - 0.001390 0.000081 0.000027 0.000001
"l:uflux" - 961 - 0.115097 0.000392 0.000092 0.000049
"l:bgplake" - 961 - 0.036947 0.000057 0.000029 0.000049
"l:irrigationneeded" - 961 - 0.004590 0.000008 0.000004 0.000049
"l:bgc" - 961 - 0.150352 0.000208 0.000152 0.000049
"l:lakeTemp" - 961 - 0.140897 0.000188 0.000133 0.000049
"l:soiltemperature" - 961 - 2.581335 0.003484 0.002610 0.000049
"l:SoilThermProp" - 961 - 0.355748 0.000579 0.000361 0.000049
"l:SoilTempBandDiag" - 961 - 1.323218 0.001684 0.001346 0.000049
"l:PhaseChangeH2osfc" - 961 - 0.005079 0.000008 0.000003 0.000049
"l:PhaseChangebeta" - 961 - 0.196624 0.000379 0.000189 0.000049
"l:bgp2" - 961 - 0.157010 0.000243 0.000153 0.000049
"l:bgp2_loop_1" - 961 - 0.027138 0.000048 0.000026 0.000049
"l:bgp2_loop_2" - 961 - 0.033912 0.000088 0.000032 0.000049
"l:bgp2_loop_3" - 961 - 0.070546 0.000125 0.000069 0.000049
"l:bgp2_loop_4" - 961 - 0.018734 0.000049 0.000018 0.000049
"l:patch2col" - 961 - 0.028093 0.000054 0.000027 0.000049
"l:hydro_without_drainage" - 961 - 3.430780 0.004731 0.002949 0.000049
"l:hylake" - 961 - 0.139538 0.000248 0.000079 0.000049
"l:snow_init" - 961 - 0.098911 0.000199 0.000065 0.000049
"l:ecosysdyn" - 961 - 17.350626 0.019018 0.016831 0.000049
"l:CNZero" - 961 - 3.540478 0.004625 0.002775 0.000049
"l:CNDeposition" - 961 - 0.005556 0.000022 0.000002 0.000049
"l:CNFLivFixation" - 961 - 0.013276 0.000034 0.000004 0.000049
"l:CNMResp" - 961 - 0.157393 0.000546 0.000123 0.000049
"l:SoilBiogeochem" - 961 - 2.646341 0.003291 0.002266 0.000049
"l:CNDecompAlloc" - 961 - 3.765175 0.004620 0.003478 0.000049
"l:CNPhenology_phase1" - 961 - 0.100002 0.000172 0.000057 0.000049
"l:CNFUNInit" - 961 - 0.003335 0.000015 0.000001 0.000049
"l:calc_plant_nutrient_demand" - 961 - 0.102853 0.000192 0.000065 0.000049
"l:soilbiogeochemcompetition" - 961 - 3.276235 0.004045 0.002918 0.000049
"l:CNFUN" - 961 - 2.922903 0.003578 0.002567 0.000049
"l:CNFUNzeroarrays" - 961 - 0.292138 0.000642 0.000196 0.000049
"l:CNFUNcalcs1" - 961 - 0.120884 0.000214 0.000108 0.000049
"l:CNFUNzeroarrays2" - 961 - 0.164946 0.000424 0.000101 0.000049
"l:CNFUNcalcs" - 961 - 2.210668 0.002712 0.001930 0.000049
"l:calc_plant_nutrient_competition" - 961 - 0.276049 0.000428 0.000204 0.000049
"l:SoilBiogeochemDecomp" - 961 - 0.637395 0.000921 0.000457 0.000049
"l:CNPhenology" - 961 - 0.512104 0.000718 0.000493 0.000049
"l:CNGResp" - 961 - 0.027876 0.000064 0.000016 0.000049
"l:CNUpdate0" - 961 - 0.002599 0.000014 0.000001 0.000049
* "l:CNPrecisionControl" - 4805 - 0.265603 0.000105 0.000045 0.000243
"l:CNUpdate1" - 961 - 0.387338 0.000788 0.000293 0.000049
"l:SoilBiogeochemStateUpdate1" - 961 - 0.269172 0.000527 0.000193 0.000049
"l:SoilBiogeochemLittVertTransp" - 961 - 2.340466 0.002836 0.002322 0.000049
"l:CNGapMortality" - 961 - 0.947220 0.001266 0.000932 0.000049
"l:CNUpdate2" - 961 - 0.162492 0.000256 0.000137 0.000049
"l:CNWoodProducts" - 961 - 0.024519 0.000232 0.000021 0.000049
"l:CNFire" - 961 - 1.518904 0.002068 0.001475 0.000049
"l:CNUpdate3" - 961 - 0.106650 0.000162 0.000083 0.000049
"l:depvel" - 961 - 0.276773 0.000411 0.000264 0.000049
"l:hydro2_drainage" - 961 - 0.203861 0.000489 0.000166 0.000049
"l:EcosysDynPostDrainage" - 961 - 1.701970 0.002051 0.001505 0.000049
* "l:CNsum" - 2883 - 1.829643 0.001317 0.000348 0.000146
"l:SoilBiogeochemNLeaching" - 961 - 0.041156 0.000075 0.000033 0.000049
"l:NUpdate3" - 961 - 0.124033 0.000207 0.000096 0.000049
"l:SoilBiogeochemPrecisionControl" - 961 - 0.107116 0.000188 0.000082 0.000049
"l:balchk" - 961 - 0.043203 0.000096 0.000033 0.000049
"l:cnbalchk" - 961 - 0.010425 0.000094 0.000007 0.000049
"l:ch4" - 961 - 3.244078 0.003706 0.003234 0.000049
"l:lnd2atm" - 961 - 0.175991 0.000260 0.000161 0.000049
"l:lnd2glc" - 961 - 0.006189 0.000018 0.000005 0.000049
"l:wrtdiag" - 961 - 0.058308 0.000284 0.000028 0.000049
"l:hbuf" - 961 - 2.391965 0.002822 0.002321 0.000049
"l:endTSdynveg" - 961 - 0.000933 0.000008 0.000000 0.000049
"l:clm_drv_io" - 961 - 0.006562 0.000030 0.000005 0.000049
"l:clm_drv_io_htapes" - 961 - 0.005105 0.000029 0.000004 0.000049
"l:accum" - 960 - 0.137100 0.000334 0.000125 0.000048
"l:surfalb" - 480 - 0.551285 0.001285 0.001053 0.000024
"l:urbalb" - 480 - 0.019138 0.000064 0.000028 0.000024
"l:lc_lnd_export" - 961 - 0.037250 0.000069 0.000027 0.000049
"l:lc_clm2_adv_timestep" - 961 - 0.000904 0.000008 0.000001 0.000049
"l:check_fields" - 960 - 0.016801 0.000033 0.000017 0.000048
"CPL:ROF_RUN" - 160 - 2.494941 0.072392 0.011584 0.000008
"r:lc_rof_import" - 160 - 0.001515 0.000036 0.000006 0.000008
"r:mosartr_tot" - 160 - 2.454803 0.072133 0.011311 0.000008
* "r:mosartr_budget" - 507 - 0.014179 0.004039 0.000004 0.000026
"r:mosartr_irrig" - 160 - 0.000243 0.000009 0.000001 0.000008
"r:mosartr_flood" - 160 - 0.000396 0.000009 0.000002 0.000008
"r:mosartr_SMdirect" - 160 - 1.973667 0.061998 0.008844 0.000008
"r:mosartr_subcycling" - 160 - 0.452618 0.013585 0.002134 0.000008
"r:mosartr_euler" - 480 - 0.443593 0.011363 0.000560 0.000024
"r:mosartr_hillslope" - 480 - 0.004637 0.000035 0.000004 0.000024
"r:mosartr_subnetwork" - 2400 - 0.057796 0.000047 0.000009 0.000121
"r:mosartr_SMeroutUp" - 2400 - 0.220441 0.010623 0.000040 0.000121
"r:mosartr_chanroute" - 2400 - 0.147140 0.000304 0.000041 0.000121
"r:mosartr_hbuf" - 160 - 0.007553 0.000077 0.000028 0.000008
"r:mosartr_htapes" - 160 - 0.000642 0.000012 0.000003 0.000008
"r:lc_rof_export" - 160 - 0.002504 0.000023 0.000014 0.000008
"r:check_fields" - 160 - 0.003283 0.000027 0.000017 0.000008
"CPL:ATM_RUN" - 960 - 470.012512 1.463564 0.410649 0.000048
"a:CAM_import" - 960 - 0.020761 0.000030 0.000014 0.000048
"a:CAM_run2" - 961 - 68.703972 0.181803 0.061824 0.000049
"a:phys_run2" - 961 - 56.435658 0.120504 0.055012 0.000049
"a:lightning_no_prod" - 961 - 0.000510 0.000007 0.000000 0.000049
"a:ac_physics" - 961 - 56.398483 0.120443 0.054986 0.000049
"a:diag_surf" - 5766 - 0.190099 0.008481 0.000025 0.000291
"a:tphysac_init" - 5766 - 0.455688 0.000146 0.000063 0.000291
"a:qneg4" - 5766 - 0.004037 0.000009 0.000000 0.000291
"a:adv_tracer_src_snk" - 5766 - 31.364918 0.041218 0.004881 0.000291
"a:chemdr" - 5766 - 27.869793 0.017684 0.004333 0.000291
"a:imp_sol" - 5766 - 8.441821 0.001729 0.001423 0.000291
"a:lin_mat" - 3.0e+06 - 0.225991 0.000190 0.000000 0.149038
"a:nln_mat" - 5.9e+06 - 0.443952 0.000059 0.000000 0.298077
"a:lu_fac" - 5.9e+06 - 0.647623 0.000188 0.000000 0.298077
"a:prod_loss" - 5.9e+06 - 0.740507 0.000181 0.000000 0.298077
"a:lu_slv" - 5.9e+06 - 0.542275 0.000197 0.000000 0.298077
"a:modal_gas-aer_exchng" - 5766 - 4.607491 0.001082 0.000761 0.000291
"a:modal_nucl" - 5766 - 0.816314 0.000408 0.000111 0.000291
"a:modal_coag" - 5766 - 2.384210 0.000654 0.000399 0.000291
"a:vertical_diffusion_tend" - 5766 - 3.450356 0.021073 0.000474 0.000291
"a:rayleigh_friction" - 5766 - 0.092159 0.000038 0.000015 0.000291
"a:aero_drydep" - 5766 - 9.021919 0.001983 0.001532 0.000291
* "a:carma_timestep_tend" - 11532 - 0.054431 0.000024 0.000000 0.000582
"a:gw_tend" - 5766 - 11.052542 0.002236 0.001757 0.000291
"a:iondrag" - 5766 - 0.069754 0.000087 0.000011 0.000291
"a:carma_accumulate_stats" - 961 - 0.000148 0.000007 0.000000 0.000049
"a:physpkg_st2" - 961 - 0.032642 0.000080 0.000022 0.000049
"a:stepon_run2" - 961 - 12.264637 0.061295 0.006673 0.000049
"a:p_d_coupling" - 961 - 12.262934 0.061292 0.006672 0.000049
"a:chunk_to_block" - 961 - 6.314600 0.055784 0.002138 0.000049
"a:uv3s_update" - 961 - 0.139348 0.015633 0.000050 0.000049
"a:p_d_adjust" - 961 - 3.301197 0.023898 0.002782 0.000049
"a:pdadj_reprosum" - 961 - 2.899066 0.023441 0.002430 0.000049
"a:ionosphere_run2" - 961 - 0.000259 0.000001 0.000000 0.000049
"a:cam_run2_memusage" - 1 - 0.000000 0.000000 0.000000 0.000000
"a:CAM_run3" - 961 - 0.097957 0.016715 0.000002 0.000049
"a:stepon_run3" - 961 - 0.097075 0.016714 0.000001 0.000049
"a:fv_out" - 80 - 0.095540 0.016711 0.000548 0.000004
"a:gmeanxy_reprosum" - 160 - 0.054820 0.016216 0.000048 0.000008
"a:fv_out_reprosum" - 80 - 0.003668 0.000095 0.000036 0.000004
"a:cam_run3_memusage" - 1 - 0.000000 0.000000 0.000000 0.000000
"a:CAM_run4" - 961 - 0.008080 0.000512 0.000007 0.000049
"a:wshist" - 961 - 0.003088 0.000006 0.000003 0.000049
"a:cam_run4_wrapup" - 961 - 0.000833 0.000001 0.000001 0.000049
"a:CAM_adv_timestep" - 961 - 0.000616 0.000002 0.000001 0.000049
"a:CAM_run1" - 961 - 400.944550 1.392101 0.340264 0.000049
"a:stepon_run1" - 961 - 87.721375 0.116515 0.085331 0.000049
"a:diag_dynvar_ic" - 961 - 0.001215 0.000007 0.000001 0.000049
"a:comp_adv_tends1" - 961 - 0.451764 0.000918 0.000359 0.000049
"a:dyn_run" - 961 - 77.197601 0.105417 0.075638 0.000049
"a:dyn_run_alloc" - 961 - 0.102200 0.000182 0.000065 0.000049
"a:xy_to_yz" - 1922 - 15.334215 0.025128 0.006500 0.000097
"a:small_ts_init" - 1922 - 0.251542 0.000396 0.000057 0.000097
"a:cd_core" - 7688 - 25.878244 0.008395 0.002680 0.000388
"a:---PRE_C_CORE" - 7688 - 2.119328 0.001161 0.000109 0.000388
"a:---PRE_C_CORE_COMM" - 15376 - 1.162870 0.000935 0.000011 0.000776
"a:---C_DELP_LOOP" - 1922 - 0.113879 0.000099 0.000039 0.000097
"a:---C_CORE" - 7688 - 1.480816 0.000492 0.000166 0.000388
"a:---C_GEOP" - 7688 - 8.155663 0.005782 0.000693 0.000388
"a:YZ_TO_XY_C_GEOP" - 7688 - 3.557188 0.004876 0.000119 0.000388
"a:XY_TO_YZ_C_GEOP" - 7688 - 3.664788 0.004218 0.000166 0.000388
"a:---PRE_D_CORE" - 7688 - 1.425465 0.001183 0.000113 0.000388
"a:---PRE_D_CORE_COMM" - 23064 - 0.600998 0.000985 0.000005 0.001164
"a:---C_U_LOOP" - 7688 - 0.342790 0.000247 0.000039 0.000388
"a:---C_V_PGRAD" - 7688 - 0.339851 0.000101 0.000040 0.000388
"a:---D_CORE" - 7688 - 2.608106 0.000590 0.000316 0.000388
"a:---D_GEOP" - 7688 - 8.615726 0.005852 0.000769 0.000388
"a:YZ_TO_XY_D_GEOP" - 7688 - 3.422803 0.004198 0.000147 0.000388
"a:XY_TO_YZ_D_GEOP" - 7688 - 4.315260 0.004264 0.000172 0.000388
"a:---PRE_D_PGRAD" - 7688 - 0.479501 0.000455 0.000026 0.000388
"a:---PRE_D_PGRAD_COMM_1" - 15376 - 0.161902 0.000434 0.000003 0.000776
"a:---D_DELP_LOOP" - 5766 - 0.205150 0.000253 0.000033 0.000291
"a:---D_PGRAD_1" - 7688 - 0.107977 0.000242 0.000010 0.000388
"a:---D_PGRAD_2" - 7688 - 0.624949 0.000365 0.000074 0.000388
"a:---PRE_D_PGRAD_COMM_2" - 5766 - 0.056237 0.000570 0.000003 0.000291
"a:trac2d" - 1922 - 7.588102 0.006198 0.003711 0.000097
"a:---TRAC2D_COMM" - 5766 - 0.667880 0.002462 0.000004 0.000291
"a:---TRAC2D_TRACER" - 1922 - 6.865018 0.004828 0.003434 0.000097
"a:---TRAC2D_TRACER_COMM" - 73036 - 2.823356 0.000245 0.000003 0.003687
"a:yz_to_xy_psuv" - 1922 - 5.405771 0.005908 0.001459 0.000097
"a:yz_to_xy_q" - 1922 - 9.579550 0.010739 0.004211 0.000097
"a:te_map" - 1922 - 11.452881 0.008788 0.005765 0.000097
"a:xsum_reprosum" - 3844 - 0.509894 0.002967 0.000078 0.000194
* "a:shr_reprosum_NaN_INF_Chk" - 7339 - 1.043033 0.001178 0.000002 0.000371
* "a:shr_reprosum_int" - 7339 - 3.479042 0.022520 0.000030 0.000371
"a:repro_sum_loopa" - 7339 - 0.398500 0.000527 0.000000 0.000371
"a:repro_sum_allr_minmax" - 7339 - 1.589279 0.020109 0.000005 0.000371
"a:repro_sum_loopb" - 7339 - 1.099583 0.001141 0.000000 0.000371
"a:repro_sum_allr_i8" - 7339 - 0.186991 0.001451 0.000005 0.000371
"a:vdot_gradp" - 961 - 0.834507 0.005545 0.000521 0.000049
"a:dyn_run_dealloc" - 961 - 0.015658 0.000347 0.000008 0.000049
"a:comp_adv_tends2" - 961 - 0.523222 0.002056 0.000331 0.000049
"a:d_p_coupling" - 961 - 9.542733 0.013982 0.006431 0.000049
"a:d2a3dikj" - 961 - 0.264411 0.004234 0.000177 0.000049
"a:d2a3dikj_reprosum" - 961 - 0.191673 0.003354 0.000148 0.000049
"a:block_to_chunk" - 961 - 6.400595 0.010878 0.003295 0.000049
"a:derived_fields" - 961 - 0.552942 0.000789 0.000515 0.000049
"a:phys_run1" - 961 - 313.221344 1.297304 0.251654 0.000049
"a:physpkg_st1" - 1922 - 5.449472 1.046341 0.000182 0.000097
"a:chk_en_gmean" - 961 - 0.874926 0.006340 0.000181 0.000049
* "a:gmean_fixed_repro" - 1121 - 0.803578 0.006261 0.000037 0.000057
"a:advance_trcdata" - 31713 - 3.867525 1.044257 0.000007 0.001601
"a:interpolate_trcdata" - 31713 - 1.398282 0.000701 0.000000 0.001601
"a:read_next_trcdata" - 39 - 2.260336 1.043907 0.002331 0.000002
"a:PIO:pio_get_vara_2d_double" - 146 - 0.167172 0.019619 0.000190 0.000007
"a:PIO:pio_get_vara_3d_double" - 24 - 1.958138 0.155968 0.013514 0.000001
"a:bc_physics" - 961 - 307.769073 0.400474 0.248750 0.000049
"a:diag_physvar_ic" - 5766 - 0.010264 0.000015 0.000001 0.000291
"a:bc_init" - 5766 - 0.441399 0.000185 0.000049 0.000291
"a:energy_fixer" - 5766 - 0.301251 0.000140 0.000038 0.000291
"a:dry_adjustment" - 5766 - 0.370001 0.000345 0.000036 0.000291
"a:moist_convection" - 5766 - 13.555542 0.003035 0.002082 0.000291
"a:convect_deep_tend" - 5766 - 11.415768 0.002473 0.001726 0.000291
"a:zm_convr" - 5766 - 8.937250 0.002004 0.001377 0.000291
"a:zm_conv_evap" - 5766 - 0.232928 0.000333 0.000032 0.000291
"a:momtran" - 5766 - 0.141928 0.000206 0.000009 0.000291
"a:convtran1" - 5766 - 0.178341 0.000072 0.000003 0.000291
"a:convect_shallow_tend" - 5766 - 1.501863 0.000448 0.000241 0.000291
"a:macrop_tend" - 17298 - 106.268448 0.009869 0.005979 0.000873
* "a:qneg3" - 2.7e+06 - 6.557551 0.000248 0.000001 0.137686
"a:microp_aero_run" - 17298 - 56.023849 0.005420 0.002917 0.000873
"a:microp_tend" - 17298 - 41.737522 0.003761 0.001941 0.000873
"a:microp_mg_tend" - 17298 - 39.261551 0.003622 0.001820 0.000873
"a:bc_aerosols" - 5766 - 20.678820 0.005217 0.003372 0.000291
"a:calcsize" - 5766 - 3.535836 0.001018 0.000575 0.000291
"a:wateruptake" - 5766 - 7.565156 0.001878 0.001260 0.000291
"a:convect_deep_tend2" - 5766 - 1.451489 0.000494 0.000130 0.000291
"a:convtran2" - 5766 - 0.636271 0.000344 0.000010 0.000291
"a:bc_history_write" - 5766 - 0.847783 0.000431 0.000112 0.000291
"a:bc_cld_diag_history_write" - 5766 - 0.519638 0.000367 0.000070 0.000291
"a:radiation" - 5766 - 65.905861 0.027885 0.000049 0.000291
"a:cldoptics" - 2880 - 3.420619 0.001653 0.000816 0.000145
"a:mcica_subcol_sw" - 2880 - 1.898118 0.001037 0.000491 0.000145
"a:rrtmg_sw" - 2880 - 18.747261 0.008392 0.005736 0.000145
"a:mcica_subcol_lw" - 2880 - 4.147807 0.002635 0.001004 0.000145
"a:rrtmg_lw" - 2880 - 11.572951 0.005243 0.003575 0.000145
"a:tropopause" - 5766 - 0.749201 0.000191 0.000122 0.000291
"a:cam_export" - 5766 - 0.167330 0.000064 0.000020 0.000291
"a:diag_export" - 5766 - 0.038802 0.000081 0.000005 0.000291
"a:CAM_export" - 961 - 0.014751 0.000031 0.000012 0.000049
"a:check_fields" - 960 - 0.020148 0.000036 0.000020 0.000048
"CPL:GLC_RUN" - 20 - 0.005774 0.000312 0.000278 0.000001
"g:check_fields" - 20 - 0.000401 0.000020 0.000020 0.000001
"CPL:TPROF_WRITE" - 960 - 0.029601 0.029504 0.000000 0.000048
"CPL:sync1_tprof" - 1 - 0.003005 0.003005 0.003005 0.000000
"CPL:t_prf" - 1 - 0.020281 0.020281 0.020281 0.000000
"CPL:sync2_tprof" - 1 - 0.006206 0.006206 0.006206 0.000000
"CPL:RUN_LOOP_BSTOP" - 1 - 0.000025 0.000025 0.000025 0.000000
"CPL:FINAL" - 1 - 0.013300 0.013300 0.013300 0.000000
"CPL:cime_final" - 1 - 0.013299 0.013299 0.013299 0.000000
"a_f:PIO:PIO_closefile" - 2 - 0.000002 0.000002 0.000000 0.000000
"sync3_tprof" - 1 - 0.000019 0.000019 0.000019 0.000000
"t_prf" y 0 - 0.000000 0.000000 0.000000 0.000000
Overhead sum = 1.53 wallclock seconds
Total calls = 3.027e+07
Multiple parent info for thread 0:
Columns are count and name for the listed child
Rows are each parent, with their common child being the last entry, which is indented.
Count next to each parent is the number of times it called the child.
Count next to child is total number of times it was called by the listed parents.
960 "CPL:ATMOCN1"
3840 "CPL:RUN"
4800 "CPL:BUDGET"
961 "l:begcnbal_col"
1922 "l:EcosysDynPostDrainage"
2883 "l:CNsum"
3844 "l:ecosysdyn"
961 "l:EcosysDynPostDrainage"
4805 "l:CNPrecisionControl"
347 "r:mosartr_tot"
160 "r:mosartr_subcycling"
507 "r:mosartr_budget"
144150 "a:adv_tracer_src_snk"
190278 "a:vertical_diffusion_tend"
109554 "a:aero_drydep"
190278 "a:gw_tend"
5766 "a:derived_fields"
5766 "a:bc_init"
5766 "a:dry_adjustment"
40362 "a:convect_deep_tend"
190278 "a:convect_shallow_tend"
190278 "a:moist_convection"
518940 "a:macrop_tend"
363258 "a:microp_aero_run"
86490 "a:microp_mg_tend"
415152 "a:microp_tend"
109554 "a:bc_aerosols"
161448 "a:convect_deep_tend2"
2.7e+06 "a:qneg3"
5766 "a:ac_physics"
5766 "a:bc_physics"
11532 "a:carma_timestep_tend"
961 "a:pdadj_reprosum"
3844 "a:xsum_reprosum"
961 "a:d2a3dikj_reprosum"
1121 "a:gmean_fixed_repro"
160 "a:gmeanxy_reprosum"
80 "a:fv_out_reprosum"
212 "a:read_next_trcdata"
7339 "a:shr_reprosum_NaN_INF_Chk"
961 "a:pdadj_reprosum"
3844 "a:xsum_reprosum"
961 "a:d2a3dikj_reprosum"
1121 "a:gmean_fixed_repro"
160 "a:gmeanxy_reprosum"
80 "a:fv_out_reprosum"
212 "a:read_next_trcdata"
7339 "a:shr_reprosum_int"
961 "a:chk_en_gmean"
160 "a:fv_out"
1121 "a:gmean_fixed_repro"
160 "l:lnfmdyn_readLBUB_UB_readpio"
1 "l:ndepdyn_readLBUB_UB_readpio"
8 "l:readMonthlyVeg"
169 "l:PIO:pio_read_darray"
thread 0 had some hash collisions:
hashtable[0][27] had 2 entries: "a:dyn_run" "l:lnfmdyn_readLBUB_LB_copy"
hashtable[0][52] had 3 entries: "l:lnfmdyn_strd_adv_tint" "l:drvinit" "a:diag_physvar_ic"
hashtable[0][328] had 2 entries: "CPL:ocnpre1_atm2ocn" "a:YZ_TO_XY_D_GEOP"
hashtable[0][330] had 2 entries: "a:lightning_no_prod" "a:rayleigh_friction"
hashtable[0][340] had 2 entries: "a:XY_TO_YZ_D_GEOP" "CPL:GLC_RUN"
hashtable[0][390] had 2 entries: "CPL:init_aoflux" "a:---PRE_C_CORE"
hashtable[0][391] had 2 entries: "a:repro_sum_loopb" "a:chk_en_gmean"
hashtable[0][440] had 2 entries: "CPL:ATM_RUN" "CPL:g2c_glcg2glcx"
hashtable[0][614] had 2 entries: "l:CNDeposition" "a:lu_fac"
hashtable[0][620] had 2 entries: "CPL:C2L" "CPL:O2C"
hashtable[0][644] had 2 entries: "a:pdadj_reprosum" "CPL:C2O"
hashtable[0][668] had 2 entries: "CPL:C2R" "CPL:W2C"
hashtable[0][688] had 2 entries: "CPL:iceprep_atm2ice" "l:lc_lnd_import"
hashtable[0][693] had 2 entries: "l:EcosysDynPostDrainage" "a:physpkg_st2"
hashtable[0][715] had 2 entries: "a:shr_reprosum_int" "a:bc_history_write"
hashtable[0][732] had 2 entries: "a:stepon_run3" "a:te_map"
hashtable[0][763] had 2 entries: "r:mosartr_euler" "l:ndepdyn_readLBUB_UB_readpio"
hashtable[0][769] had 2 entries: "a:carma_timestep_tend" "a:---PRE_D_PGRAD_COMM_1"
hashtable[0][796] had 2 entries: "CPL:cime_init" "CPL:CLOCK_ADVANCE"
hashtable[0][971] had 2 entries: "CPL:RUN" "a:fv_out"
hashtable[0][979] had 2 entries: "l:CNUpdateDynPatch" "l:CNFUN"
hashtable[0][1012] had 2 entries: "CPL:TPROF_WRITE" "l:PIO:pio_read_nf"
hashtable[0][1020] had 2 entries: "a:wshist" "a:convect_deep_tend2"
hashtable[0][1021] had 2 entries: "l:CNPhenology" "CPL:atmprep_mrgx2a"
hashtable[0][1092] had 2 entries: "CPL:c2r_rofx2rofr" "CPL:r2c_rofr2rofx"
hashtable[0][1177] had 2 entries: "CPL:wavprep_ice2wav" "a:PIO:pio_get_vara_3d_double"
hashtable[0][1218] had 2 entries: "CPL:atmocnp_wav2ocn" "l:CNUpdate2"
hashtable[0][1243] had 3 entries: "CPL:init_rof2ocn" "l:dyn_subgrid" "a:yz_to_xy_psuv"
hashtable[0][1323] had 2 entries: "l:CNFUNInit" "l:CNGResp"
hashtable[0][1359] had 2 entries: "l:lnfmdyn_readLBUB_filemgt" "l:CNMResp"
hashtable[0][1363] had 2 entries: "l:hydro2_drainage" "a:bc_aerosols"
hashtable[0][1385] had 2 entries: "CPL:comp_init_cc_ice" "l:soilbiogeochemcompetition"
hashtable[0][1398] had 3 entries: "r:mosartr_subnetwork" "CPL:i2c_infoexch" "CPL:w2c_wavw2wavx"
hashtable[0][1405] had 2 entries: "CPL:wavprep_ocn2wav" "a:qneg4"
hashtable[0][1434] had 2 entries: "CPL:c2l_infoexch" "CPL:o2c_infoexch"
hashtable[0][1482] had 2 entries: "CPL:c2r_infoexch" "CPL:w2c_infoexch"
hashtable[0][1618] had 2 entries: "CPL:INIT" "a:cam_run3_memusage"
hashtable[0][1686] had 2 entries: "CPL:atmocnp_accum" "a:vdot_gradp"
hashtable[0][1810] had 3 entries: "CPL:init_domain_check" "l:dyn_cnbal_patch" "a:---C_GEOP"
hashtable[0][1817] had 3 entries: "CPL:comp_init_cc_rof" "CPL:init_areacor" "a:---D_GEOP"
hashtable[0][1867] had 2 entries: "a:lin_mat" "a:gw_tend"
hashtable[0][1890] had 2 entries: "l:ch4" "a:nln_mat"
hashtable[0][2022] had 2 entries: "l:clm_run" "a:momtran"
Total collisions thread 0 = 48
Entry information:
num_zero = 1656 num_one = 349 num_two = 38 num_more = 5
Most = 3
Thread 0 total memory usage = 163.224 KB
Hashmem = 32.768 KB
Regionmem = 123.2 KB (papimem portion = 0 KB)
Parent/child arrays = 7.256 KB
Total memory usage all threads = 163.224 KB
threadid[0] = 0Maybe we should replace it with nothing and use gprof, the information seems very similar:
https://hpc.llnl.gov/software/development-environment-software/gprof
jedwards4b
commented
5 years ago I think gprof is relatively very expensive and requires special compiler flags.
edhartnett
commented
5 years ago Yes to compiler flags but that is trivial, right?
Is the timer run during normal model runs? Or only sometimes? In which case, does the extra computational expense of gprof matter?
jedwards4b
commented
5 years ago Yes, timers are on in every run.
edhartnett
commented
5 years ago OK, I am going to ponder for a while on this.
edhartnett
commented
5 years ago The goal of this issue cannot be met. Since GPTL is used by user code that also user PIO, we have to leave initialization to the user, which means we must also initialize it in our test code. Bummer.
In our current use of GPTL we must have an initialization call in each test, like this, from tests/cunit/test_common,c
I this is not done, and --enable-timing is used, then every timing call results in an an initialization error message being printed to consoile.
The initialization can be handled within the PIO C library, so that test programs don't have to care about initializing GPTL.