Jobsub ID 268896.120@dunegpschedd01.fnal.gov

Jobsub ID	268896.120@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:59:38
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:14:40
Input files	usertests:pdhd_prod_beam__267379_118_1_20251212T162138Z_gen_g4_IonScintPDExt.root_262726_161_1_20251215T213903Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (6287s)
	CPU time	1h (4744s = 75%)
	Max RSS bytes	6699429888 (6389 MiB)
Outputting started	2025-12-17 20:59:28
Output files
Finished	2025-12-17 20:59:38
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 51426 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":24517 [0] "wiener0":26909 [26909] ] cmm:[ bad:0 lf_noisy:107 ] input 1: frame: ident=189 time=0 tick=512 with 37844 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":16743 [0] "wiener1":21101 [21101] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 31657 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":14342 [0] "wiener2":17315 [17315] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 43275 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":18768 [0] "wiener3":24507 [24507] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 164202 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":24517 [0] "gauss1":16743 [0] "gauss2":14342 [0] "gauss3":18768 [0] "wiener0":26909 [26909] "wiener1":21101 [21101] "wiener2":17315 [17315] "wiener3":24507 [24507] ] cmm:[ bad:0 lf_noisy:107 ] 
Retagger: tagging trace set: wiener with 89832 traces, 89832 summary
Retagger: tagging trace set: gauss with 74370 traces, 0 summary
[20:58:41.475] D [  glue  ] sink frame: #189 @0 with 164202 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:58:41.475] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:58:41.475] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:58:41.475] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:58:41.475] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:58:41.475] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:58:41.475] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:58:41.475] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:58:41.475] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:58:41.475] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:58:41.475] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:58:41.475] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:58:41.475] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:58:41.475] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:58:41.475] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:58:41.475] D [  glue  ] frame sink sees EOS
[20:58:41.475] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.75 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.47 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.33 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.29 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.71 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.71 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.7 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.64 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:58:41.475] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:58:41.476] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:58:41.476] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:41.476] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:58:41.476] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:58:41.476] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:58:41.476] I [ timer  ] Timer: Total node execution : 52.68000037968159 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 74370 traces tagged "gauss"
FrameSaver: q=2.51342e+06 n=1202217 tag=gauss
wclsFrameSaver: saving 89832 traces tagged "wiener"
FrameSaver: q=3.21732e+06 n=1180603 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 13823 XUs and 11527 XVs -> 498 XUVs
C:0 T:3 0 XUs and 3 XVs -> 0 XUVs
C:0 T:4 1 XUs and 5 XVs -> 0 XUVs
C:0 T:5 11514 XUs and 13399 XVs -> 563 XUVs
C:0 T:6 26141 XUs and 43435 XVs -> 1702 XUVs
2763 XUVs total
1647 collection wire objects
2763 potential space points
Neighbour search...
191493 tests to find 64912 neighbours
Iterating with no regularization...
Begin: 6.39591e+07
0 5.93801e+07
1 5.90411e+07
2 5.9006e+07
Now with regularization...
Begin: 5.47573e+07
0 5.47313e+07
17-Dec-2025 20:59:19 UTC  Closed output file "pdhd_prod_beam__267379_118_1_20251212T162138Z_gen_g4_IonScintPDExt.root_262726_161_1_20251215T213903Z_PDInt.root_268896_120_1_20251217T191614Z_detsim_reco1.root"
17-Dec-2025 20:59:19 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           88.3578       97.2948       112.731       94.9951       8.3842         10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000956961   0.00621328     0.023642     0.00464523    0.00604601       10     
reco:wclsdatahd:WireCellToolkit                      54.1533       57.1479       59.8945       57.1957       2.07626        10     
reco:wirefilter:WireFilter                          0.0258344     0.0302204     0.0372517     0.0292534    0.00370556       10     
reco:gaushit:GausHitFinder                          0.504412      0.605908       0.82442      0.587479      0.0973043       10     
reco:nhitsfilter:NumberOfHitsFilter                0.000163225   0.00026285    0.000375936   0.000257059   7.18687e-05      10     
reco:reco3d:SpacePointSolver                        0.230675      0.482149      0.811248       0.48528      0.187293        10     
reco:hitpdune:DisambigFromSpacePoints               0.281138      0.566336       1.08516      0.502735      0.215533        10     
reco:pandora:StandardPandora                         5.45319       8.28584       14.8278       6.96674       3.12725        10     
reco:pandoraWriter:StandardPandora                  0.138284      0.239728      0.632065      0.196697      0.136268        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.660536       1.10037       1.86191       1.04281      0.325623        10     
reco:pandoraShower:LArPandoraShowerCreation          0.61655       1.03257       1.75384      0.910208      0.375438        10     
reco:pandoracalo:Calorimetry                         0.37909      0.598318       1.01253      0.560611      0.160193        10     
reco:pandoracalonosce:Calorimetry                   0.366468      0.573844      0.933651      0.545392       0.14331        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.623843       1.03237       1.75144      0.936715      0.336048        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.624444       1.02538       1.69018      0.938882      0.317006        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0350929     0.0499155     0.0631236     0.0492118    0.00815385       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0362536     0.0492963     0.0637477     0.0478313    0.00757617       10     
reco:emtrkmichelid:EmTrackMichelId                   17.6849       22.9873       30.0551       22.0699       4.04943        10     
[art]:TriggerResults:TriggerResultInserter         2.1492e-05    3.25302e-05   7.4624e-05    2.7971e-05    1.48696e-05      10     
end_path:out1:RootOutput                            3.867e-06    9.7019e-06     2.428e-05     7.34e-06     6.05869e-06      10     
end_path:out1:RootOutput(write)                     0.984007       1.42981       2.84725       1.13456      0.572734        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5776.18 MB
  Peak resident set size usage (VmHWM): 3606.2 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11601364
-rw-r--r-- 1 dunegli fnalgrid     231120 Dec 17 20:59 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        202 Dec 17 20:59 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:59 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:59 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:59 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:59 time.db
-rw-r--r-- 1 dunegli fnalgrid 6017579265 Dec 17 20:59 pdhd_prod_beam__267379_118_1_20251212T162138Z_gen_g4_IonScintPDExt.root_262726_161_1_20251215T213903Z_PDInt.root_268896_120_1_20251217T191614Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   34487220 Dec 17 20:58 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:37 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:37 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 5827264704 Dec 17 20:36 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        123 Dec 17 19:16 all-input-dids.txt