Jobsub ID 269119.102@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
13:13.259] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=179 time=0 tick=512 with 51322 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":24354 [0] "wiener0":26968 [26968] ] cmm:[ bad:0 lf_noisy:315 ] input 1: frame: ident=179 time=0 tick=512 with 33088 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":14716 [0] "wiener1":18372 [18372] ] cmm:[ bad:0 ] input 2: frame: ident=179 time=0 tick=512 with 40378 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":17575 [0] "wiener2":22803 [22803] ] cmm:[ bad:0 ] input 3: frame: ident=179 time=0 tick=512 with 40525 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16694 [0] "wiener3":23831 [23831] ] cmm:[ bad:0 ] output: frame: ident=179 time=0 tick=512 with 165313 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":24354 [0] "gauss1":14716 [0] "gauss2":17575 [0] "gauss3":16694 [0] "wiener0":26968 [26968] "wiener1":18372 [18372] "wiener2":22803 [22803] "wiener3":23831 [23831] ] cmm:[ bad:0 lf_noisy:315 ]
Retagger: tagging trace set: wiener with 91974 traces, 91974 summary
Retagger: tagging trace set: gauss with 73339 traces, 0 summary
[16:13:13.275] D [ glue ] sink frame: #179 @0 with 165313 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[16:13:13.275] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[16:13:13.275] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[16:13:13.275] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[16:13:13.275] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[16:13:13.275] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[16:13:13.275] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[16:13:13.275] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[16:13:13.275] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[16:13:13.275] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[16:13:13.275] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[16:13:13.275] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[16:13:13.275] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[16:13:13.275] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[16:13:13.275] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[16:13:13.276] D [ glue ] frame sink sees EOS
[16:13:13.276] D [ pgraph ] <Pgrapher:> graph execution complete
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 17.04 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.36 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.2 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.31 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.28 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.14 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.12 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.08 sec
[16:13:13.276] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:13:13.276] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:13:13.276] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:13:13.276] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:13:13.276] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:13:13.276] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:13:13.276] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:13:13.276] I [ timer ] Timer: Total node execution : 62.57000068575144 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 73339 traces tagged "gauss"
FrameSaver: q=2.15565e+06 n=1136365 tag=gauss
wclsFrameSaver: saving 91974 traces tagged "wiener"
FrameSaver: q=2.71175e+06 n=1095613 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 10077 XUs and 8225 XVs -> 221 XUVs
C:0 T:5 28806 XUs and 16702 XVs -> 437 XUVs
C:0 T:6 21779 XUs and 21348 XVs -> 1199 XUVs
C:0 T:7 0 XUs and 6 XVs -> 0 XUVs
1857 XUVs total
1014 collection wire objects
1857 potential space points
Neighbour search...
29285 tests to find 16852 neighbours
Iterating with no regularization...
Begin: 1.16341e+07
0 1.10364e+07
1 1.09975e+07
2 1.09926e+07
Now with regularization...
Begin: 1.0017e+07
0 1.00161e+07
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 16:13:55 CST Closed output file "pdhd_prod_beam__261612_37_1_20251212T155601Z_gen_g4_IonScintPDExt.root_262727_112_1_20251215T215347Z_PDInt.root_269119_102_1_20251218T204312Z_detsim_reco1.root"
18-Dec-2025 16:13:55 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 72.5371 94.3029 115.186 92.1949 13.9674 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00118625 0.00358562 0.00645796 0.00327182 0.00154153 10
reco:wclsdatahd:WireCellToolkit 51.6898 58.6907 65.0916 59.28 4.13886 10
reco:wirefilter:WireFilter 0.0138891 0.0200654 0.0326522 0.0181126 0.00558135 10
reco:gaushit:GausHitFinder 0.272712 0.550433 0.763298 0.535621 0.143822 10
reco:nhitsfilter:NumberOfHitsFilter 0.000155454 0.000282845 0.000533087 0.000254942 0.00010291 10
reco:reco3d:SpacePointSolver 0.189349 0.413217 1.11226 0.288289 0.304251 10
reco:hitpdune:DisambigFromSpacePoints 0.0902551 0.291282 0.577123 0.292395 0.120969 10
reco:pandora:StandardPandora 2.51603 6.33718 10.2749 5.96216 2.91326 10
reco:pandoraWriter:StandardPandora 0.119561 0.19285 0.263727 0.182765 0.0517781 10
reco:pandoraTrack:LArPandoraTrackCreation 0.289164 0.652494 1.09507 0.603011 0.277269 10
reco:pandoraShower:LArPandoraShowerCreation 0.242139 0.54744 1.11246 0.536923 0.267221 10
reco:pandoracalo:Calorimetry 0.198569 0.379016 0.61199 0.387123 0.151149 10
reco:pandoracalonosce:Calorimetry 0.190439 0.358934 0.521687 0.373626 0.126289 10
reco:pandoraShowercalo:ShowerCalorimetry 0.237499 0.527255 0.870667 0.552643 0.231949 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.224467 0.507521 0.771477 0.563606 0.204947 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0314498 0.0453367 0.0632485 0.0446469 0.0102991 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0319195 0.0446201 0.064037 0.0426383 0.0102188 10
reco:emtrkmichelid:EmTrackMichelId 14.3433 23.567 34.6725 23.9699 7.02789 10
[art]:TriggerResults:TriggerResultInserter 2.8824e-05 4.28119e-05 0.000106802 3.85325e-05 2.17265e-05 10
end_path:out1:RootOutput 7.835e-06 1.25416e-05 3.6789e-05 1.0329e-05 8.14361e-06 10
end_path:out1:RootOutput(write) 0.804668 1.12771 1.48859 1.12619 0.181099 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5656.17 MB
Peak resident set size usage (VmHWM): 3460.41 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10474168
-rw-r--r--. 1 dune osgvo 231028 Dec 18 16:13 jobscript.log
-rw-r--r--. 1 dune osgvo 201 Dec 18 16:13 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo 519 Dec 18 16:13 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 3574 Dec 18 16:13 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo 139264 Dec 18 16:13 mem.db
-rw-r--r--. 1 dune osgvo 28672 Dec 18 16:13 time.db
-rw-r--r--. 1 dune osgvo 5428353644 Dec 18 16:13 pdhd_prod_beam__261612_37_1_20251212T155601Z_gen_g4_IonScintPDExt.root_262727_112_1_20251215T215347Z_PDInt.root_269119_102_1_20251218T204312Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo 28652820 Dec 18 16:13 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo 0 Dec 18 15:56 debugprod.log
-rw-r--r--. 1 dune osgvo 519 Dec 18 15:56 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 5268092307 Dec 18 15:56 temp_detsim.root
-rw-r--r--. 1 dune osgvo 122 Dec 18 14:43 all-input-dids.txt