Jobsub ID 268896.42@dunegpschedd01.fnal.gov

Jobsub ID	268896.42@dunegpschedd01.fnal.gov
Workflow ID	11239
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 17:53:51
Site	US_FNAL-T1
Entry	CMSHTPC_T1_US_FNAL_condce_opp1_whole
Last heartbeat	2025-12-17 20:48:10
From worker node	Hostname	dunegli-49199-0-cmswn2413.fnal.gov
	cpuinfo	AMD EPYC 7551 32-Core Processor
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	171000 (47 hours)
	GPU
	Inner Apptainer?	True
Job state	outputting_failed
Started	2025-12-17 18:32:42
Input files	usertests:pdhd_prod_beam__267379_34_1_20251212T160842Z_gen_g4_IonScintPDExt.root_262726_34_1_20251215T212455Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (8033s)
	CPU time	1h (6166s = 76%)
	Max RSS bytes	9182158848 (8756 MiB)
Outputting started	2025-12-17 20:46:36
Output files
Finished	2025-12-17 20:48:10
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 71134 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":33589 [0] "wiener0":37545 [37545] ] cmm:[ bad:0 lf_noisy:84 ] input 1: frame: ident=189 time=0 tick=512 with 44198 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":18819 [0] "wiener1":25379 [25379] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 43913 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":18360 [0] "wiener2":25553 [25553] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 56571 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":23268 [0] "wiener3":33303 [33303] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 215816 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":33589 [0] "gauss1":18819 [0] "gauss2":18360 [0] "gauss3":23268 [0] "wiener0":37545 [37545] "wiener1":25379 [25379] "wiener2":25553 [25553] "wiener3":33303 [33303] ] cmm:[ bad:0 lf_noisy:84 ] 
Retagger: tagging trace set: wiener with 121780 traces, 121780 summary
Retagger: tagging trace set: gauss with 94036 traces, 0 summary
[20:45:32.088] D [  glue  ] sink frame: #189 @0 with 215816 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:45:32.088] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:45:32.088] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:45:32.088] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:45:32.088] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:45:32.088] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:45:32.088] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:45:32.088] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:45:32.088] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:45:32.088] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:45:32.088] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:45:32.088] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:45:32.088] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:45:32.088] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:45:32.088] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:45:32.089] D [  glue  ] frame sink sees EOS
[20:45:32.089] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.69 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.1 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.02 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.57 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.06 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.84 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.83 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.79 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:45:32.089] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:45:32.089] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:45:32.089] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:45:32.089] I [ timer  ] Timer: Total node execution : 42.92999937944114 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 94036 traces tagged "gauss"
FrameSaver: q=3.3305e+06 n=1496506 tag=gauss
wclsFrameSaver: saving 121780 traces tagged "wiener"
FrameSaver: q=4.324e+06 n=1427604 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 49746 XUs and 33969 XVs -> 1369 XUVs
C:0 T:3 2 XUs and 0 XVs -> 0 XUVs
C:0 T:4 3 XUs and 9 XVs -> 0 XUVs
C:0 T:5 29775 XUs and 59929 XVs -> 1731 XUVs
C:0 T:6 65136 XUs and 32548 XVs -> 1420 XUVs
C:0 T:7 29 XUs and 30 XVs -> 0 XUVs
4520 XUVs total
2094 collection wire objects
4520 potential space points
Neighbour search...
159472 tests to find 100772 neighbours
Iterating with no regularization...
Begin: 2.95029e+07
0 2.70088e+07
1 2.68577e+07
2 2.6839e+07
Now with regularization...
Begin: 2.51029e+07
0 2.50973e+07
17-Dec-2025 20:46:34 UTC  Closed output file "pdhd_prod_beam__267379_34_1_20251212T160842Z_gen_g4_IonScintPDExt.root_262726_34_1_20251215T212455Z_PDInt.root_268896_42_1_20251217T183247Z_detsim_reco1.root"
17-Dec-2025 20:46:34 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           70.4694       84.5615       105.167       85.6293       10.0539        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                              0.001227      0.0279614     0.254995     0.00297946     0.0756841       10     
reco:wclsdatahd:WireCellToolkit                      42.3644       44.1635       49.7639       43.4046       2.23098        10     
reco:wirefilter:WireFilter                          0.0126648     0.0155642     0.0180536     0.0159763    0.00158763       10     
reco:gaushit:GausHitFinder                          0.385041      0.512186       0.71967      0.480883      0.117299        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000172751   0.000270515   0.000424933   0.000252011   8.08209e-05      10     
reco:reco3d:SpacePointSolver                        0.188821      0.474707       1.27452      0.397645      0.310415        10     
reco:hitpdune:DisambigFromSpacePoints               0.168347      0.321149      0.497926      0.325548      0.114679        10     
reco:pandora:StandardPandora                         3.20539       6.35451       11.8847       5.95914       2.48161        10     
reco:pandoraWriter:StandardPandora                  0.122321       0.24417      0.909066       0.17409      0.226863        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.468032      0.789849       1.42483      0.755936      0.243333        10     
reco:pandoraShower:LArPandoraShowerCreation         0.387224      0.779729       1.42679      0.620808      0.341984        10     
reco:pandoracalo:Calorimetry                        0.238263      0.396092      0.612104      0.375721      0.0953897       10     
reco:pandoracalonosce:Calorimetry                   0.231102       0.36514      0.502598       0.35562      0.0753219       10     
reco:pandoraShowercalo:ShowerCalorimetry            0.383431      0.711316       1.34979      0.542002      0.347858        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.401688      0.699612       1.29254      0.542241      0.300758        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0334967     0.0437466     0.0587954     0.0419305    0.00815785       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0322645     0.0429162     0.0596164     0.039944     0.00860291       10     
reco:emtrkmichelid:EmTrackMichelId                   20.1434       27.456        38.9548       27.2569       5.8186         10     
[art]:TriggerResults:TriggerResultInserter          1.991e-05    3.17382e-05   9.2461e-05    2.5685e-05    2.04376e-05      10     
end_path:out1:RootOutput                            6.39e-06     9.6971e-06     2.937e-05     6.88e-06     6.85452e-06      10     
end_path:out1:RootOutput(write)                     0.905725       1.12238       1.40851       1.09314      0.184233        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6154.9 MB
  Peak resident set size usage (VmHWM): 3942.33 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 13141520
-rw-r--r-- 1 dunegli fnalgrid     231340 Dec 17 20:46 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        200 Dec 17 20:46 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:46 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:46 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:46 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:46 time.db
-rw-r--r-- 1 dunegli fnalgrid 6803430783 Dec 17 20:46 pdhd_prod_beam__267379_34_1_20251212T160842Z_gen_g4_IonScintPDExt.root_262726_34_1_20251215T212455Z_PDInt.root_268896_42_1_20251217T183247Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   33822930 Dec 17 20:45 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:12 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:12 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 6619207572 Dec 17 20:12 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        121 Dec 17 18:32 all-input-dids.txt