Jobsub ID 234994.0@dunegpschedd02.fnal.gov

Jobsub ID	234994.0@dunegpschedd02.fnal.gov
Workflow ID	9384
Stage ID	1
User name	mwrobel@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-10-29 20:44:49
Site	US_UChicago
Entry	Engage_US_MWT2_uiuc_condce_mcore
Last heartbeat	2025-10-29 22:18:06
From worker node	Hostname	mwt2-c193.campuscluster.illinois.edu
	cpuinfo	AMD EPYC 7402 24-Core Processor
	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-10-29 20:45:19
Input files	usertests:pdhd_prod_beam__231901_42_1_20251008T212400Z_gen_g4_IonScintPDExt.root_226750_110_1_20251009T211654Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (5451s)
	CPU time	1h (5300s = 97%)
	Max RSS bytes	6362951680 (6068 MiB)
Outputting started	2025-10-29 22:16:11
Output files	usertests:pdhd_prod_beam__231901_42_1_20251008T212400Z_gen_g4_IonScintPDExt.root_226750_110_1_20251009T211654Z_PDInt.root_234994_0_1_20251029T204525Z_detsim_reco1.root
Finished	2025-10-29 22:18:06
Saved logs	justin-logs:234994.0-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

proc" ] 2 tagged trace sets:[ "gauss0":17682 [0] "wiener0":19963 [19963] ] cmm:[ bad:0 lf_noisy:31 ] 
[17:15:30.127] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=79 time=0 tick=512 with 37645 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":17682 [0] "wiener0":19963 [19963] ] cmm:[ bad:0 lf_noisy:31 ] input 1: frame: ident=79 time=0 tick=512 with 23481 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":11189 [0] "wiener1":12292 [12292] ] cmm:[ bad:0 ] input 2: frame: ident=79 time=0 tick=512 with 47662 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":21099 [0] "wiener2":26563 [26563] ] cmm:[ bad:0 ] input 3: frame: ident=79 time=0 tick=512 with 35837 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16083 [0] "wiener3":19754 [19754] ] cmm:[ bad:0 ] output: frame: ident=79 time=0 tick=512 with 144625 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":17682 [0] "gauss1":11189 [0] "gauss2":21099 [0] "gauss3":16083 [0] "wiener0":19963 [19963] "wiener1":12292 [12292] "wiener2":26563 [26563] "wiener3":19754 [19754] ] cmm:[ bad:0 lf_noisy:31 ] 
Retagger: tagging trace set: wiener with 78572 traces, 78572 summary
Retagger: tagging trace set: gauss with 66053 traces, 0 summary
[17:15:30.143] D [  glue  ] sink frame: #79 @0 with 144625 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[17:15:30.143] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[17:15:30.144] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[17:15:30.144] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[17:15:30.144] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[17:15:30.144] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[17:15:30.144] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[17:15:30.144] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[17:15:30.144] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[17:15:30.144] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[17:15:30.144] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[17:15:30.144] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[17:15:30.144] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[17:15:30.144] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[17:15:30.144] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[17:15:30.144] D [  glue  ] frame sink sees EOS
[17:15:30.144] D [ pgraph ] <Pgrapher:> graph execution complete 
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.69 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.32 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.31 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.57 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.39 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.11 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.97 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.64 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[17:15:30.144] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[17:15:30.144] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[17:15:30.144] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[17:15:30.144] I [ timer  ] Timer: Total node execution : 49.04999999888241 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 66053 traces tagged "gauss"
FrameSaver: q=1.95124e+06 n=1052842 tag=gauss
wclsFrameSaver: saving 78572 traces tagged "wiener"
FrameSaver: q=2.36977e+06 n=1018945 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 1643 XUs and 2103 XVs -> 329 XUVs
C:0 T:5 61882 XUs and 39671 XVs -> 1141 XUVs
C:0 T:6 17084 XUs and 11242 XVs -> 430 XUVs
C:0 T:7 3 XUs and 5 XVs -> 0 XUVs
1900 XUVs total
1292 collection wire objects
1900 potential space points
Neighbour search...
32362 tests to find 15050 neighbours
Iterating with no regularization...
Begin: 2.6662e+07
0 2.45113e+07
1 2.43391e+07
2 2.43362e+07
Now with regularization...
Begin: 2.31629e+07
0 2.31622e+07
29-Oct-2025 17:16:09 CDT  Closed output file "pdhd_prod_beam__231901_42_1_20251008T212400Z_gen_g4_IonScintPDExt.root_226750_110_1_20251009T211654Z_PDInt.root_234994_0_1_20251029T204525Z_detsim_reco1.root"
29-Oct-2025 17:16:09 CDT  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           82.2062       91.9194       107.091       90.9321       7.56148        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00148203    0.00387223    0.00609742    0.00393564    0.00160025       10     
reco:wclsdatahd:WireCellToolkit                      49.0941       51.7167       54.9305       51.4831       2.08626        10     
reco:wirefilter:WireFilter                          0.0236817     0.0346613     0.0425129     0.0354624    0.00614676       10     
reco:gaushit:GausHitFinder                          0.425539      0.577108      0.714808      0.579876      0.0883295       10     
reco:nhitsfilter:NumberOfHitsFilter                0.000280518   0.000489699   0.000696259   0.00045974    0.000130579      10     
reco:reco3d:SpacePointSolver                        0.347848      0.693573       1.45969       0.64852      0.321534        10     
reco:hitpdune:DisambigFromSpacePoints               0.234101      0.359115      0.582655      0.289471      0.124929        10     
reco:pandora:StandardPandora                         5.32516       8.12383       13.0324       8.07163       2.1074         10     
reco:pandoraWriter:StandardPandora                  0.205215      0.267901      0.380531      0.247504      0.0604327       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.570823       1.14948       2.06715      0.989221      0.492961        10     
reco:pandoraShower:LArPandoraShowerCreation         0.472603      0.868648       1.28034      0.899638      0.301962        10     
reco:pandoracalo:Calorimetry                        0.331991      0.641928      0.987901       0.59807      0.208727        10     
reco:pandoracalonosce:Calorimetry                   0.356613       0.59615      0.937233      0.585029       0.18614        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.406029      0.831982       1.28685      0.793386      0.298836        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.428583      0.933694       1.48835       0.86814      0.324374        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0428242     0.0562006     0.0738202     0.0558891     0.0093836       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0417781     0.0550285     0.0719329     0.0554758    0.00884492       10     
reco:emtrkmichelid:EmTrackMichelId                   18.8789       23.5711       28.328        23.8454       3.21153        10     
[art]:TriggerResults:TriggerResultInserter         3.7491e-05    6.13003e-05   0.000130786   5.1822e-05    2.83228e-05      10     
end_path:out1:RootOutput                            8.816e-06    1.27079e-05   2.7673e-05    9.8685e-06    5.76086e-06      10     
end_path:out1:RootOutput(write)                      1.10283       1.35315       1.61313       1.34806      0.181963        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5790.33 MB
  Peak resident set size usage (VmHWM): 3594.88 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10869376
-rw-r--r-- 1 dune osgvo     230547 Oct 29 17:16 jobscript.log
-rw-r--r-- 1 dune osgvo        201 Oct 29 17:16 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo        519 Oct 29 17:16 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo       3574 Oct 29 17:16 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo     139264 Oct 29 17:16 mem.db
-rw-r--r-- 1 dune osgvo      28672 Oct 29 17:16 time.db
-rw-r--r-- 1 dune osgvo 5634543581 Oct 29 17:16 pdhd_prod_beam__231901_42_1_20251008T212400Z_gen_g4_IonScintPDExt.root_226750_110_1_20251009T211654Z_PDInt.root_234994_0_1_20251029T204525Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo   31539000 Oct 29 17:15 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo          0 Oct 29 16:58 debugprod.log
-rw-r--r-- 1 dune osgvo        519 Oct 29 16:58 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 5463703855 Oct 29 16:58 temp_detsim.root
-rw-r--r-- 1 dune osgvo        122 Oct 29 15:45 all-input-dids.txt