Jobsub ID 263305.12@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
:39 ]
[14:39:52.157] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=179 time=0 tick=512 with 45323 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":21618 [0] "wiener0":23705 [23705] ] cmm:[ bad:0 lf_noisy:39 ] input 1: frame: ident=179 time=0 tick=512 with 39430 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":17425 [0] "wiener1":22005 [22005] ] cmm:[ bad:0 ] input 2: frame: ident=179 time=0 tick=512 with 27388 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":12485 [0] "wiener2":14903 [14903] ] cmm:[ bad:0 ] input 3: frame: ident=179 time=0 tick=512 with 38775 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16198 [0] "wiener3":22577 [22577] ] cmm:[ bad:0 ] output: frame: ident=179 time=0 tick=512 with 150916 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":21618 [0] "gauss1":17425 [0] "gauss2":12485 [0] "gauss3":16198 [0] "wiener0":23705 [23705] "wiener1":22005 [22005] "wiener2":14903 [14903] "wiener3":22577 [22577] ] cmm:[ bad:0 lf_noisy:39 ]
Retagger: tagging trace set: wiener with 83190 traces, 83190 summary
Retagger: tagging trace set: gauss with 67726 traces, 0 summary
[14:39:52.168] D [ glue ] sink frame: #179 @0 with 150916 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[14:39:52.168] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[14:39:52.168] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[14:39:52.168] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[14:39:52.168] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[14:39:52.168] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[14:39:52.168] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[14:39:52.168] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[14:39:52.168] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[14:39:52.168] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[14:39:52.168] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[14:39:52.168] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[14:39:52.168] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[14:39:52.168] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[14:39:52.168] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[14:39:52.168] D [ glue ] frame sink sees EOS
[14:39:52.168] D [ pgraph ] <Pgrapher:> graph execution complete
[14:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.22 sec
[14:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.95 sec
[14:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.52 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.14 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.61 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.58 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.12 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.09 sec
[14:39:52.169] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:39:52.169] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:39:52.169] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[14:39:52.169] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[14:39:52.169] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[14:39:52.169] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[14:39:52.169] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[14:39:52.169] I [ timer ] Timer: Total node execution : 51.26000049524009 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 67726 traces tagged "gauss"
FrameSaver: q=1.91308e+06 n=1047301 tag=gauss
wclsFrameSaver: saving 83190 traces tagged "wiener"
FrameSaver: q=2.38094e+06 n=1033127 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 30876 XUs and 20978 XVs -> 747 XUVs
C:0 T:3 7 XUs and 5 XVs -> 0 XUVs
C:0 T:4 2 XUs and 3 XVs -> 0 XUVs
C:0 T:5 4601 XUs and 6020 XVs -> 363 XUVs
C:0 T:6 12626 XUs and 17744 XVs -> 709 XUVs
C:0 T:7 31 XUs and 25 XVs -> 0 XUVs
1819 XUVs total
1063 collection wire objects
1819 potential space points
Neighbour search...
29905 tests to find 18110 neighbours
Iterating with no regularization...
Begin: 1.66217e+07
0 1.59228e+07
1 1.58816e+07
2 1.58786e+07
Now with regularization...
Begin: 1.50454e+07
0 1.50444e+07
18-Dec-2025 14:40:20 PST Closed output file "pdhd_prod_beam__261612_17_1_20251212T155447Z_gen_g4_IonScintPDExt.root_268535_8_1_20251215T213118Z_PDInt.root_263305_12_1_20251218T203049Z_detsim_reco1.root"
18-Dec-2025 14:40:20 PST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 74.2921 89.3888 113.735 86.9691 10.3575 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00118271 0.00367587 0.00587354 0.00368548 0.00148222 10
reco:wclsdatahd:WireCellToolkit 50.985 54.4272 58.5905 54.2821 2.76166 10
reco:wirefilter:WireFilter 0.0154936 0.0187157 0.0236872 0.0179016 0.00316697 10
reco:gaushit:GausHitFinder 0.422779 0.613576 0.9204 0.587421 0.149567 10
reco:nhitsfilter:NumberOfHitsFilter 0.000170816 0.000261882 0.000443196 0.000250042 7.54097e-05 10
reco:reco3d:SpacePointSolver 0.156187 0.474457 1.40593 0.351877 0.34042 10
reco:hitpdune:DisambigFromSpacePoints 0.164072 0.359405 0.646406 0.357215 0.153416 10
reco:pandora:StandardPandora 3.64135 7.00151 11.772 6.74946 2.44401 10
reco:pandoraWriter:StandardPandora 0.135955 0.177515 0.251338 0.177392 0.030616 10
reco:pandoraTrack:LArPandoraTrackCreation 0.515036 0.734025 1.28307 0.625263 0.23946 10
reco:pandoraShower:LArPandoraShowerCreation 0.267478 0.737128 1.5312 0.666861 0.325666 10
reco:pandoracalo:Calorimetry 0.291213 0.421989 0.705049 0.386195 0.122026 10
reco:pandoracalonosce:Calorimetry 0.28287 0.429925 0.895209 0.382844 0.168825 10
reco:pandoraShowercalo:ShowerCalorimetry 0.24117 0.79097 1.86771 0.676889 0.430256 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.242801 0.751396 1.3424 0.698682 0.331466 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0392995 0.0522703 0.0752115 0.0479132 0.010881 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0390796 0.0517491 0.0763104 0.047355 0.0111303 10
reco:emtrkmichelid:EmTrackMichelId 14.5737 21.0817 32.7758 20.4733 4.85285 10
[art]:TriggerResults:TriggerResultInserter 2.2763e-05 3.68626e-05 8.2528e-05 2.59995e-05 2.05848e-05 10
end_path:out1:RootOutput 8.196e-06 1.01755e-05 2.2373e-05 8.7765e-06 4.11925e-06 10
end_path:out1:RootOutput(write) 0.98293 1.20694 1.66871 1.18322 0.176367 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6161.67 MB
Peak resident set size usage (VmHWM): 3945.53 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12125228
-rw-r--r--. 1 cuser cuser 230999 Dec 18 14:40 jobscript.log
-rw-r--r--. 1 cuser cuser 199 Dec 18 14:40 justin-processed-pfns.txt
-rw-r--r--. 1 cuser cuser 519 Dec 18 14:40 reco_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 3574 Dec 18 14:40 Pandora_Geometry.xml
-rw-r--r--. 1 cuser cuser 139264 Dec 18 14:40 mem.db
-rw-r--r--. 1 cuser cuser 28672 Dec 18 14:40 time.db
-rw-r--r--. 1 cuser cuser 6280500123 Dec 18 14:40 pdhd_prod_beam__261612_17_1_20251212T155447Z_gen_g4_IonScintPDExt.root_268535_8_1_20251215T213118Z_PDInt.root_263305_12_1_20251218T203049Z_detsim_reco1.root
-rw-r--r--. 1 cuser cuser 31310640 Dec 18 14:39 Pandora_Events.pndr
-rw-r--r--. 1 cuser cuser 0 Dec 18 14:23 debugprod.log
-rw-r--r--. 1 cuser cuser 519 Dec 18 14:23 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 6103887610 Dec 18 14:23 temp_detsim.root
-rw-r--r--. 1 cuser cuser 120 Dec 18 12:30 all-input-dids.txt