Jobsub ID 234967.9@dunegpschedd02.fnal.gov

Jobsub ID	234967.9@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_condce_mcore
Last heartbeat	2025-10-29 20:58:53
From worker node	Hostname	mwt2-c091.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:10:14
Input files	usertests:pdhd_prod_beam__231691_23_1_20251008T183130Z_gen_g4_IonScintPDExt.root_227038_47_1_20251010T161214Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (6107s)
	CPU time	1h (5892s = 96%)
	Max RSS bytes	10668625920 (10174 MiB)
Outputting started	2025-10-29 20:52:02
Output files
Finished	2025-10-29 20:58:53
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

gproc" ] 2 tagged trace sets:[ "gauss0":27865 [0] "wiener0":31510 [31510] ] cmm:[ bad:0 lf_noisy:234 ] 
[15:51:35.267] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=89 time=0 tick=512 with 59375 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":27865 [0] "wiener0":31510 [31510] ] cmm:[ bad:0 lf_noisy:234 ] input 1: frame: ident=89 time=0 tick=512 with 22577 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":10576 [0] "wiener1":12001 [12001] ] cmm:[ bad:0 ] input 2: frame: ident=89 time=0 tick=512 with 40954 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":17808 [0] "wiener2":23146 [23146] ] cmm:[ bad:0 ] input 3: frame: ident=89 time=0 tick=512 with 37672 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16424 [0] "wiener3":21248 [21248] ] cmm:[ bad:0 ] output: frame: ident=89 time=0 tick=512 with 160578 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":27865 [0] "gauss1":10576 [0] "gauss2":17808 [0] "gauss3":16424 [0] "wiener0":31510 [31510] "wiener1":12001 [12001] "wiener2":23146 [23146] "wiener3":21248 [21248] ] cmm:[ bad:0 lf_noisy:234 ] 
Retagger: tagging trace set: wiener with 87905 traces, 87905 summary
Retagger: tagging trace set: gauss with 72673 traces, 0 summary
[15:51:35.278] D [  glue  ] sink frame: #89 @0 with 160578 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[15:51:35.278] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[15:51:35.278] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[15:51:35.278] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[15:51:35.278] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[15:51:35.278] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[15:51:35.278] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[15:51:35.278] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[15:51:35.278] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[15:51:35.278] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[15:51:35.278] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[15:51:35.278] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[15:51:35.278] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[15:51:35.278] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[15:51:35.278] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[15:51:35.278] D [  glue  ] frame sink sees EOS
[15:51:35.278] D [ pgraph ] <Pgrapher:> graph execution complete 
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.81 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.98 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.98 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.74 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.72 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.67 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.6 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.57 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.02 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:51:35.278] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[15:51:35.278] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[15:51:35.278] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:51:35.278] I [ timer  ] Timer: Total node execution : 42.11000017076731 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 72673 traces tagged "gauss"
FrameSaver: q=1.95063e+06 n=1081493 tag=gauss
wclsFrameSaver: saving 87905 traces tagged "wiener"
FrameSaver: q=2.62351e+06 n=1058537 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 2550 XUs and 2097 XVs -> 171 XUVs
C:0 T:3 3 XUs and 2 XVs -> 0 XUVs
C:0 T:5 37559 XUs and 35341 XVs -> 528 XUVs
C:0 T:6 18756 XUs and 17803 XVs -> 912 XUVs
1611 XUVs total
947 collection wire objects
1611 potential space points
Neighbour search...
25821 tests to find 15386 neighbours
Iterating with no regularization...
Begin: 6.71903e+06
0 6.25074e+06
1 6.21303e+06
2 6.20881e+06
Now with regularization...
Begin: 5.67969e+06
0 5.67858e+06
29-Oct-2025 15:52:01 CDT  Closed output file "pdhd_prod_beam__231691_23_1_20251008T183130Z_gen_g4_IonScintPDExt.root_227038_47_1_20251010T161214Z_PDInt.root_234967_9_1_20251029T191025Z_detsim_reco1.root"
29-Oct-2025 15:52:01 CDT  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           62.217        84.289        118.77        78.707        17.1324        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00118911    0.00369615    0.00733282    0.00353958    0.00182087       10     
reco:wclsdatahd:WireCellToolkit                      43.859        45.3179       47.1209       45.379        1.16313        10     
reco:wirefilter:WireFilter                          0.0124611     0.021059      0.0314541     0.0190966    0.00610484       10     
reco:gaushit:GausHitFinder                          0.316176      0.600861       0.91939      0.596059      0.175689        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000143218   0.000300537   0.000559719   0.000277937   0.000110942      10     
reco:reco3d:SpacePointSolver                        0.128156      0.612745       2.07028      0.321318      0.573925        10     
reco:hitpdune:DisambigFromSpacePoints               0.128274      0.423804       1.04372      0.304051      0.272131        10     
reco:pandora:StandardPandora                         3.37851       9.18514       22.2956       6.69127       5.66466        10     
reco:pandoraWriter:StandardPandora                  0.125635       0.24589      0.441835      0.220022      0.0890555       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.367122      0.923822       2.02605       0.80923      0.468295        10     
reco:pandoraShower:LArPandoraShowerCreation          0.3056        0.93433       2.09756      0.712637      0.598665        10     
reco:pandoracalo:Calorimetry                        0.203177      0.530581       1.11927      0.502091      0.253263        10     
reco:pandoracalonosce:Calorimetry                   0.199428       0.51684       1.11094      0.482442       0.25127        10     
reco:pandoraShowercalo:ShowerCalorimetry             0.28113       1.01255       2.71367      0.772269       0.72989        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.278547      0.978646       2.52793       0.75586      0.695105        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0272398     0.0578054     0.0962728     0.0478709     0.023119        10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0280256     0.057232      0.0960905     0.051658      0.0209649       10     
reco:emtrkmichelid:EmTrackMichelId                   11.4706       21.4878       33.8456       19.3555       6.96406        10     
[art]:TriggerResults:TriggerResultInserter         3.1399e-05    5.10938e-05   9.4086e-05    4.92725e-05   1.75953e-05      10     
end_path:out1:RootOutput                            8.757e-06    1.20607e-05   3.3182e-05     9.583e-06     7.082e-06       10     
end_path:out1:RootOutput(write)                     0.807845       1.30694       1.84692       1.22609      0.342067        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6351.76 MB
  Peak resident set size usage (VmHWM): 4156.79 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 14125520
-rw-r--r-- 1 dune osgvo     230650 Oct 29 15:52 jobscript.log
-rw-r--r-- 1 dune osgvo        200 Oct 29 15:52 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo        519 Oct 29 15:52 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo       3574 Oct 29 15:52 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo     139264 Oct 29 15:52 mem.db
-rw-r--r-- 1 dune osgvo      28672 Oct 29 15:52 time.db
-rw-r--r-- 1 dune osgvo 7313188668 Oct 29 15:52 pdhd_prod_beam__231691_23_1_20251008T183130Z_gen_g4_IonScintPDExt.root_227038_47_1_20251010T161214Z_PDInt.root_234967_9_1_20251029T191025Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo   36798540 Oct 29 15:51 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo          0 Oct 29 15:35 debugprod.log
-rw-r--r-- 1 dune osgvo        519 Oct 29 15:35 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 7114099913 Oct 29 15:35 temp_detsim.root
-rw-r--r-- 1 dune osgvo        121 Oct 29 14:10 all-input-dids.txt