Jobsub ID 268896.161@dunegpschedd01.fnal.gov

Jobsub ID	268896.161@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_ce03_mcore_op_duneonly
Last heartbeat	2025-12-17 21:00:36
From worker node	Hostname	dunegli-7943973-0-fnpc9025.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:38:28
Input files	usertests:pdhd_prod_beam__267379_98_1_20251212T162024Z_gen_g4_IonScintPDExt.root_262726_123_1_20251215T212747Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (4916s)
	CPU time	1h (4723s = 96%)
	Max RSS bytes	6953586688 (6631 MiB)
Outputting started	2025-12-17 21:00:24
Output files
Finished	2025-12-17 21:00:36
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

oisy:139 ] 
[20:59:45.632] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 53898 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":26079 [0] "wiener0":27819 [27819] ] cmm:[ bad:0 lf_noisy:139 ] input 1: frame: ident=189 time=0 tick=512 with 27843 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":12800 [0] "wiener1":15043 [15043] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 46251 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":19381 [0] "wiener2":26870 [26870] ] cmm:[ bad:0 lf_noisy:1 ] input 3: frame: ident=189 time=0 tick=512 with 46249 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":19170 [0] "wiener3":27079 [27079] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 174241 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":26079 [0] "gauss1":12800 [0] "gauss2":19381 [0] "gauss3":19170 [0] "wiener0":27819 [27819] "wiener1":15043 [15043] "wiener2":26870 [26870] "wiener3":27079 [27079] ] cmm:[ bad:0 lf_noisy:140 ] 
Retagger: tagging trace set: wiener with 96811 traces, 96811 summary
Retagger: tagging trace set: gauss with 77430 traces, 0 summary
[20:59:45.655] D [  glue  ] sink frame: #189 @0 with 174241 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:59:45.656] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:59:45.656] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:59:45.656] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:59:45.656] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:59:45.656] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:59:45.656] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:59:45.656] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:59:45.656] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:59:45.656] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:59:45.656] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:59:45.656] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:59:45.656] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:59:45.656] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:59:45.656] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:59:45.656] D [  glue  ] frame sink sees EOS
[20:59:45.656] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.22 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.57 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.54 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.14 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.74 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.7 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.66 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.65 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:59:45.656] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:59:45.656] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:59:45.656] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:59:45.656] I [ timer  ] Timer: Total node execution : 57.2700005043298 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 77430 traces tagged "gauss"
FrameSaver: q=2.42912e+06 n=1204198 tag=gauss
wclsFrameSaver: saving 96811 traces tagged "wiener"
FrameSaver: q=3.232e+06 n=1182058 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 4610 XUs and 7375 XVs -> 246 XUVs
C:0 T:4 6 XUs and 1 XVs -> 0 XUVs
C:0 T:5 20347 XUs and 21024 XVs -> 1213 XUVs
C:0 T:6 23659 XUs and 25441 XVs -> 833 XUVs
2292 XUVs total
1315 collection wire objects
2292 potential space points
Neighbour search...
30198 tests to find 17422 neighbours
Iterating with no regularization...
Begin: 2.16211e+07
0 2.08369e+07
1 2.07812e+07
2 2.07754e+07
Now with regularization...
Begin: 1.92762e+07
0 1.92752e+07
17-Dec-2025 21:00:20 UTC  Closed output file "pdhd_prod_beam__267379_98_1_20251212T162024Z_gen_g4_IonScintPDExt.root_262726_123_1_20251215T212747Z_PDInt.root_268896_161_1_20251217T193831Z_detsim_reco1.root"
17-Dec-2025 21:00:20 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           85.1784       100.908       118.249       97.9181       11.4092        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000933959   0.00355461    0.00614491     0.0036509    0.00165702       10     
reco:wclsdatahd:WireCellToolkit                      54.2226       58.8981       66.8612       58.8794       3.76191        10     
reco:wirefilter:WireFilter                          0.0216848     0.0309407      0.03603      0.0312745    0.00427462       10     
reco:gaushit:GausHitFinder                          0.402117       0.62874      0.912805       0.60795      0.156932        10     
reco:nhitsfilter:NumberOfHitsFilter                0.00011905    0.000285925   0.000614906    0.0002383    0.000135568      10     
reco:reco3d:SpacePointSolver                        0.0994608     0.495428       1.21374      0.427763      0.305375        10     
reco:hitpdune:DisambigFromSpacePoints               0.114793      0.618136       1.15455      0.563526      0.304195        10     
reco:pandora:StandardPandora                         3.76726       8.38517       14.2541       6.9271        3.39837        10     
reco:pandoraWriter:StandardPandora                  0.114729       0.28427       1.16353      0.185647      0.295697        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.464402       1.04058       1.58341       1.01848      0.392104        10     
reco:pandoraShower:LArPandoraShowerCreation         0.315523       1.19741       1.95671      0.992538       0.54679        10     
reco:pandoracalo:Calorimetry                        0.245491      0.556965      0.794192      0.578999      0.187702        10     
reco:pandoracalonosce:Calorimetry                   0.230878      0.535478      0.775436      0.567285      0.176891        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.245767       1.00391       1.58337      0.871296      0.432505        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.239421       0.99913       1.64096      0.873046      0.437252        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0242809     0.0509358     0.0675841     0.0505971     0.0130045       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0238519     0.0509185     0.065933      0.0504744     0.0125062       10     
reco:emtrkmichelid:EmTrackMichelId                   14.8894       24.6852       37.0714       22.9071       7.77563        10     
[art]:TriggerResults:TriggerResultInserter         2.8694e-05     4.06e-05     7.1942e-05    3.86875e-05   1.24279e-05      10     
end_path:out1:RootOutput                            7.184e-06    1.02092e-05   2.4444e-05     9.276e-06    4.82787e-06      10     
end_path:out1:RootOutput(write)                     0.664799       1.39741       1.91769       1.48119      0.355649        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6203.3 MB
  Peak resident set size usage (VmHWM): 4040.3 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11482156
-rw-r--r-- 1 dunegli fnalgrid     231246 Dec 17 21:00 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        201 Dec 17 21:00 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 21:00 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 21:00 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 21:00 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 21:00 time.db
-rw-r--r-- 1 dunegli fnalgrid 5949683597 Dec 17 21:00 pdhd_prod_beam__267379_98_1_20251212T162024Z_gen_g4_IonScintPDExt.root_262726_123_1_20251215T212747Z_PDInt.root_268896_161_1_20251217T193831Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   33981000 Dec 17 20:59 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:41 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:40 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 5762118170 Dec 17 20:40 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        122 Dec 17 19:38 all-input-dids.txt