Jobsub ID 268896.171@dunegpschedd01.fnal.gov

Jobsub ID	268896.171@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 20:50:55
From worker node	Hostname	dunegli-7943587-0-fnpc23033.fnal.gov
	cpuinfo	AMD EPYC 7543 32-Core Processor
	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:44:34
Input files	usertests:pdhd_prod_beam__267379_90_1_20251212T161921Z_gen_g4_IonScintPDExt.root_262726_159_1_20251215T213947Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (3971s)
	CPU time	1h (3902s = 98%)
	Max RSS bytes	8693342208 (8290 MiB)
Outputting started	2025-12-17 20:50:45
Output files
Finished	2025-12-17 20:50:55
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

cmm:[ bad:0 lf_noisy:95 ] 
[20:50:24.247] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 39645 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":19160 [0] "wiener0":20485 [20485] ] cmm:[ bad:0 lf_noisy:95 ] input 1: frame: ident=189 time=0 tick=512 with 34182 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":15089 [0] "wiener1":19093 [19093] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 44854 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":19384 [0] "wiener2":25470 [25470] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 31843 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":14166 [0] "wiener3":17677 [17677] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 150524 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":19160 [0] "gauss1":15089 [0] "gauss2":19384 [0] "gauss3":14166 [0] "wiener0":20485 [20485] "wiener1":19093 [19093] "wiener2":25470 [25470] "wiener3":17677 [17677] ] cmm:[ bad:0 lf_noisy:95 ] 
Retagger: tagging trace set: wiener with 82725 traces, 82725 summary
Retagger: tagging trace set: gauss with 67799 traces, 0 summary
[20:50:24.253] D [  glue  ] sink frame: #189 @0 with 150524 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:50:24.253] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:50:24.253] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:50:24.253] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:50:24.253] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:50:24.253] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:50:24.253] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:50:24.253] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:50:24.253] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:50:24.253] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:50:24.253] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:50:24.253] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:50:24.253] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:50:24.253] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:50:24.253] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:50:24.253] D [  glue  ] frame sink sees EOS
[20:50:24.253] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.25 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 5.78 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 5.61 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 5.6 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.05 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.04 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.03 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.03 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:50:24.253] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:50:24.253] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[20:50:24.253] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:50:24.253] I [ timer  ] Timer: Total node execution : 33.40000010468066 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 67799 traces tagged "gauss"
FrameSaver: q=2.06326e+06 n=1044984 tag=gauss
wclsFrameSaver: saving 82725 traces tagged "wiener"
FrameSaver: q=2.62388e+06 n=1037999 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 15082 XUs and 9116 XVs -> 368 XUVs
C:0 T:4 20 XUs and 8 XVs -> 0 XUVs
C:0 T:5 33926 XUs and 32637 XVs -> 1812 XUVs
C:0 T:6 9467 XUs and 8085 XVs -> 276 XUVs
2456 XUVs total
1379 collection wire objects
2456 potential space points
Neighbour search...
69300 tests to find 28856 neighbours
Iterating with no regularization...
Begin: 2.55793e+07
0 2.33665e+07
1 2.31878e+07
2 2.31647e+07
Now with regularization...
Begin: 2.16228e+07
0 2.16143e+07
17-Dec-2025 20:50:44 UTC  Closed output file "pdhd_prod_beam__267379_90_1_20251212T161921Z_gen_g4_IonScintPDExt.root_262726_159_1_20251215T213947Z_PDInt.root_268896_171_1_20251217T194438Z_detsim_reco1.root"
17-Dec-2025 20:50:44 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           51.2343       61.3281       81.3345       57.3232       10.1114        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000482102   0.00271216    0.00486499    0.00271015    0.00141998       10     
reco:wclsdatahd:WireCellToolkit                      33.6295       34.4442       35.3913       34.4418      0.438753        10     
reco:wirefilter:WireFilter                         0.00904922     0.0108691     0.0149572    0.00989683    0.00203523       10     
reco:gaushit:GausHitFinder                          0.253593      0.410598      0.640308      0.394951      0.112651        10     
reco:nhitsfilter:NumberOfHitsFilter                9.0623e-05    0.000169479   0.000378965   0.000155543   7.75916e-05      10     
reco:reco3d:SpacePointSolver                        0.140806      0.323837      0.743419      0.271997       0.18642        10     
reco:hitpdune:DisambigFromSpacePoints                0.15329      0.305942      0.668553      0.215022      0.167401        10     
reco:pandora:StandardPandora                         2.53606       6.02556       13.3835       4.40771       3.82178        10     
reco:pandoraWriter:StandardPandora                  0.0804763     0.118982      0.184381      0.109701      0.0353665       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.284464       0.55028       1.00289      0.474208      0.252163        10     
reco:pandoraShower:LArPandoraShowerCreation          0.26705      0.591817       1.23639      0.422624       0.31359        10     
reco:pandoracalo:Calorimetry                        0.185446      0.347125      0.695028      0.289517       0.15601        10     
reco:pandoracalonosce:Calorimetry                   0.184739      0.335965      0.681696      0.278713      0.152109        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.292415      0.656483       1.56555      0.452753      0.382226        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.281692       0.64634       1.55117      0.447528      0.378356        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0222936     0.0315101     0.0480858     0.0301364    0.00742358       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0218424     0.0304452     0.0457897     0.0279155    0.00708391       10     
reco:emtrkmichelid:EmTrackMichelId                    10.91        15.668        22.9119       14.4355       3.90684        10     
[art]:TriggerResults:TriggerResultInserter          1.566e-05    2.47382e-05    7.824e-05    1.9442e-05    1.79475e-05      10     
end_path:out1:RootOutput                            3.597e-06    6.8171e-06    2.7543e-05     4.058e-06    7.00476e-06      10     
end_path:out1:RootOutput(write)                     0.606393      0.799765       1.15212      0.729336      0.176764        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6579.73 MB
  Peak resident set size usage (VmHWM): 4422.5 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 13458468
-rw-r--r-- 1 dunegli fnalgrid     231309 Dec 17 20:50 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        201 Dec 17 20:50 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:50 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:50 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:50 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:50 time.db
-rw-r--r-- 1 dunegli fnalgrid 6971367637 Dec 17 20:50 pdhd_prod_beam__267379_90_1_20251212T161921Z_gen_g4_IonScintPDExt.root_262726_159_1_20251215T213947Z_PDInt.root_268896_171_1_20251217T194438Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   37532790 Dec 17 20:50 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:39 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:39 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 6772105694 Dec 17 20:39 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        122 Dec 17 19:44 all-input-dids.txt