Jobsub ID 268745.1@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
:0 lf_noisy:176 ]
[19:24:11.587] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=159 time=0 tick=512 with 57416 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":27302 [0] "wiener0":30114 [30114] ] cmm:[ bad:0 lf_noisy:176 ] input 1: frame: ident=159 time=0 tick=512 with 37657 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":16606 [0] "wiener1":21051 [21051] ] cmm:[ bad:0 lf_noisy:1 ] input 2: frame: ident=159 time=0 tick=512 with 47717 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":19959 [0] "wiener2":27758 [27758] ] cmm:[ bad:0 ] input 3: frame: ident=159 time=0 tick=512 with 38350 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16671 [0] "wiener3":21679 [21679] ] cmm:[ bad:0 ] output: frame: ident=159 time=0 tick=512 with 181140 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":27302 [0] "gauss1":16606 [0] "gauss2":19959 [0] "gauss3":16671 [0] "wiener0":30114 [30114] "wiener1":21051 [21051] "wiener2":27758 [27758] "wiener3":21679 [21679] ] cmm:[ bad:0 lf_noisy:177 ]
Retagger: tagging trace set: wiener with 100602 traces, 100602 summary
Retagger: tagging trace set: gauss with 80538 traces, 0 summary
[19:24:11.624] D [ glue ] sink frame: #159 @0 with 181140 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[19:24:11.624] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[19:24:11.624] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[19:24:11.625] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[19:24:11.625] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[19:24:11.625] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[19:24:11.625] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[19:24:11.625] D [ glue ] frame sink sees EOS
[19:24:11.625] D [ pgraph ] <Pgrapher:> graph execution complete
[19:24:11.625] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 22.89 sec
[19:24:11.625] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 17.35 sec
[19:24:11.625] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.99 sec
[19:24:11.625] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.13 sec
[19:24:11.625] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.92 sec
[19:24:11.625] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.82 sec
[19:24:11.626] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.65 sec
[19:24:11.626] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.36 sec
[19:24:11.626] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[19:24:11.626] I [ timer ] Timer: WireCell::Gen::Retagger : 0.03 sec
[19:24:11.626] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[19:24:11.626] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[19:24:11.627] I [ timer ] Timer: wcls::FrameSaver : 0.01 sec
[19:24:11.627] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:24:11.627] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[19:24:11.627] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:24:11.627] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[19:24:11.627] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[19:24:11.627] I [ timer ] Timer: Total node execution : 86.20999965444207 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 80538 traces tagged "gauss"
FrameSaver: q=2.33056e+06 n=1210171 tag=gauss
wclsFrameSaver: saving 100602 traces tagged "wiener"
FrameSaver: q=3.21758e+06 n=1166539 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 20649 XUs and 23312 XVs -> 352 XUVs
C:0 T:4 46 XUs and 53 XVs -> 19 XUVs
C:0 T:5 35624 XUs and 51328 XVs -> 2307 XUVs
C:0 T:6 36535 XUs and 21067 XVs -> 554 XUVs
C:0 T:7 3 XUs and 8 XVs -> 0 XUVs
3232 XUVs total
1268 collection wire objects
3232 potential space points
Neighbour search...
118786 tests to find 73506 neighbours
Iterating with no regularization...
Begin: 1.39086e+07
0 1.26069e+07
1 1.2526e+07
2 1.25129e+07
3 1.25086e+07
Now with regularization...
Begin: 1.15489e+07
0 1.15458e+07
16-Dec-2025 19:25:01 CST Closed output file "pdhd_prod_beam__265029_13_1_20251208T213855Z_gen_g4_IonScintPDExt.root_260262_24_1_20251210T192009Z_PDInt.root_268745_1_1_20251216T233206Z_detsim_reco1.root"
16-Dec-2025 19:25:01 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 123.528 146.163 190.575 138.579 19.7311 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00174996 0.00985095 0.0236651 0.00985776 0.00623163 10
reco:wclsdatahd:WireCellToolkit 82.8233 91.8136 103.544 91.7629 5.37246 10
reco:wirefilter:WireFilter 0.0395406 0.0539053 0.0744348 0.0512433 0.00961107 10
reco:gaushit:GausHitFinder 0.568625 0.963453 1.40194 0.948509 0.214217 10
reco:nhitsfilter:NumberOfHitsFilter 0.000379134 0.000596079 0.000941651 0.000577637 0.000154561 10
reco:reco3d:SpacePointSolver 0.470363 0.981006 2.9848 0.705717 0.715024 10
reco:hitpdune:DisambigFromSpacePoints 0.434786 0.743642 1.53788 0.689145 0.290941 10
reco:pandora:StandardPandora 9.02067 17.5875 35.1525 13.6691 8.67104 10
reco:pandoraWriter:StandardPandora 0.283859 0.39307 0.648134 0.389763 0.0965747 10
reco:pandoraTrack:LArPandoraTrackCreation 1.68583 3.23716 5.5429 3.19121 0.962454 10
reco:pandoraShower:LArPandoraShowerCreation 1.70312 3.16044 6.10038 2.97275 1.09737 10
reco:pandoracalo:Calorimetry 0.929384 1.66454 2.904 1.57222 0.552298 10
reco:pandoracalonosce:Calorimetry 0.865506 1.68011 2.6961 1.75155 0.478448 10
reco:pandoraShowercalo:ShowerCalorimetry 1.73116 3.14585 6.01222 2.98904 1.10647 10
reco:pandoraShowercalonosce:ShowerCalorimetry 1.4259 3.0142 5.83915 2.84509 1.12694 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0419282 0.0979603 0.122351 0.103337 0.0212454 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0419723 0.0930478 0.11773 0.0954733 0.0196998 10
reco:emtrkmichelid:EmTrackMichelId 10.2466 15.6872 25.5637 14.9222 3.79862 10
[art]:TriggerResults:TriggerResultInserter 3.0899e-05 8.78844e-05 0.000183374 8.32305e-05 4.07727e-05 10
end_path:out1:RootOutput 8.228e-06 1.70128e-05 3.9355e-05 1.51715e-05 8.82616e-06 10
end_path:out1:RootOutput(write) 1.19416 1.73311 2.57518 1.709 0.375012 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6500.59 MB
Peak resident set size usage (VmHWM): 4089.09 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11921628
-rw-r--r-- 1 dune osgvo 231397 Dec 16 19:25 jobscript.log
-rw-r--r-- 1 dune osgvo 200 Dec 16 19:25 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo 519 Dec 16 19:25 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 3574 Dec 16 19:25 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo 139264 Dec 16 19:25 mem.db
-rw-r--r-- 1 dune osgvo 28672 Dec 16 19:25 time.db
-rw-r--r-- 1 dune osgvo 6178562458 Dec 16 19:25 pdhd_prod_beam__265029_13_1_20251208T213855Z_gen_g4_IonScintPDExt.root_260262_24_1_20251210T192009Z_PDInt.root_268745_1_1_20251216T233206Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo 34914350 Dec 16 19:24 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo 0 Dec 16 18:56 debugprod.log
-rw-r--r-- 1 dune osgvo 519 Dec 16 18:55 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 5993819280 Dec 16 18:55 temp_detsim.root
-rw-r--r-- 1 dune osgvo 121 Dec 16 17:32 all-input-dids.txt