Jobsub ID 268896.155@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
<FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 39799 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":19176 [0] "wiener0":20623 [20623] ] cmm:[ bad:0 lf_noisy:230 ] input 1: frame: ident=189 time=0 tick=512 with 56790 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":23638 [0] "wiener1":33152 [33152] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 34593 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":15009 [0] "wiener2":19584 [19584] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 46473 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":18773 [0] "wiener3":27700 [27700] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 177655 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":19176 [0] "gauss1":23638 [0] "gauss2":15009 [0] "gauss3":18773 [0] "wiener0":20623 [20623] "wiener1":33152 [33152] "wiener2":19584 [19584] "wiener3":27700 [27700] ] cmm:[ bad:0 lf_noisy:230 ]
Retagger: tagging trace set: wiener with 101059 traces, 101059 summary
Retagger: tagging trace set: gauss with 76596 traces, 0 summary
[15:19:53.172] D [ glue ] sink frame: #189 @0 with 177655 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[15:19:53.173] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[15:19:53.173] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[15:19:53.173] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[15:19:53.173] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[15:19:53.173] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[15:19:53.173] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[15:19:53.173] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[15:19:53.173] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[15:19:53.173] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[15:19:53.173] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[15:19:53.173] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[15:19:53.173] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[15:19:53.173] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[15:19:53.173] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[15:19:53.173] D [ glue ] frame sink sees EOS
[15:19:53.173] D [ pgraph ] <Pgrapher:> graph execution complete
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.21 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.74 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.33 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.2 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.27 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.21 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.21 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.18 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[15:19:53.173] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:19:53.173] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:19:53.173] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:19:53.173] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[15:19:53.173] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:19:53.173] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[15:19:53.173] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:19:53.173] I [ timer ] Timer: Total node execution : 50.409999664872885 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 76596 traces tagged "gauss"
FrameSaver: q=2.58123e+06 n=1232056 tag=gauss
wclsFrameSaver: saving 101059 traces tagged "wiener"
FrameSaver: q=3.11732e+06 n=1172836 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 42994 XUs and 40588 XVs -> 1018 XUVs
C:0 T:3 36 XUs and 35 XVs -> 0 XUVs
C:0 T:4 450 XUs and 122 XVs -> 3 XUVs
C:0 T:5 60277 XUs and 52137 XVs -> 5130 XUVs
C:0 T:6 39253 XUs and 33096 XVs -> 4126 XUVs
C:0 T:7 36 XUs and 51 XVs -> 5 XUVs
10282 XUVs total
1739 collection wire objects
10282 potential space points
Neighbour search...
1985986 tests to find 865340 neighbours
Iterating with no regularization...
Begin: 3.03006e+07
0 2.59229e+07
1 2.55925e+07
2 2.55282e+07
3 2.55046e+07
Now with regularization...
Begin: 2.37396e+07
0 2.37215e+07
17-Dec-2025 15:20:45 CST Closed output file "pdhd_prod_beam__267379_25_1_20251212T160804Z_gen_g4_IonScintPDExt.root_262726_147_1_20251215T213644Z_PDInt.root_268896_155_1_20251217T193626Z_detsim_reco1.root"
17-Dec-2025 15:20:45 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 72.5698 95.1768 126.93 90.7041 15.0231 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00122195 0.00407063 0.00821804 0.00386747 0.00196999 10
reco:wclsdatahd:WireCellToolkit 47.095 51.1195 53.9045 50.8138 1.9971 10
reco:wirefilter:WireFilter 0.0108711 0.021911 0.0277123 0.024026 0.0053646 10
reco:gaushit:GausHitFinder 0.305994 0.699818 1.0827 0.721687 0.245242 10
reco:nhitsfilter:NumberOfHitsFilter 0.0001383 0.00034763 0.000599538 0.000351527 0.000127238 10
reco:reco3d:SpacePointSolver 0.0919315 0.707275 1.76108 0.522548 0.539605 10
reco:hitpdune:DisambigFromSpacePoints 0.118438 0.572231 1.38101 0.486274 0.343274 10
reco:pandora:StandardPandora 2.73235 9.55965 17.1689 9.73677 4.65186 10
reco:pandoraWriter:StandardPandora 0.136029 0.21234 0.319798 0.192768 0.0670187 10
reco:pandoraTrack:LArPandoraTrackCreation 0.433602 0.975013 2.62399 0.695606 0.619578 10
reco:pandoraShower:LArPandoraShowerCreation 0.348269 1.00909 2.49031 0.85084 0.633976 10
reco:pandoracalo:Calorimetry 0.240109 0.552638 1.77244 0.411806 0.424261 10
reco:pandoracalonosce:Calorimetry 0.234482 0.534228 1.27796 0.446391 0.27483 10
reco:pandoraShowercalo:ShowerCalorimetry 0.358945 0.947193 1.88157 0.806252 0.514014 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.350064 0.903739 1.72356 0.830416 0.475318 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.035677 0.0553963 0.0942099 0.0492176 0.0187824 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0376854 0.0546677 0.0911002 0.0501283 0.0168158 10
reco:emtrkmichelid:EmTrackMichelId 15.2373 25.6935 40.3266 22.3252 7.29129 10
[art]:TriggerResults:TriggerResultInserter 3.0828e-05 7.24421e-05 0.000339258 3.4815e-05 9.07141e-05 10
end_path:out1:RootOutput 8.235e-06 1.10627e-05 2.665e-05 8.7665e-06 5.48845e-06 10
end_path:out1:RootOutput(write) 1.01566 1.49852 2.27452 1.3863 0.347181 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6500.3 MB
Peak resident set size usage (VmHWM): 4326.84 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12733204
-rw-r--r--. 1 dune osgvo 231206 Dec 17 15:20 jobscript.log
-rw-r--r--. 1 dune osgvo 201 Dec 17 15:20 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo 519 Dec 17 15:20 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 3574 Dec 17 15:20 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo 139264 Dec 17 15:20 mem.db
-rw-r--r--. 1 dune osgvo 28672 Dec 17 15:20 time.db
-rw-r--r--. 1 dune osgvo 6598643630 Dec 17 15:20 pdhd_prod_beam__267379_25_1_20251212T160804Z_gen_g4_IonScintPDExt.root_262726_147_1_20251215T213644Z_PDInt.root_268896_155_1_20251217T193626Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo 36638380 Dec 17 15:20 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo 0 Dec 17 15:03 debugprod.log
-rw-r--r--. 1 dune osgvo 519 Dec 17 15:02 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 6403070070 Dec 17 15:02 temp_detsim.root
-rw-r--r--. 1 dune osgvo 122 Dec 17 13:36 all-input-dids.txt
