Jobsub ID 268896.40@dunegpschedd01.fnal.gov

Jobsub ID	268896.40@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-T1
Entry	CMSHTPC_T1_US_FNAL_condce_opp1_whole
Last heartbeat	2025-12-17 20:48:13
From worker node	Hostname	dunegli-49199-0-cmswn2413.fnal.gov
	cpuinfo	AMD EPYC 7551 32-Core Processor
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	171000 (47 hours)
	GPU
	Inner Apptainer?	True
Job state	outputting_failed
Started	2025-12-17 18:32:42
Input files	usertests:pdhd_prod_beam__267379_40_1_20251212T160918Z_gen_g4_IonScintPDExt.root_262726_39_1_20251215T212447Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (8116s)
	CPU time	1h (6337s = 78%)
	Max RSS bytes	7449907200 (7104 MiB)
Outputting started	2025-12-17 20:47:59
Output files
Finished	2025-12-17 20:48:13
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

:0 lf_noisy:310 ] 
[20:47:10.818] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 43585 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":20707 [0] "wiener0":22878 [22878] ] cmm:[ bad:0 lf_noisy:310 ] input 1: frame: ident=189 time=0 tick=512 with 38307 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":17181 [0] "wiener1":21126 [21126] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 47055 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":20706 [0] "wiener2":26349 [26349] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 34601 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":15803 [0] "wiener3":18798 [18798] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 163548 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":20707 [0] "gauss1":17181 [0] "gauss2":20706 [0] "gauss3":15803 [0] "wiener0":22878 [22878] "wiener1":21126 [21126] "wiener2":26349 [26349] "wiener3":18798 [18798] ] cmm:[ bad:0 lf_noisy:310 ] 
Retagger: tagging trace set: wiener with 89151 traces, 89151 summary
Retagger: tagging trace set: gauss with 74397 traces, 0 summary
[20:47:10.830] D [  glue  ] sink frame: #189 @0 with 163548 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:47:10.831] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:47:10.831] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:47:10.831] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:47:10.831] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:47:10.831] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:47:10.831] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:47:10.831] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:47:10.831] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:47:10.831] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:47:10.831] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:47:10.831] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:47:10.831] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:47:10.831] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:47:10.831] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:47:10.831] D [  glue  ] frame sink sees EOS
[20:47:10.831] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.95 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.3 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.18 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.15 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.97 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.96 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.86 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.84 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:47:10.831] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:47:10.832] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:47:10.832] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:47:10.832] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:47:10.832] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:47:10.832] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:47:10.832] I [ timer  ] Timer: Total node execution : 48.25999979861081 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 74397 traces tagged "gauss"
FrameSaver: q=2.13912e+06 n=1244205 tag=gauss
wclsFrameSaver: saving 89151 traces tagged "wiener"
FrameSaver: q=2.52e+06 n=1188303 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 36004 XUs and 14663 XVs -> 296 XUVs
C:0 T:4 8 XUs and 30 XVs -> 2 XUVs
C:0 T:5 42370 XUs and 50018 XVs -> 1561 XUVs
C:0 T:6 16743 XUs and 10982 XVs -> 290 XUVs
2149 XUVs total
1324 collection wire objects
2149 potential space points
Neighbour search...
55491 tests to find 26324 neighbours
Iterating with no regularization...
Begin: 1.84634e+07
0 1.70803e+07
1 1.70191e+07
2 1.70143e+07
Now with regularization...
Begin: 1.61293e+07
0 1.61273e+07
17-Dec-2025 20:47:57 UTC  Closed output file "pdhd_prod_beam__267379_40_1_20251212T160918Z_gen_g4_IonScintPDExt.root_262726_39_1_20251215T212447Z_PDInt.root_268896_40_1_20251217T183247Z_detsim_reco1.root"
17-Dec-2025 20:47:57 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           73.5383       94.001        133.026       95.474        16.6516        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00116098     0.0154234     0.124953     0.00349733     0.0365381       10     
reco:wclsdatahd:WireCellToolkit                      43.3697       46.0091       49.5438       46.1267       1.95907        10     
reco:wirefilter:WireFilter                          0.0124968     0.0175271     0.0249542     0.0178682    0.00337364       10     
reco:gaushit:GausHitFinder                          0.421622      0.629885      0.989113      0.628647      0.155894        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000215531   0.000330963   0.000537233   0.000298382   9.73035e-05      10     
reco:reco3d:SpacePointSolver                        0.172847      0.579504       1.22239      0.519945      0.337166        10     
reco:hitpdune:DisambigFromSpacePoints               0.138535      0.433756      0.986356      0.434717      0.234594        10     
reco:pandora:StandardPandora                         3.75231       9.56968       20.0773       9.29847       4.92229        10     
reco:pandoraWriter:StandardPandora                   0.12361      0.254243      0.811049      0.192569      0.191973        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.505351       1.02388       2.1378       0.948778      0.429736        10     
reco:pandoraShower:LArPandoraShowerCreation         0.406731       1.10454       3.36761      0.907136      0.805928        10     
reco:pandoracalo:Calorimetry                         0.27386      0.500178       1.09714      0.480342      0.216504        10     
reco:pandoracalonosce:Calorimetry                   0.227879      0.479186       1.06061      0.469599      0.215076        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.306099       1.05361       3.53456      0.835893      0.874127        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.293898       1.07457       3.09337      0.913443      0.757797        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0329582     0.0480021     0.077821      0.0459581     0.0132353       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0323849     0.0474836     0.0773417     0.0439663     0.0136239       10     
reco:emtrkmichelid:EmTrackMichelId                   19.6492       29.8676       48.5256       29.3399       8.33072        10     
[art]:TriggerResults:TriggerResultInserter          2.044e-05    3.26663e-05    8.05e-05     2.5226e-05    1.77432e-05      10     
end_path:out1:RootOutput                            7.57e-06     1.0778e-05     2.671e-05     8.305e-06    5.81254e-06      10     
end_path:out1:RootOutput(write)                     0.910664       1.24314       1.89705       1.23308      0.265017        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6074.96 MB
  Peak resident set size usage (VmHWM): 3828.97 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12038900
-rw-r--r-- 1 dunegli fnalgrid     231361 Dec 17 20:47 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        200 Dec 17 20:47 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:47 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:47 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:47 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:47 time.db
-rw-r--r-- 1 dunegli fnalgrid 6243791596 Dec 17 20:47 pdhd_prod_beam__267379_40_1_20251212T160918Z_gen_g4_IonScintPDExt.root_262726_39_1_20251215T212447Z_PDInt.root_268896_40_1_20251217T183247Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   37207960 Dec 17 20:47 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:15 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:15 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 6046380144 Dec 17 20:15 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        121 Dec 17 18:32 all-input-dids.txt