Jobsub ID 265030.70@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=109 time=0 tick=512 with 41561 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":20514 [0] "wiener0":21047 [21047] ] cmm:[ bad:0 lf_noisy:242 ] input 1: frame: ident=109 time=0 tick=512 with 44827 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":18587 [0] "wiener1":26240 [26240] ] cmm:[ bad:0 lf_noisy:1 ] input 2: frame: ident=109 time=0 tick=512 with 44687 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":18989 [0] "wiener2":25698 [25698] ] cmm:[ bad:0 ] input 3: frame: ident=109 time=0 tick=512 with 46039 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":20187 [0] "wiener3":25852 [25852] ] cmm:[ bad:0 ] output: frame: ident=109 time=0 tick=512 with 177114 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":20514 [0] "gauss1":18587 [0] "gauss2":18989 [0] "gauss3":20187 [0] "wiener0":21047 [21047] "wiener1":26240 [26240] "wiener2":25698 [25698] "wiener3":25852 [25852] ] cmm:[ bad:0 lf_noisy:243 ]
Retagger: tagging trace set: wiener with 98837 traces, 98837 summary
Retagger: tagging trace set: gauss with 78277 traces, 0 summary
[22:49:02.567] D [ glue ] sink frame: #109 @0 with 177114 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[22:49:02.567] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[22:49:02.567] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[22:49:02.567] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[22:49:02.567] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[22:49:02.567] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[22:49:02.567] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[22:49:02.567] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[22:49:02.567] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[22:49:02.567] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[22:49:02.567] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[22:49:02.567] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[22:49:02.567] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[22:49:02.567] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[22:49:02.567] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[22:49:02.567] D [ glue ] frame sink sees EOS
[22:49:02.567] D [ pgraph ] <Pgrapher:> graph execution complete
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.09 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.13 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.04 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.01 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.71 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.66 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.65 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.64 sec
[22:49:02.567] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:49:02.567] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:49:02.567] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:49:02.568] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:49:02.568] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:49:02.568] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[22:49:02.568] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:49:02.568] I [ timer ] Timer: Total node execution : 54.96000078134239 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 78277 traces tagged "gauss"
FrameSaver: q=2.61018e+06 n=1277932 tag=gauss
wclsFrameSaver: saving 98837 traces tagged "wiener"
FrameSaver: q=3.20052e+06 n=1230415 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 63915 XUs and 45785 XVs -> 3741 XUVs
C:0 T:3 39 XUs and 69 XVs -> 23 XUVs
C:0 T:4 11 XUs and 17 XVs -> 3 XUVs
C:0 T:5 21360 XUs and 20547 XVs -> 1204 XUVs
C:0 T:6 36470 XUs and 23297 XVs -> 799 XUVs
C:0 T:7 32 XUs and 22 XVs -> 0 XUVs
5770 XUVs total
2005 collection wire objects
5770 potential space points
Neighbour search...
256788 tests to find 154520 neighbours
Iterating with no regularization...
Begin: 2.66439e+07
0 2.35094e+07
1 2.32452e+07
2 2.32032e+07
3 2.31939e+07
Now with regularization...
Begin: 2.10598e+07
0 2.10535e+07
08-Dec-2025 22:49:51 PST Closed output file "pdhd_prod_beam__247678_4_1_20251112T042001Z_gen_g4_IonScintPDExt.root_258129_1_1_20251205T192207Z_PDInt.root_265030_70_1_20251208T220718Z_detsim_reco1.root"
08-Dec-2025 22:49:51 PST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 75.5997 94.4934 104.489 96.0369 9.04496 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.000935448 0.00481978 0.0161366 0.00443802 0.00404327 10
reco:wclsdatahd:WireCellToolkit 56.5749 58.3819 61.3635 57.9878 1.7069 10
reco:wirefilter:WireFilter 0.0183586 0.0229677 0.0264472 0.0237869 0.00240782 10
reco:gaushit:GausHitFinder 0.385422 0.57025 0.714453 0.607243 0.108131 10
reco:nhitsfilter:NumberOfHitsFilter 0.000110586 0.000167576 0.000272591 0.000158416 4.18605e-05 10
reco:reco3d:SpacePointSolver 0.139943 0.488345 0.88569 0.444607 0.246294 10
reco:hitpdune:DisambigFromSpacePoints 0.140446 0.450344 0.766938 0.499983 0.182306 10
reco:pandora:StandardPandora 3.32394 7.9724 12.2043 8.10887 2.71793 10
reco:pandoraWriter:StandardPandora 0.10785 0.168499 0.22421 0.173529 0.0335316 10
reco:pandoraTrack:LArPandoraTrackCreation 0.402667 0.837554 1.35525 0.763195 0.319392 10
reco:pandoraShower:LArPandoraShowerCreation 0.298794 0.812106 1.2053 0.947906 0.303023 10
reco:pandoracalo:Calorimetry 0.2374 0.469163 0.689324 0.461365 0.154832 10
reco:pandoracalonosce:Calorimetry 0.225324 0.448294 0.657791 0.44552 0.144409 10
reco:pandoraShowercalo:ShowerCalorimetry 0.27632 0.800918 1.20005 0.956719 0.321213 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.269896 0.797084 1.19958 0.948841 0.323633 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0275281 0.0420294 0.054345 0.0436364 0.00755066 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0276833 0.041622 0.0532378 0.044172 0.00752604 10
reco:emtrkmichelid:EmTrackMichelId 12.2328 21.1406 25.8179 21.4362 4.11242 10
[art]:TriggerResults:TriggerResultInserter 2.2507e-05 3.1074e-05 6.7061e-05 2.45835e-05 1.3369e-05 10
end_path:out1:RootOutput 6.577e-06 8.3402e-06 2.1661e-05 6.9065e-06 4.44401e-06 10
end_path:out1:RootOutput(write) 0.750483 1.0182 1.24856 1.0706 0.149346 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5832.81 MB
Peak resident set size usage (VmHWM): 3637.75 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10699876
-rw-r--r--. 1 cuser cuser 231264 Dec 8 22:49 jobscript.log
-rw-r--r--. 1 cuser cuser 198 Dec 8 22:49 justin-processed-pfns.txt
-rw-r--r--. 1 cuser cuser 519 Dec 8 22:49 reco_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 3574 Dec 8 22:49 Pandora_Geometry.xml
-rw-r--r--. 1 cuser cuser 139264 Dec 8 22:49 mem.db
-rw-r--r--. 1 cuser cuser 28672 Dec 8 22:49 time.db
-rw-r--r--. 1 cuser cuser 5549861856 Dec 8 22:49 pdhd_prod_beam__247678_4_1_20251112T042001Z_gen_g4_IonScintPDExt.root_258129_1_1_20251205T192207Z_PDInt.root_265030_70_1_20251208T220718Z_detsim_reco1.root
-rw-r--r--. 1 cuser cuser 31635910 Dec 8 22:49 Pandora_Events.pndr
-rw-r--r--. 1 cuser cuser 0 Dec 8 22:31 debugprod.log
-rw-r--r--. 1 cuser cuser 519 Dec 8 22:31 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 5374653341 Dec 8 22:31 temp_detsim.root
-rw-r--r--. 1 cuser cuser 119 Dec 8 14:07 all-input-dids.txt
