Jobsub ID 234967.37@dunegpschedd02.fnal.gov

Jobsub ID	234967.37@dunegpschedd02.fnal.gov
Workflow ID	9455
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 18:54:48
Site	US_UChicago
Entry	Engage_US_MWT2_uct2_gk02_condce_mcore
Last heartbeat	2025-10-29 20:50:59
From worker node	Hostname	mwt2-c068.campuscluster.illinois.edu
	cpuinfo	AMD EPYC 7443 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	outputting_failed
Started	2025-10-29 19:26:51
Input files	usertests:pdhd_prod_beam__231691_77_1_20251008T183236Z_gen_g4_IonScintPDExt.root_227038_110_1_20251010T163645Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (4640s)
	CPU time	1h (4428s = 95%)
	Max RSS bytes	6416097280 (6118 MiB)
Outputting started	2025-10-29 20:44:11
Output files
Finished	2025-10-29 20:50:59
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

] 2 tagged trace sets:[ "gauss0":30243 [0] "wiener0":34812 [34812] ] cmm:[ bad:0 lf_noisy:168 ] 
[15:43:42.354] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=89 time=0 tick=512 with 65055 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":30243 [0] "wiener0":34812 [34812] ] cmm:[ bad:0 lf_noisy:168 ] input 1: frame: ident=89 time=0 tick=512 with 28780 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":12654 [0] "wiener1":16126 [16126] ] cmm:[ bad:0 ] input 2: frame: ident=89 time=0 tick=512 with 37035 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":16320 [0] "wiener2":20715 [20715] ] cmm:[ bad:0 lf_noisy:1 ] input 3: frame: ident=89 time=0 tick=512 with 32617 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":14370 [0] "wiener3":18247 [18247] ] cmm:[ bad:0 ] output: frame: ident=89 time=0 tick=512 with 163487 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":30243 [0] "gauss1":12654 [0] "gauss2":16320 [0] "gauss3":14370 [0] "wiener0":34812 [34812] "wiener1":16126 [16126] "wiener2":20715 [20715] "wiener3":18247 [18247] ] cmm:[ bad:0 lf_noisy:169 ] 
Retagger: tagging trace set: wiener with 89900 traces, 89900 summary
Retagger: tagging trace set: gauss with 73587 traces, 0 summary
[15:43:42.367] D [  glue  ] sink frame: #89 @0 with 163487 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[15:43:42.367] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[15:43:42.367] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[15:43:42.367] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[15:43:42.368] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[15:43:42.368] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[15:43:42.368] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[15:43:42.368] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[15:43:42.368] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[15:43:42.368] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[15:43:42.368] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[15:43:42.368] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[15:43:42.368] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[15:43:42.368] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[15:43:42.368] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[15:43:42.368] D [  glue  ] frame sink sees EOS
[15:43:42.368] D [ pgraph ] <Pgrapher:> graph execution complete 
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.93 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.77 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.7 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.4 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.9 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.85 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.84 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.83 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:43:42.368] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[15:43:42.368] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[15:43:42.368] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[15:43:42.368] I [ timer  ] Timer: Total node execution : 51.240000028163195 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 73587 traces tagged "gauss"
FrameSaver: q=2.1939e+06 n=1106898 tag=gauss
wclsFrameSaver: saving 89900 traces tagged "wiener"
FrameSaver: q=2.84877e+06 n=1085871 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 6353 XUs and 4664 XVs -> 310 XUVs
C:0 T:4 0 XUs and 9 XVs -> 0 XUVs
C:0 T:5 49161 XUs and 24668 XVs -> 898 XUVs
C:0 T:6 11904 XUs and 13016 XVs -> 467 XUVs
1675 XUVs total
825 collection wire objects
1675 potential space points
Neighbour search...
43443 tests to find 23944 neighbours
Iterating with no regularization...
Begin: 2.17294e+07
0 2.01741e+07
1 2.01205e+07
2 2.01133e+07
Now with regularization...
Begin: 1.86928e+07
0 1.86897e+07
29-Oct-2025 15:44:10 CDT  Closed output file "pdhd_prod_beam__231691_77_1_20251008T183236Z_gen_g4_IonScintPDExt.root_227038_110_1_20251010T163645Z_PDInt.root_234967_37_1_20251029T192705Z_detsim_reco1.root"
29-Oct-2025 15:44:10 CDT  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           63.3963       81.7049       105.02        79.8226       14.7465        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000984607   0.00356068    0.00627339    0.00311829    0.00183455       10     
reco:wclsdatahd:WireCellToolkit                      42.8197       50.1544       54.6592       53.6692       4.81584        10     
reco:wirefilter:WireFilter                          0.0109652     0.023757      0.0403266     0.0221583    0.00873757       10     
reco:gaushit:GausHitFinder                          0.333839      0.508318      0.719824      0.479051      0.123446        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000185227   0.000285688    0.0004906    0.000246879   9.11435e-05      10     
reco:reco3d:SpacePointSolver                        0.119494      0.389252      0.804597      0.339609      0.198565        10     
reco:hitpdune:DisambigFromSpacePoints                0.12948      0.275492       0.61066      0.235393      0.140793        10     
reco:pandora:StandardPandora                         3.0725        5.78124       11.772        4.93923       2.8092         10     
reco:pandoraWriter:StandardPandora                  0.100644      0.186962      0.309441      0.185006      0.0630337       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.242027      0.598047      0.916573      0.637043      0.239347        10     
reco:pandoraShower:LArPandoraShowerCreation         0.152124      0.466037      0.885597      0.420622      0.257007        10     
reco:pandoracalo:Calorimetry                        0.128935      0.396583      0.706853      0.386643      0.178571        10     
reco:pandoracalonosce:Calorimetry                   0.123979      0.362919      0.614143      0.335402      0.166797        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.153527      0.466694       1.00597      0.379879      0.295637        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.146634      0.451672      0.972678      0.336003      0.289704        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0220795     0.0426921     0.0728528     0.0391868     0.0162357       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0194083     0.0398294     0.067941      0.0366727     0.0145782       10     
reco:emtrkmichelid:EmTrackMichelId                   13.1657       20.4175       31.0701       18.1634       6.20972        10     
[art]:TriggerResults:TriggerResultInserter         4.3281e-05    5.30054e-05   0.000104746   4.7249e-05    1.74609e-05      10     
end_path:out1:RootOutput                            9.047e-06    1.36948e-05   3.4174e-05    1.1832e-05    7.02807e-06      10     
end_path:out1:RootOutput(write)                     0.568192       1.07293       1.49117       1.05666      0.232685        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5554.11 MB
  Peak resident set size usage (VmHWM): 3351.8 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10358360
-rw-r--r-- 1 dune osgvo     230348 Oct 29 15:44 jobscript.log
-rw-r--r-- 1 dune osgvo        201 Oct 29 15:44 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo        519 Oct 29 15:44 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo       3574 Oct 29 15:44 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo     139264 Oct 29 15:44 mem.db
-rw-r--r-- 1 dune osgvo      28672 Oct 29 15:44 time.db
-rw-r--r-- 1 dune osgvo 5368537996 Oct 29 15:44 pdhd_prod_beam__231691_77_1_20251008T183236Z_gen_g4_IonScintPDExt.root_227038_110_1_20251010T163645Z_PDInt.root_234967_37_1_20251029T192705Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo   28285200 Oct 29 15:43 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo          0 Oct 29 15:28 debugprod.log
-rw-r--r-- 1 dune osgvo        519 Oct 29 15:28 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 5209686809 Oct 29 15:28 temp_detsim.root
-rw-r--r-- 1 dune osgvo        122 Oct 29 14:27 all-input-dids.txt