Jobsub ID 268896.168@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
[15:19:25.311] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 47369 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":22851 [0] "wiener0":24518 [24518] ] cmm:[ bad:0 lf_noisy:163 ] input 1: frame: ident=189 time=0 tick=512 with 25354 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":11254 [0] "wiener1":14100 [14100] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 45497 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":19685 [0] "wiener2":25812 [25812] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 36699 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16305 [0] "wiener3":20394 [20394] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 154919 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":22851 [0] "gauss1":11254 [0] "gauss2":19685 [0] "gauss3":16305 [0] "wiener0":24518 [24518] "wiener1":14100 [14100] "wiener2":25812 [25812] "wiener3":20394 [20394] ] cmm:[ bad:0 lf_noisy:163 ]
Retagger: tagging trace set: wiener with 84824 traces, 84824 summary
Retagger: tagging trace set: gauss with 70095 traces, 0 summary
[15:19:25.336] D [ glue ] sink frame: #189 @0 with 154919 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[15:19:25.336] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[15:19:25.336] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[15:19:25.336] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[15:19:25.336] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[15:19:25.336] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[15:19:25.336] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[15:19:25.336] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[15:19:25.336] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[15:19:25.336] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[15:19:25.336] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[15:19:25.336] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[15:19:25.336] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[15:19:25.337] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[15:19:25.337] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[15:19:25.337] D [ glue ] frame sink sees EOS
[15:19:25.337] D [ pgraph ] <Pgrapher:> graph execution complete
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.88 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.93 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.87 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.74 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.4 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.35 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.71 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.49 sec
[15:19:25.337] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:19:25.337] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:19:25.337] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:19:25.337] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:19:25.337] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[15:19:25.337] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[15:19:25.337] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:19:25.337] I [ timer ] Timer: Total node execution : 51.41000012308359 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 70095 traces tagged "gauss"
FrameSaver: q=2.01798e+06 n=1078670 tag=gauss
wclsFrameSaver: saving 84824 traces tagged "wiener"
FrameSaver: q=2.69107e+06 n=1063338 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 10623 XUs and 15498 XVs -> 1660 XUVs
C:0 T:3 13 XUs and 19 XVs -> 3 XUVs
C:0 T:4 11 XUs and 30 XVs -> 0 XUVs
C:0 T:5 35138 XUs and 31909 XVs -> 1283 XUVs
C:0 T:6 18747 XUs and 33847 XVs -> 1588 XUVs
C:0 T:7 9 XUs and 10 XVs -> 0 XUVs
4534 XUVs total
1833 collection wire objects
4534 potential space points
Neighbour search...
157822 tests to find 91210 neighbours
Iterating with no regularization...
Begin: 1.84225e+07
0 1.62881e+07
1 1.60473e+07
2 1.60052e+07
3 1.59944e+07
Now with regularization...
Begin: 1.44867e+07
0 1.448e+07
17-Dec-2025 15:20:03 CST Closed output file "pdhd_prod_beam__267379_94_1_20251212T161950Z_gen_g4_IonScintPDExt.root_262726_128_1_20251215T213357Z_PDInt.root_268896_168_1_20251217T194526Z_detsim_reco1.root"
17-Dec-2025 15:20:03 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 80.721 92.5885 113.154 88.5987 10.8377 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00142041 0.00370681 0.00520371 0.00394578 0.00123781 10
reco:wclsdatahd:WireCellToolkit 44.2461 54.764 65.0857 55.4638 5.12557 10
reco:wirefilter:WireFilter 0.0145817 0.0337558 0.0538188 0.0336879 0.0112761 10
reco:gaushit:GausHitFinder 0.378721 0.564953 0.828916 0.492754 0.157914 10
reco:nhitsfilter:NumberOfHitsFilter 0.00023334 0.000434716 0.000744343 0.000382762 0.000173693 10
reco:reco3d:SpacePointSolver 0.13824 0.447318 1.08294 0.380706 0.279188 10
reco:hitpdune:DisambigFromSpacePoints 0.160941 0.353254 0.779984 0.269123 0.211636 10
reco:pandora:StandardPandora 2.77454 7.93273 19.2374 6.63766 4.72314 10
reco:pandoraWriter:StandardPandora 0.141465 0.242229 0.374058 0.244253 0.0744233 10
reco:pandoraTrack:LArPandoraTrackCreation 0.369903 0.815185 1.60702 0.605981 0.451527 10
reco:pandoraShower:LArPandoraShowerCreation 0.179043 0.8585 1.9005 0.575131 0.598113 10
reco:pandoracalo:Calorimetry 0.154385 0.510836 1.21007 0.370241 0.321954 10
reco:pandoracalonosce:Calorimetry 0.138262 0.433988 0.833234 0.318676 0.239635 10
reco:pandoraShowercalo:ShowerCalorimetry 0.162239 0.841751 1.95214 0.617785 0.618397 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.165328 0.745173 1.82227 0.503659 0.546684 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0265477 0.0522547 0.0874475 0.0485942 0.0191196 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0263939 0.0514856 0.0843246 0.0500085 0.0190743 10
reco:emtrkmichelid:EmTrackMichelId 15.6274 22.7315 28.7412 23.6763 4.5729 10
[art]:TriggerResults:TriggerResultInserter 3.3453e-05 6.27851e-05 0.000181752 4.0787e-05 4.41082e-05 10
end_path:out1:RootOutput 1.0159e-05 1.58509e-05 4.3252e-05 1.2148e-05 9.693e-06 10
end_path:out1:RootOutput(write) 0.779611 1.1349 1.63469 1.04645 0.218872 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5718.63 MB
Peak resident set size usage (VmHWM): 3501.91 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10224160
-rw-r--r-- 1 dune osgvo 231104 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 5301607416 Dec 17 15:20 pdhd_prod_beam__267379_94_1_20251212T161950Z_gen_g4_IonScintPDExt.root_262726_128_1_20251215T213357Z_PDInt.root_268896_168_1_20251217T194526Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo 29580230 Dec 17 15:19 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo 0 Dec 17 15:02 debugprod.log
-rw-r--r-- 1 dune osgvo 519 Dec 17 15:02 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 5137899179 Dec 17 15:02 temp_detsim.root
-rw-r--r-- 1 dune osgvo 122 Dec 17 13:45 all-input-dids.txt
