Jobsub ID 269119.115@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
ident=179 time=0 tick=512 with 52888 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":25112 [0] "wiener0":27776 [27776] ] cmm:[ bad:0 lf_noisy:63 ] input 1: frame: ident=179 time=0 tick=512 with 36845 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":15476 [0] "wiener1":21369 [21369] ] cmm:[ bad:0 ] input 2: frame: ident=179 time=0 tick=512 with 40186 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":17915 [0] "wiener2":22271 [22271] ] cmm:[ bad:0 ] input 3: frame: ident=179 time=0 tick=512 with 42007 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":17910 [0] "wiener3":24097 [24097] ] cmm:[ bad:0 ] output: frame: ident=179 time=0 tick=512 with 171926 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":25112 [0] "gauss1":15476 [0] "gauss2":17915 [0] "gauss3":17910 [0] "wiener0":27776 [27776] "wiener1":21369 [21369] "wiener2":22271 [22271] "wiener3":24097 [24097] ] cmm:[ bad:0 lf_noisy:63 ]
Retagger: tagging trace set: wiener with 95513 traces, 95513 summary
Retagger: tagging trace set: gauss with 76413 traces, 0 summary
[16:41:13.764] D [ glue ] sink frame: #179 @0 with 171926 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[16:41:13.764] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[16:41:13.764] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[16:41:13.764] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[16:41:13.764] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[16:41:13.764] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[16:41:13.764] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[16:41:13.764] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[16:41:13.764] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[16:41:13.764] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[16:41:13.764] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[16:41:13.764] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[16:41:13.764] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[16:41:13.764] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[16:41:13.764] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[16:41:13.764] D [ glue ] frame sink sees EOS
[16:41:13.764] D [ pgraph ] <Pgrapher:> graph execution complete
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.44 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.49 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.33 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.87 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.06 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.82 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.15 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.1 sec
[16:41:13.764] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:41:13.764] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:41:13.764] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:41:13.764] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:41:13.764] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:41:13.764] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[16:41:13.764] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:41:13.764] I [ timer ] Timer: Total node execution : 41.26999903656542 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 76413 traces tagged "gauss"
FrameSaver: q=2.32229e+06 n=1137301 tag=gauss
wclsFrameSaver: saving 95513 traces tagged "wiener"
FrameSaver: q=3.06992e+06 n=1118805 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 30705 XUs and 39671 XVs -> 3540 XUVs
C:0 T:3 22 XUs and 15 XVs -> 0 XUVs
C:0 T:4 39 XUs and 204 XVs -> 18 XUVs
C:0 T:5 15533 XUs and 17992 XVs -> 542 XUVs
C:0 T:6 50736 XUs and 41319 XVs -> 2414 XUVs
C:0 T:7 51 XUs and 22 XVs -> 0 XUVs
6514 XUVs total
1749 collection wire objects
6514 potential space points
Neighbour search...
571786 tests to find 277720 neighbours
Iterating with no regularization...
Begin: 2.81331e+07
0 2.42052e+07
1 2.38187e+07
2 2.37559e+07
3 2.37367e+07
Now with regularization...
Begin: 2.21058e+07
0 2.20883e+07
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 16:41:46 CST Closed output file "pdhd_prod_beam__261612_105_1_20251212T160458Z_gen_g4_IonScintPDExt.root_262727_70_1_20251215T214811Z_PDInt.root_269119_115_1_20251218T210437Z_detsim_reco1.root"
18-Dec-2025 16:41:46 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 72.8448 88.6404 127.155 83.5861 16.3082 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00117724 0.00367395 0.00570389 0.00360376 0.00138277 10
reco:wclsdatahd:WireCellToolkit 40.6651 46.0531 49.4509 46.4272 2.74102 10
reco:wirefilter:WireFilter 0.0109211 0.0186151 0.0305702 0.018418 0.00605441 10
reco:gaushit:GausHitFinder 0.334688 0.605584 0.963307 0.66466 0.228377 10
reco:nhitsfilter:NumberOfHitsFilter 0.000172685 0.00032435 0.000569173 0.000329601 0.000114423 10
reco:reco3d:SpacePointSolver 0.188984 0.588775 1.72951 0.44156 0.42226 10
reco:hitpdune:DisambigFromSpacePoints 0.154511 0.441989 0.732756 0.446485 0.20803 10
reco:pandora:StandardPandora 3.18584 8.35976 21.9664 7.17866 5.53443 10
reco:pandoraWriter:StandardPandora 0.108556 0.2125 0.348525 0.193584 0.0713776 10
reco:pandoraTrack:LArPandoraTrackCreation 0.317021 0.911199 2.1905 0.809184 0.531455 10
reco:pandoraShower:LArPandoraShowerCreation 0.45059 0.948741 2.37891 0.760885 0.556967 10
reco:pandoracalo:Calorimetry 0.264518 0.576001 1.35326 0.565016 0.295664 10
reco:pandoracalonosce:Calorimetry 0.235029 0.612376 1.38868 0.575413 0.340633 10
reco:pandoraShowercalo:ShowerCalorimetry 0.445424 1.01971 2.7996 0.84791 0.681193 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.427827 1.01491 2.70729 0.753506 0.681424 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0277083 0.057946 0.098544 0.0534202 0.0243944 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0277409 0.0576023 0.0976827 0.0531977 0.0242544 10
reco:emtrkmichelid:EmTrackMichelId 18.1784 25.7083 38.2389 24.8475 6.74246 10
[art]:TriggerResults:TriggerResultInserter 2.683e-05 4.21011e-05 9.8866e-05 3.36875e-05 2.11162e-05 10
end_path:out1:RootOutput 8.677e-06 1.3161e-05 3.5377e-05 1.02795e-05 7.63326e-06 10
end_path:out1:RootOutput(write) 0.71186 1.37653 1.92815 1.37126 0.345266 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5943.9 MB
Peak resident set size usage (VmHWM): 3756.92 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12308300
-rw-r--r-- 1 dune osgvo 232267 Dec 18 16:41 jobscript.log
-rw-r--r-- 1 dune osgvo 201 Dec 18 16:41 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo 519 Dec 18 16:41 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 3574 Dec 18 16:41 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo 139264 Dec 18 16:41 mem.db
-rw-r--r-- 1 dune osgvo 28672 Dec 18 16:41 time.db
-rw-r--r-- 1 dune osgvo 6384169725 Dec 18 16:41 pdhd_prod_beam__261612_105_1_20251212T160458Z_gen_g4_IonScintPDExt.root_262727_70_1_20251215T214811Z_PDInt.root_269119_115_1_20251218T210437Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo 38424120 Dec 18 16:41 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo 0 Dec 18 16:25 debugprod.log
-rw-r--r-- 1 dune osgvo 519 Dec 18 16:25 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 6180660922 Dec 18 16:25 temp_detsim.root
-rw-r--r-- 1 dune osgvo 122 Dec 18 15:04 all-input-dids.txt