Jobsub ID 268896.162@dunegpschedd01.fnal.gov

Jobsub ID	268896.162@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:03:10
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:20
Input files	usertests:pdhd_prod_beam__267379_156_1_20251212T162420Z_gen_g4_IonScintPDExt.root_262726_162_1_20251215T213957Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (5079s)
	CPU time	1h (4772s = 93%)
	Max RSS bytes	6952001536 (6629 MiB)
Outputting started	2025-12-17 21:02:59
Output files
Finished	2025-12-17 21:03:10
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 49076 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":23581 [0] "wiener0":25495 [25495] ] cmm:[ bad:0 lf_noisy:338 ] input 1: frame: ident=189 time=0 tick=512 with 41509 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":17570 [0] "wiener1":23939 [23939] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 39768 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":18050 [0] "wiener2":21718 [21718] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 34959 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":15067 [0] "wiener3":19892 [19892] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 165312 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":23581 [0] "gauss1":17570 [0] "gauss2":18050 [0] "gauss3":15067 [0] "wiener0":25495 [25495] "wiener1":23939 [23939] "wiener2":21718 [21718] "wiener3":19892 [19892] ] cmm:[ bad:0 lf_noisy:338 ] 
Retagger: tagging trace set: wiener with 91044 traces, 91044 summary
Retagger: tagging trace set: gauss with 74268 traces, 0 summary
[21:02:20.228] D [  glue  ] sink frame: #189 @0 with 165312 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[21:02:20.228] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[21:02:20.228] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[21:02:20.229] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[21:02:20.229] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[21:02:20.229] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[21:02:20.229] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[21:02:20.229] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[21:02:20.229] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[21:02:20.229] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[21:02:20.229] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[21:02:20.229] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[21:02:20.229] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[21:02:20.229] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[21:02:20.229] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[21:02:20.229] D [  glue  ] frame sink sees EOS
[21:02:20.229] D [ pgraph ] <Pgrapher:> graph execution complete 
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.92 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.86 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.77 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.6 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.76 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.66 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.65 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.64 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:02:20.229] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[21:02:20.229] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[21:02:20.229] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:02:20.229] I [ timer  ] Timer: Total node execution : 49.910000847652555 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 74268 traces tagged "gauss"
FrameSaver: q=2.18223e+06 n=1157656 tag=gauss
wclsFrameSaver: saving 91044 traces tagged "wiener"
FrameSaver: q=2.92004e+06 n=1139211 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 41745 XUs and 55655 XVs -> 765 XUVs
C:0 T:3 7 XUs and 16 XVs -> 0 XUVs
C:0 T:5 22858 XUs and 19789 XVs -> 681 XUVs
C:0 T:6 23311 XUs and 36478 XVs -> 532 XUVs
C:0 T:7 13 XUs and 7 XVs -> 0 XUVs
1978 XUVs total
1166 collection wire objects
1978 potential space points
Neighbour search...
36880 tests to find 21012 neighbours
Iterating with no regularization...
Begin: 1.79433e+07
0 1.63919e+07
1 1.62961e+07
2 1.62904e+07
Now with regularization...
Begin: 1.55638e+07
0 1.55617e+07
17-Dec-2025 21:02:56 UTC  Closed output file "pdhd_prod_beam__267379_156_1_20251212T162420Z_gen_g4_IonScintPDExt.root_262726_162_1_20251215T213957Z_PDInt.root_268896_162_1_20251217T193826Z_detsim_reco1.root"
17-Dec-2025 21:02:56 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           85.8384       102.567       124.809       100.097       12.2895        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00116082    0.00330542    0.00514169    0.00333729    0.00138816       10     
reco:wclsdatahd:WireCellToolkit                      50.9954       54.4225       57.4166       54.2098       2.07651        10     
reco:wirefilter:WireFilter                          0.0215644     0.0295741     0.0428299     0.0292711    0.00642011       10     
reco:gaushit:GausHitFinder                          0.465368      0.613812      0.795016      0.583674      0.0997068       10     
reco:nhitsfilter:NumberOfHitsFilter                0.00018049    0.000290697   0.000470009   0.000252492   0.000104168      10     
reco:reco3d:SpacePointSolver                        0.284314       0.6235        1.08697      0.592173      0.240102        10     
reco:hitpdune:DisambigFromSpacePoints               0.327712      0.715337       1.75931      0.642447      0.410211        10     
reco:pandora:StandardPandora                         6.55892       10.6678       17.9278       8.9722        4.11844        10     
reco:pandoraWriter:StandardPandora                  0.170322      0.221358       0.31283      0.213141      0.0418595       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.867555       1.17233       1.52724       1.10897      0.246035        10     
reco:pandoraShower:LArPandoraShowerCreation           0.726        1.1061        1.79051      0.971818      0.354081        10     
reco:pandoracalo:Calorimetry                        0.482113       0.63823      0.816655      0.607759      0.113188        10     
reco:pandoracalonosce:Calorimetry                   0.469557      0.600306      0.783232      0.573261      0.111501        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.743403       1.16183       1.86415      0.967259      0.404756        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.744917       1.16582       1.88388      0.999261      0.411156        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0416892     0.0511328     0.0647421     0.0471655    0.00803305       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0397532     0.0509054     0.0642456     0.0473291    0.00831842       10     
reco:emtrkmichelid:EmTrackMichelId                   20.9002       28.0136       37.7627       26.4456       6.19004        10     
[art]:TriggerResults:TriggerResultInserter         2.7258e-05    4.23416e-05   0.000107865   3.37255e-05   2.27697e-05      10     
end_path:out1:RootOutput                            6.812e-06    1.0058e-05    3.0932e-05    7.8605e-06    6.97521e-06      10     
end_path:out1:RootOutput(write)                     0.974153       1.25493       1.74047       1.22651       0.23879        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5923.34 MB
  Peak resident set size usage (VmHWM): 3765.55 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11899932
-rw-r--r-- 1 dunegli fnalgrid     231143 Dec 17 21:02 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        202 Dec 17 21:02 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 21:02 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 21:02 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 21:02 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 21:02 time.db
-rw-r--r-- 1 dunegli fnalgrid 6166791771 Dec 17 21:02 pdhd_prod_beam__267379_156_1_20251212T162420Z_gen_g4_IonScintPDExt.root_262726_162_1_20251215T213957Z_PDInt.root_268896_162_1_20251217T193826Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   37200810 Dec 17 21:02 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:40 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:39 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 5969178268 Dec 17 20:39 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        123 Dec 17 19:38 all-input-dids.txt