Jobsub ID 262980.1@dunegpschedd02.fnal.gov

Jobsub ID	262980.1@dunegpschedd02.fnal.gov
Workflow ID	11227
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-17 00:50:58
Site	US_UChicago
Entry	Engage_US_MWT2_uiuc_gk02_condce_mcore
Last heartbeat	2025-12-17 03:36:45
From worker node	Hostname	mwt2-c164.campuscluster.illinois.edu
	cpuinfo	Intel(R) Xeon(R) Gold 6148 CPU @ 2.40GHz
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	86400 (24 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-12-17 00:52:32
Input files	usertests:pdhd_prod_beam__265029_89_1_20251208T214626Z_gen_g4_IonScintPDExt.root_260194_42_1_20251210T115533Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (9728s)
	CPU time	2h (9359s = 96%)
	Max RSS bytes	7465517056 (7119 MiB)
Outputting started	2025-12-17 03:34:40
Output files	usertests:pdhd_prod_beam__265029_89_1_20251208T214626Z_gen_g4_IonScintPDExt.root_260194_42_1_20251210T115533Z_PDInt.root_262980_1_1_20251217T005300Z_detsim_reco1.root
Finished	2025-12-17 03:36:45
Saved logs	justin-logs:262980.1-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":21702 [0] "wiener0":23744 [23744] ] cmm:[ bad:0 lf_noisy:189 ] 
[21:33:43.977] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=159 time=0 tick=512 with 45446 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":21702 [0] "wiener0":23744 [23744] ] cmm:[ bad:0 lf_noisy:189 ] input 1: frame: ident=159 time=0 tick=512 with 37892 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":16703 [0] "wiener1":21189 [21189] ] cmm:[ bad:0 ] input 2: frame: ident=159 time=0 tick=512 with 44139 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":18716 [0] "wiener2":25423 [25423] ] cmm:[ bad:0 ] input 3: frame: ident=159 time=0 tick=512 with 35650 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":15402 [0] "wiener3":20248 [20248] ] cmm:[ bad:0 ] output: frame: ident=159 time=0 tick=512 with 163127 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":21702 [0] "gauss1":16703 [0] "gauss2":18716 [0] "gauss3":15402 [0] "wiener0":23744 [23744] "wiener1":21189 [21189] "wiener2":25423 [25423] "wiener3":20248 [20248] ] cmm:[ bad:0 lf_noisy:189 ] 
Retagger: tagging trace set: wiener with 90604 traces, 90604 summary
Retagger: tagging trace set: gauss with 72523 traces, 0 summary
[21:33:44.008] D [  glue  ] sink frame: #159 @0 with 163127 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[21:33:44.009] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[21:33:44.009] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[21:33:44.009] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[21:33:44.009] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[21:33:44.009] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[21:33:44.009] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[21:33:44.009] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[21:33:44.009] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[21:33:44.009] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[21:33:44.009] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[21:33:44.009] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[21:33:44.009] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[21:33:44.009] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[21:33:44.009] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[21:33:44.009] D [  glue  ] frame sink sees EOS
[21:33:44.009] D [ pgraph ] <Pgrapher:> graph execution complete 
[21:33:44.009] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 22.09 sec
[21:33:44.009] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.27 sec
[21:33:44.009] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.14 sec
[21:33:44.009] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.36 sec
[21:33:44.009] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 5.2 sec
[21:33:44.009] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.39 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.19 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.06 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.05 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.02 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:33:44.010] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[21:33:44.010] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[21:33:44.010] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:33:44.010] I [ timer  ] Timer: Total node execution : 84.81000028550625 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 72523 traces tagged "gauss"
FrameSaver: q=2.11945e+06 n=1071505 tag=gauss
wclsFrameSaver: saving 90604 traces tagged "wiener"
FrameSaver: q=2.84252e+06 n=1028352 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 25632 XUs and 14762 XVs -> 532 XUVs
C:0 T:5 19620 XUs and 31040 XVs -> 930 XUVs
C:0 T:6 24427 XUs and 20043 XVs -> 828 XUVs
2290 XUVs total
1352 collection wire objects
2290 potential space points
Neighbour search...
45964 tests to find 26114 neighbours
Iterating with no regularization...
Begin: 1.81836e+07
0 1.70025e+07
1 1.69185e+07
2 1.69131e+07
Now with regularization...
Begin: 1.55528e+07
0 1.55509e+07
16-Dec-2025 21:34:37 CST  Closed output file "pdhd_prod_beam__265029_89_1_20251208T214626Z_gen_g4_IonScintPDExt.root_260194_42_1_20251210T115533Z_PDInt.root_262980_1_1_20251217T005300Z_detsim_reco1.root"
16-Dec-2025 21:34:37 CST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           139.868       170.101       244.822       168.448       26.9895        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00402289    0.00659067    0.00913429    0.00670222    0.00174886       10     
reco:wclsdatahd:WireCellToolkit                      83.759        89.5708       94.023        90.0974       3.11167        10     
reco:wirefilter:WireFilter                          0.0300255     0.0540441     0.0676144     0.0564734     0.0107518       10     
reco:gaushit:GausHitFinder                          0.648553       1.15466       1.62678       1.20585      0.251538        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000384543   0.000576102   0.00102647    0.000545765   0.000163217      10     
reco:reco3d:SpacePointSolver                        0.454696       1.45857       2.68197       1.47836      0.732716        10     
reco:hitpdune:DisambigFromSpacePoints               0.597268       1.10666       2.01628       1.00245      0.382294        10     
reco:pandora:StandardPandora                         8.26406       17.0827       37.8394       15.3029       7.62978        10     
reco:pandoraWriter:StandardPandora                  0.327377      0.396478      0.519823      0.390214      0.0560606       10     
reco:pandoraTrack:LArPandoraTrackCreation            1.90868       3.03338       5.62033       2.72958      0.966813        10     
reco:pandoraShower:LArPandoraShowerCreation          1.94483       3.77529       9.32354       3.1127        2.03957        10     
reco:pandoracalo:Calorimetry                         1.25642       1.7135        3.2983        1.47817      0.582283        10     
reco:pandoracalonosce:Calorimetry                    1.06529       1.37934       1.72941       1.3437       0.233154        10     
reco:pandoraShowercalo:ShowerCalorimetry             1.89441       3.60947       9.01597       3.15605       1.90257        10     
reco:pandoraShowercalonosce:ShowerCalorimetry        1.95368       3.59455       10.3638       2.63272       2.37371        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0614365      0.10845      0.164854       0.10876      0.0269807       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0633809     0.107165      0.147751      0.106927      0.0246169       10     
reco:emtrkmichelid:EmTrackMichelId                   27.9833       39.6608       72.3523       38.1145       12.3278        10     
[art]:TriggerResults:TriggerResultInserter         6.1701e-05    8.40261e-05   0.000175953   7.60915e-05   3.22486e-05      10     
end_path:out1:RootOutput                           1.0694e-05    1.57918e-05    4.653e-05    1.2577e-05    1.03035e-05      10     
end_path:out1:RootOutput(write)                      1.78262       2.19041       2.82435       1.9729       0.364867        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6153.68 MB
  Peak resident set size usage (VmHWM): 3950.21 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12848276
-rw-r--r-- 1 dune osgvo     231536 Dec 16 21:34 jobscript.log
-rw-r--r-- 1 dune osgvo        200 Dec 16 21:34 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo        519 Dec 16 21:34 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo       3574 Dec 16 21:34 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo     139264 Dec 16 21:34 mem.db
-rw-r--r-- 1 dune osgvo      28672 Dec 16 21:34 time.db
-rw-r--r-- 1 dune osgvo 6664069284 Dec 16 21:34 pdhd_prod_beam__265029_89_1_20251208T214626Z_gen_g4_IonScintPDExt.root_260194_42_1_20251210T115533Z_PDInt.root_262980_1_1_20251217T005300Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo   40208540 Dec 16 21:33 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo          0 Dec 16 21:02 debugprod.log
-rw-r--r-- 1 dune osgvo        519 Dec 16 21:02 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 6451910544 Dec 16 21:02 temp_detsim.root
-rw-r--r-- 1 dune osgvo        121 Dec 16 18:53 all-input-dids.txt