Jobsub ID 234967.29@dunegpschedd02.fnal.gov

Jobsub ID	234967.29@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_iut2_gk02_condce_mcore
Last heartbeat	2025-10-29 21:02:14
From worker node	Hostname	iut2-c391.iu.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:16:32
Input files	usertests:pdhd_prod_beam__226242_43_1_20251008T182818Z_gen_g4_IonScintPDExt.root_227038_49_1_20251010T161417Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (5931s)
	CPU time	1h (5688s = 95%)
	Max RSS bytes	6581714944 (6276 MiB)
Outputting started	2025-10-29 20:55:23
Output files
Finished	2025-10-29 21:02:14
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

0 lf_noisy:155 ] 
[16:54:40.422] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=89 time=0 tick=512 with 56332 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":26746 [0] "wiener0":29586 [29586] ] cmm:[ bad:0 lf_noisy:155 ] input 1: frame: ident=89 time=0 tick=512 with 46147 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":19371 [0] "wiener1":26776 [26776] ] cmm:[ bad:0 ] input 2: frame: ident=89 time=0 tick=512 with 39796 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":16541 [0] "wiener2":23255 [23255] ] cmm:[ bad:0 ] input 3: frame: ident=89 time=0 tick=512 with 35872 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":15236 [0] "wiener3":20636 [20636] ] cmm:[ bad:0 lf_noisy:10 ] output: frame: ident=89 time=0 tick=512 with 178147 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":26746 [0] "gauss1":19371 [0] "gauss2":16541 [0] "gauss3":15236 [0] "wiener0":29586 [29586] "wiener1":26776 [26776] "wiener2":23255 [23255] "wiener3":20636 [20636] ] cmm:[ bad:0 lf_noisy:165 ] 
Retagger: tagging trace set: wiener with 100253 traces, 100253 summary
Retagger: tagging trace set: gauss with 77894 traces, 0 summary
[16:54:40.436] D [  glue  ] sink frame: #89 @0 with 178147 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[16:54:40.436] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[16:54:40.436] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[16:54:40.436] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[16:54:40.436] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[16:54:40.436] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[16:54:40.436] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[16:54:40.436] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[16:54:40.436] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[16:54:40.436] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[16:54:40.436] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[16:54:40.436] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[16:54:40.436] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[16:54:40.436] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[16:54:40.436] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[16:54:40.436] D [  glue  ] frame sink sees EOS
[16:54:40.436] D [ pgraph ] <Pgrapher:> graph execution complete 
[16:54:40.436] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.71 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.84 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.63 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.55 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.91 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.86 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.86 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.77 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:54:40.437] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:54:40.437] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:54:40.437] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[16:54:40.437] I [ timer  ] Timer: Total node execution : 46.18000035174191 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 77894 traces tagged "gauss"
FrameSaver: q=2.53691e+06 n=1233285 tag=gauss
wclsFrameSaver: saving 100253 traces tagged "wiener"
FrameSaver: q=3.07449e+06 n=1202880 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 39860 XUs and 31962 XVs -> 3720 XUVs
C:0 T:3 28 XUs and 32 XVs -> 1 XUVs
C:0 T:5 46550 XUs and 55657 XVs -> 1730 XUVs
C:0 T:6 16805 XUs and 35227 XVs -> 3654 XUVs
C:0 T:7 7 XUs and 21 XVs -> 2 XUVs
9107 XUVs total
2149 collection wire objects
9107 potential space points
Neighbour search...
731347 tests to find 447770 neighbours
Iterating with no regularization...
Begin: 2.1404e+07
0 1.89262e+07
1 1.86848e+07
2 1.8638e+07
3 1.86207e+07
Now with regularization...
Begin: 1.6577e+07
0 1.65645e+07
29-Oct-2025 16:55:22 EDT  Closed output file "pdhd_prod_beam__226242_43_1_20251008T182818Z_gen_g4_IonScintPDExt.root_227038_49_1_20251010T161417Z_PDInt.root_234967_29_1_20251029T191642Z_detsim_reco1.root"
29-Oct-2025 16:55:22 EDT  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           72.1688       92.8446       110.126       93.3139       9.96987        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00119109    0.00424003    0.00697383    0.00466793    0.00167977       10     
reco:wclsdatahd:WireCellToolkit                      47.014        49.0696       50.6835       49.216        1.27072        10     
reco:wirefilter:WireFilter                          0.0113647     0.0288481     0.0494357     0.0274813     0.010709        10     
reco:gaushit:GausHitFinder                           0.36664       0.68899       0.90718       0.72243      0.144921        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000201899   0.00033321    0.000595943   0.000332855   0.000102676      10     
reco:reco3d:SpacePointSolver                        0.177972      0.620757      0.948293      0.636296      0.218008        10     
reco:hitpdune:DisambigFromSpacePoints               0.185423      0.545132      0.972548      0.533323      0.234877        10     
reco:pandora:StandardPandora                         4.69857       9.67296       15.7158       9.30605       2.71292        10     
reco:pandoraWriter:StandardPandora                  0.165942      0.248669      0.344273      0.248088      0.0469747       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.703474       1.16032       1.56587       1.15854      0.254378        10     
reco:pandoraShower:LArPandoraShowerCreation         0.408878       1.12924       1.82944       1.20621      0.397462        10     
reco:pandoracalo:Calorimetry                        0.375463      0.656233      0.877286      0.661594      0.150716        10     
reco:pandoracalonosce:Calorimetry                   0.353595      0.618056      0.854218      0.627422      0.150473        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.389152       1.11933       1.92965       1.14993      0.426064        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.391108       1.10752       1.87863       1.1338       0.411293        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0414175     0.066281      0.0869351     0.0682407     0.0133379       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0423275     0.0644751     0.0872837     0.0662135     0.0129008       10     
reco:emtrkmichelid:EmTrackMichelId                   15.8835       24.6168       30.7253       25.5296       4.35693        10     
[art]:TriggerResults:TriggerResultInserter         3.8863e-05    5.41689e-05   0.000121489   4.4003e-05    2.42085e-05      10     
end_path:out1:RootOutput                            8.697e-06    1.62246e-05   4.1038e-05    1.09805e-05   1.14877e-05      10     
end_path:out1:RootOutput(write)                     0.895766       1.34407       1.64323       1.38218       0.21801        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5826.76 MB
  Peak resident set size usage (VmHWM): 3621.14 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11559168
-rw-r--r--. 1 dune osgvo     230676 Oct 29 16:55 jobscript.log
-rw-r--r--. 1 dune osgvo        194 Oct 29 16:55 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo        519 Oct 29 16:55 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo       3574 Oct 29 16:55 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo     139264 Oct 29 16:55 mem.db
-rw-r--r--. 1 dune osgvo      28672 Oct 29 16:55 time.db
-rw-r--r--. 1 dune osgvo 6000252834 Oct 29 16:55 pdhd_prod_beam__226242_43_1_20251008T182818Z_gen_g4_IonScintPDExt.root_227038_49_1_20251010T161417Z_PDInt.root_234967_29_1_20251029T191642Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo   37780950 Oct 29 16:54 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo          0 Oct 29 16:38 debugprod.log
-rw-r--r--. 1 dune osgvo        519 Oct 29 16:38 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 5798107044 Oct 29 16:37 temp_detsim.root
-rw-r--r--. 1 dune osgvo        121 Oct 29 15:16 all-input-dids.txt