Jobsub ID 268896.144@dunegpschedd01.fnal.gov

Jobsub ID	268896.144@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:56:31
From worker node	Hostname	dunegli-8100549-0-fnpc9059.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:31:29
Input files	usertests:pdhd_prod_beam__267379_67_1_20251212T161159Z_gen_g4_IonScintPDExt.root_262726_66_1_20251215T212433Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (5089s)
	CPU time	1h (4467s = 87%)
	Max RSS bytes	6831714304 (6515 MiB)
Outputting started	2025-12-17 20:56:20
Output files
Finished	2025-12-17 20:56:31
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

[20:55:29.593] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 60744 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":28632 [0] "wiener0":32112 [32112] ] cmm:[ bad:0 lf_noisy:232 ] input 1: frame: ident=189 time=0 tick=512 with 43600 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":18881 [0] "wiener1":24719 [24719] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 47064 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":19741 [0] "wiener2":27323 [27323] ] cmm:[ bad:0 lf_noisy:1 ] input 3: frame: ident=189 time=0 tick=512 with 32386 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":14379 [0] "wiener3":18007 [18007] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 183794 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":28632 [0] "gauss1":18881 [0] "gauss2":19741 [0] "gauss3":14379 [0] "wiener0":32112 [32112] "wiener1":24719 [24719] "wiener2":27323 [27323] "wiener3":18007 [18007] ] cmm:[ bad:0 lf_noisy:233 ] 
Retagger: tagging trace set: wiener with 102161 traces, 102161 summary
Retagger: tagging trace set: gauss with 81633 traces, 0 summary
[20:55:29.619] D [  glue  ] sink frame: #189 @0 with 183794 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:55:29.619] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:55:29.619] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:55:29.619] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:55:29.619] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:55:29.619] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:55:29.619] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:55:29.619] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:55:29.619] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:55:29.619] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:55:29.619] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:55:29.619] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:55:29.619] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:55:29.619] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:55:29.619] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:55:29.619] D [  glue  ] frame sink sees EOS
[20:55:29.619] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.74 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.22 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.89 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.85 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.78 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.68 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.67 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.66 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.02 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:55:29.619] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:55:29.619] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:55:29.619] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:55:29.619] I [ timer  ] Timer: Total node execution : 55.56000096164644 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 81633 traces tagged "gauss"
FrameSaver: q=2.72103e+06 n=1297796 tag=gauss
wclsFrameSaver: saving 102161 traces tagged "wiener"
FrameSaver: q=3.77155e+06 n=1264877 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 33119 XUs and 21306 XVs -> 603 XUVs
C:0 T:4 58 XUs and 38 XVs -> 3 XUVs
C:0 T:5 53661 XUs and 29530 XVs -> 938 XUVs
C:0 T:6 9639 XUs and 8118 XVs -> 196 XUVs
1740 XUVs total
1052 collection wire objects
1740 potential space points
Neighbour search...
18252 tests to find 11064 neighbours
Iterating with no regularization...
Begin: 1.91736e+07
0 1.84576e+07
1 1.84047e+07
2 1.83997e+07
Now with regularization...
Begin: 1.73806e+07
0 1.73795e+07
17-Dec-2025 20:56:12 UTC  Closed output file "pdhd_prod_beam__267379_67_1_20251212T161159Z_gen_g4_IonScintPDExt.root_262726_66_1_20251215T212433Z_PDInt.root_268896_144_1_20251217T193133Z_detsim_reco1.root"
17-Dec-2025 20:56:12 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           70.5574       95.6569       110.413       99.1919       12.8281        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000921944   0.00548819     0.0191172    0.00402867     0.004937        10     
reco:wclsdatahd:WireCellToolkit                      54.5956       57.4576       60.1864       57.7527       1.70408        10     
reco:wirefilter:WireFilter                          0.0190196     0.0293804     0.0378904     0.0305323    0.00590046       10     
reco:gaushit:GausHitFinder                          0.249237      0.531413      0.759732      0.587997      0.149334        10     
reco:nhitsfilter:NumberOfHitsFilter                9.3527e-05    0.000233808   0.000575423   0.000207057   0.000128624      10     
reco:reco3d:SpacePointSolver                        0.254875      0.530113      0.990306      0.453089      0.259904        10     
reco:hitpdune:DisambigFromSpacePoints                0.12542      0.473684       0.92775      0.440943      0.241921        10     
reco:pandora:StandardPandora                         1.78605       8.54864       13.2185       9.03892       3.30144        10     
reco:pandoraWriter:StandardPandora                  0.118873      0.343216       1.08475       0.26186       0.26221        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.389319       1.25525       2.01714       1.38857       0.54949        10     
reco:pandoraShower:LArPandoraShowerCreation         0.173177       1.00457       2.1613        1.0985       0.577877        10     
reco:pandoracalo:Calorimetry                        0.195321      0.618477      0.995821      0.689847      0.259459        10     
reco:pandoracalonosce:Calorimetry                   0.182993      0.581054      0.839822      0.658998      0.229653        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.160069      0.923306       1.97642       1.07935      0.529054        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.160205      0.878528       1.5929        1.04793      0.460374        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0240422     0.0442758     0.0598251     0.0458055     0.0118909       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0244847     0.0445424     0.0587769     0.0475109     0.0115034       10     
reco:emtrkmichelid:EmTrackMichelId                   10.2071       21.1719       31.1113       21.616        6.26178        10     
[art]:TriggerResults:TriggerResultInserter         2.5998e-05    4.03239e-05   8.5874e-05    3.03275e-05   1.93761e-05      10     
end_path:out1:RootOutput                            7.905e-06    1.11051e-05   2.4657e-05    8.4685e-06    5.48887e-06      10     
end_path:out1:RootOutput(write)                     0.596363       1.16601       1.5406        1.22452       0.28014        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5971.14 MB
  Peak resident set size usage (VmHWM): 3802.88 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11866224
-rw-r--r-- 1 dunegli fnalgrid     231172 Dec 17 20:56 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        200 Dec 17 20:56 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:56 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:56 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:56 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:56 time.db
-rw-r--r-- 1 dunegli fnalgrid 6147386508 Dec 17 20:56 pdhd_prod_beam__267379_67_1_20251212T161159Z_gen_g4_IonScintPDExt.root_262726_66_1_20251215T212433Z_PDInt.root_268896_144_1_20251217T193133Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   32173260 Dec 17 20:55 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:35 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:35 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 5970986581 Dec 17 20:35 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        121 Dec 17 19:31 all-input-dids.txt