Jobsub ID 263305.40@dunegpschedd02.fnal.gov

Jobsub ID	263305.40@dunegpschedd02.fnal.gov
Workflow ID	11264
Stage ID	1
User name	avizcaya@fnal.gov
HTCondor Group	group_dune
Requested	Processors	1
	GPU	No
	RSS bytes	9437184000 (9000 MiB)
	Wall seconds limit	80000 (22 hours)
Submitted time	2025-12-18 19:31:07
Site	US_FNAL-FermiGrid
Entry	FNAL_GPGrid_ce04_mcore_op_duneonly
Last heartbeat	2025-12-18 22:37:44
From worker node	Hostname	dunegli-8108345-0-fnpc9056.fnal.gov
	cpuinfo	Intel(R) Xeon(R) CPU E5-2680 v4 @ 2.40GHz
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	172800 (48 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-12-18 21:10:18
Input files	usertests:pdhd_prod_beam__261612_71_1_20251212T160138Z_gen_g4_IonScintPDExt.root_262727_10_1_20251215T214312Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (5160s)
	CPU time	1h (4368s = 84%)
	Max RSS bytes	6848139264 (6530 MiB)
Outputting started	2025-12-18 22:36:19
Output files	usertests:pdhd_prod_beam__261612_71_1_20251212T160138Z_gen_g4_IonScintPDExt.root_262727_10_1_20251215T214312Z_PDInt.root_263305_40_1_20251218T211025Z_detsim_reco1.root
Finished	2025-12-18 22:37:44
Saved logs	justin-logs:263305.40-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

7 ] 
[22:34:10.579] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=179 time=0 tick=512 with 54960 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":25889 [0] "wiener0":29071 [29071] ] cmm:[ bad:0 lf_noisy:97 ] input 1: frame: ident=179 time=0 tick=512 with 27392 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":12320 [0] "wiener1":15072 [15072] ] cmm:[ bad:0 ] input 2: frame: ident=179 time=0 tick=512 with 57508 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":24384 [0] "wiener2":33124 [33124] ] cmm:[ bad:0 lf_noisy:1 ] input 3: frame: ident=179 time=0 tick=512 with 41438 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":17448 [0] "wiener3":23990 [23990] ] cmm:[ bad:0 ] output: frame: ident=179 time=0 tick=512 with 181298 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":25889 [0] "gauss1":12320 [0] "gauss2":24384 [0] "gauss3":17448 [0] "wiener0":29071 [29071] "wiener1":15072 [15072] "wiener2":33124 [33124] "wiener3":23990 [23990] ] cmm:[ bad:0 lf_noisy:98 ] 
Retagger: tagging trace set: wiener with 101257 traces, 101257 summary
Retagger: tagging trace set: gauss with 80041 traces, 0 summary
[22:34:10.591] D [  glue  ] sink frame: #179 @0 with 181298 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[22:34:10.591] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[22:34:10.591] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[22:34:10.591] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[22:34:10.591] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[22:34:10.591] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[22:34:10.591] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[22:34:10.591] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[22:34:10.591] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[22:34:10.591] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[22:34:10.592] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[22:34:10.592] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[22:34:10.592] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[22:34:10.592] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[22:34:10.592] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[22:34:10.592] D [  glue  ] frame sink sees EOS
[22:34:10.592] D [ pgraph ] <Pgrapher:> graph execution complete 
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.93 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.57 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.02 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.93 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.47 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.43 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.33 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.28 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:10.592] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:10.592] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[22:34:10.592] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:34:10.592] I [ timer  ] Timer: Total node execution : 50.01000075228512 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 80041 traces tagged "gauss"
FrameSaver: q=2.49964e+06 n=1284457 tag=gauss
wclsFrameSaver: saving 101257 traces tagged "wiener"
FrameSaver: q=3.30556e+06 n=1247773 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 14778 XUs and 71200 XVs -> 752 XUVs
C:0 T:5 40107 XUs and 55250 XVs -> 1171 XUVs
C:0 T:6 21670 XUs and 26922 XVs -> 1575 XUVs
C:0 T:7 23 XUs and 143 XVs -> 2 XUVs
3500 XUVs total
1622 collection wire objects
3500 potential space points
Neighbour search...
81370 tests to find 47810 neighbours
Iterating with no regularization...
Begin: 2.66044e+07
0 2.43641e+07
1 2.42705e+07
2 2.42553e+07
Now with regularization...
Begin: 2.29869e+07
0 2.29809e+07
18-Dec-2025 22:34:56 UTC  Closed output file "pdhd_prod_beam__261612_71_1_20251212T160138Z_gen_g4_IonScintPDExt.root_262727_10_1_20251215T214312Z_PDInt.root_263305_40_1_20251218T211025Z_detsim_reco1.root"
18-Dec-2025 22:34:56 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           64.8561       88.161        108.772       87.8553       14.1907        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000441868   0.00285663    0.00458392    0.00327691    0.00130059       10     
reco:wclsdatahd:WireCellToolkit                      48.0791       51.1633       56.913        50.6276       2.39153        10     
reco:wirefilter:WireFilter                          0.0145688     0.0208579     0.0266624     0.0209568    0.00416384       10     
reco:gaushit:GausHitFinder                           0.32561      0.565214      0.782991      0.598181       0.1635         10     
reco:nhitsfilter:NumberOfHitsFilter                9.2996e-05    0.000159207   0.000300435   0.000154701   5.62746e-05      10     
reco:reco3d:SpacePointSolver                        0.0751065      0.50932      0.982326      0.551985      0.296605        10     
reco:hitpdune:DisambigFromSpacePoints               0.115733      0.565625      0.976126      0.605907      0.309084        10     
reco:pandora:StandardPandora                         2.53996       7.66785       12.8621       7.51795       3.51012        10     
reco:pandoraWriter:StandardPandora                  0.138471      0.937702       4.53781      0.373619       1.27466        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.212005       0.84692       1.45149      0.913099      0.379182        10     
reco:pandoraShower:LArPandoraShowerCreation          0.15971      0.809473       1.26871      0.904893      0.393382        10     
reco:pandoracalo:Calorimetry                        0.121743      0.443044      0.684133      0.503456      0.180069        10     
reco:pandoracalonosce:Calorimetry                   0.117375      0.437132      0.672766      0.503581      0.179333        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.155836      0.816203       1.35582      0.878918      0.420441        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.151592      0.799366       1.30802      0.887551      0.405598        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0222514     0.0406889     0.0549501     0.0463102     0.0108133       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0215611     0.0393126     0.0532321     0.0436852     0.0103131       10     
reco:emtrkmichelid:EmTrackMichelId                   10.6315       19.6421       26.8471       21.4378       5.60501        10     
[art]:TriggerResults:TriggerResultInserter         2.0474e-05    3.02903e-05   7.4091e-05    2.56985e-05   1.4793e-05       10     
end_path:out1:RootOutput                            4.438e-06    8.5529e-06    2.2758e-05    7.2725e-06    4.81882e-06      10     
end_path:out1:RootOutput(write)                     0.620665       2.82866       6.87961       1.88616       2.16347        10     
=====================================================================================================================================

====================================================================================================
MemoryTracker summary (base-10 MB units used)

  Peak virtual memory usage (VmPeak)  : 5802.7 MB
  Peak resident set size usage (VmHWM): 3637.1 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11253468
-rw-r--r-- 1 dunegli fnalgrid     231792 Dec 18 22:36 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        200 Dec 18 22:36 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 18 22:36 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 18 22:36 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 18 22:36 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 18 22:35 time.db
-rw-r--r-- 1 dunegli fnalgrid 5835912083 Dec 18 22:34 pdhd_prod_beam__261612_71_1_20251212T160138Z_gen_g4_IonScintPDExt.root_262727_10_1_20251215T214312Z_PDInt.root_263305_40_1_20251218T211025Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   33531210 Dec 18 22:34 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 18 22:10 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 18 22:09 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 5653636172 Dec 18 22:09 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        121 Dec 18 21:10 all-input-dids.txt