Jobsub ID 268896.134@dunegpschedd01.fnal.gov

Jobsub ID	268896.134@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-FermiGrid
Entry	FNAL_GPGrid_ce04_mcore_op_duneonly
Last heartbeat	2025-12-17 20:48:11
From worker node	Hostname	dunegli-8092434-0-fnpc9041.fnal.gov
	cpuinfo	Intel(R) Xeon(R) CPU E5-2680 v4 @ 2.40GHz
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	172800 (48 hours)
	GPU
	Inner Apptainer?	True
Job state	outputting_failed
Started	2025-12-17 19:23:30
Input files	usertests:pdhd_prod_beam__267379_27_1_20251212T160808Z_gen_g4_IonScintPDExt.root_262726_117_1_20251215T212450Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (5019s)
	CPU time	1h (4940s = 98%)
	Max RSS bytes	7411462144 (7068 MiB)
Outputting started	2025-12-17 20:47:09
Output files
Finished	2025-12-17 20:48:11
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

t 0: frame: ident=189 time=0 tick=512 with 38877 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":18334 [0] "wiener0":20543 [20543] ] cmm:[ bad:0 lf_noisy:71 ] input 1: frame: ident=189 time=0 tick=512 with 35060 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":14910 [0] "wiener1":20150 [20150] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 35994 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":15308 [0] "wiener2":20686 [20686] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 39862 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":17563 [0] "wiener3":22299 [22299] ] cmm:[ bad:0 lf_noisy:4 ] output: frame: ident=189 time=0 tick=512 with 149793 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":18334 [0] "gauss1":14910 [0] "gauss2":15308 [0] "gauss3":17563 [0] "wiener0":20543 [20543] "wiener1":20150 [20150] "wiener2":20686 [20686] "wiener3":22299 [22299] ] cmm:[ bad:0 lf_noisy:75 ] 
Retagger: tagging trace set: wiener with 83678 traces, 83678 summary
Retagger: tagging trace set: gauss with 66115 traces, 0 summary
[20:46:26.900] D [  glue  ] sink frame: #189 @0 with 149793 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:46:26.900] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:46:26.900] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:46:26.900] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:46:26.900] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:46:26.900] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:46:26.900] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:46:26.900] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:46:26.900] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:46:26.900] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:46:26.900] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:46:26.900] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:46:26.900] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:46:26.900] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:46:26.900] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:46:26.900] D [  glue  ] frame sink sees EOS
[20:46:26.900] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.64 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.71 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.64 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.64 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.7 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.68 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.68 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.67 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.02 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:46:26.900] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:46:26.901] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:46:26.901] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:46:26.901] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:46:26.901] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:46:26.901] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:46:26.901] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:46:26.901] I [ timer  ] Timer: Total node execution : 53.41000132448971 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 66115 traces tagged "gauss"
FrameSaver: q=1.96546e+06 n=999221 tag=gauss
wclsFrameSaver: saving 83678 traces tagged "wiener"
FrameSaver: q=2.42899e+06 n=976187 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 36088 XUs and 47142 XVs -> 1944 XUVs
C:0 T:3 8 XUs and 14 XVs -> 4 XUVs
C:0 T:4 4 XUs and 8 XVs -> 0 XUVs
C:0 T:5 12617 XUs and 13546 XVs -> 852 XUVs
C:0 T:6 28137 XUs and 43459 XVs -> 1726 XUVs
C:0 T:7 1 XUs and 12 XVs -> 0 XUVs
4526 XUVs total
1221 collection wire objects
4526 potential space points
Neighbour search...
476054 tests to find 248934 neighbours
Iterating with no regularization...
Begin: 2.71896e+07
0 2.59827e+07
1 2.58758e+07
2 2.58614e+07
Now with regularization...
Begin: 2.42221e+07
0 2.42171e+07
17-Dec-2025 20:47:07 UTC  Closed output file "pdhd_prod_beam__267379_27_1_20251212T160808Z_gen_g4_IonScintPDExt.root_262726_117_1_20251215T212450Z_PDInt.root_268896_134_1_20251217T192339Z_detsim_reco1.root"
17-Dec-2025 20:47:07 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           93.6776       113.129       142.17        111.05        14.3879        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00103149    0.00435936    0.00715463    0.00470812    0.00199565       10     
reco:wclsdatahd:WireCellToolkit                      53.2281       58.6049       71.8359       55.2526       6.81925        10     
reco:wirefilter:WireFilter                          0.0233441     0.029163      0.0407627     0.0273948    0.00571605       10     
reco:gaushit:GausHitFinder                          0.464297      0.630292       0.93308      0.550683      0.167599        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000163646   0.000265599   0.000347302   0.000283416   6.72216e-05      10     
reco:reco3d:SpacePointSolver                        0.224164      0.666585       1.64296      0.552453      0.412111        10     
reco:hitpdune:DisambigFromSpacePoints               0.265654      0.656097       1.27129      0.524658      0.363599        10     
reco:pandora:StandardPandora                         5.27028       11.8235       25.1418       8.47847       6.05375        10     
reco:pandoraWriter:StandardPandora                  0.166867      0.247554       0.33884       0.24336      0.0521138       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.516859        1.261        2.21555       1.1631       0.504849        10     
reco:pandoraShower:LArPandoraShowerCreation         0.580237       1.32612       2.23566       1.15448      0.600528        10     
reco:pandoracalo:Calorimetry                        0.321235       0.67876       1.10092      0.682158      0.235119        10     
reco:pandoracalonosce:Calorimetry                   0.303946       0.67326       1.07405      0.689869      0.238217        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.583661       1.35185       2.24762       1.15194      0.619795        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.554963       1.31395       2.14319       1.18202      0.580508        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0363243     0.0498881     0.0643641     0.0490683    0.00877466       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0334161     0.0499337     0.0661975     0.0497175    0.00934975       10     
reco:emtrkmichelid:EmTrackMichelId                   21.0853       32.0647       48.0278       30.7446       7.24058        10     
[art]:TriggerResults:TriggerResultInserter         2.1594e-05    3.60644e-05    5.68e-05     3.53425e-05   1.00663e-05      10     
end_path:out1:RootOutput                            3.626e-06    7.5048e-06    1.7493e-05     5.24e-06     4.18503e-06      10     
end_path:out1:RootOutput(write)                     0.854569       1.65159       2.41037       1.73394      0.510598        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5884.4 MB
  Peak resident set size usage (VmHWM): 3714.94 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12336160
-rw-r--r-- 1 dunegli fnalgrid     231948 Dec 17 20:47 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        201 Dec 17 20:47 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:47 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:47 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:47 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:47 time.db
-rw-r--r-- 1 dunegli fnalgrid 6388621227 Dec 17 20:47 pdhd_prod_beam__267379_27_1_20251212T160808Z_gen_g4_IonScintPDExt.root_262726_117_1_20251215T212450Z_PDInt.root_268896_134_1_20251217T192339Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   36667200 Dec 17 20:46 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:26 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:25 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 6194149459 Dec 17 20:25 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        122 Dec 17 19:23 all-input-dids.txt