Jobsub ID 268896.150@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
:14.387] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 47229 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":22519 [0] "wiener0":24710 [24710] ] cmm:[ bad:0 lf_noisy:128 ] input 1: frame: ident=189 time=0 tick=512 with 30844 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":14039 [0] "wiener1":16805 [16805] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 42643 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":18291 [0] "wiener2":24352 [24352] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 45724 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":18886 [0] "wiener3":26838 [26838] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 166440 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":22519 [0] "gauss1":14039 [0] "gauss2":18291 [0] "gauss3":18886 [0] "wiener0":24710 [24710] "wiener1":16805 [16805] "wiener2":24352 [24352] "wiener3":26838 [26838] ] cmm:[ bad:0 lf_noisy:128 ]
Retagger: tagging trace set: wiener with 92705 traces, 92705 summary
Retagger: tagging trace set: gauss with 73735 traces, 0 summary
[16:23:14.407] D [ glue ] sink frame: #189 @0 with 166440 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[16:23:14.407] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[16:23:14.407] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[16:23:14.407] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[16:23:14.407] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[16:23:14.407] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[16:23:14.407] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[16:23:14.407] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[16:23:14.407] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[16:23:14.408] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[16:23:14.408] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[16:23:14.408] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[16:23:14.408] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[16:23:14.408] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[16:23:14.408] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[16:23:14.408] D [ glue ] frame sink sees EOS
[16:23:14.408] D [ pgraph ] <Pgrapher:> graph execution complete
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.04 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.81 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.56 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.41 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.3 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.29 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.98 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.78 sec
[16:23:14.408] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:23:14.408] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:23:14.408] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:23:14.408] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:23:14.408] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:23:14.408] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:23:14.408] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:23:14.408] I [ timer ] Timer: Total node execution : 51.250000551342964 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 73735 traces tagged "gauss"
FrameSaver: q=2.41523e+06 n=1179662 tag=gauss
wclsFrameSaver: saving 92705 traces tagged "wiener"
FrameSaver: q=3.07029e+06 n=1148260 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 14503 XUs and 32761 XVs -> 830 XUVs
C:0 T:3 33 XUs and 45 XVs -> 3 XUVs
C:0 T:4 38 XUs and 28 XVs -> 0 XUVs
C:0 T:5 18696 XUs and 28383 XVs -> 2556 XUVs
C:0 T:6 29781 XUs and 25241 XVs -> 852 XUVs
C:0 T:7 25 XUs and 26 XVs -> 0 XUVs
4241 XUVs total
1834 collection wire objects
4241 potential space points
Neighbour search...
122927 tests to find 73416 neighbours
Iterating with no regularization...
Begin: 3.32522e+07
0 3.00613e+07
1 2.98884e+07
2 2.98685e+07
Now with regularization...
Begin: 2.78721e+07
0 2.78661e+07
17-Dec-2025 16:23:55 EST Closed output file "pdhd_prod_beam__267379_80_1_20251212T161835Z_gen_g4_IonScintPDExt.root_262726_114_1_20251215T212431Z_PDInt.root_268896_150_1_20251217T193551Z_detsim_reco1.root"
17-Dec-2025 16:23:55 EST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 78.6613 101.28 133.118 93.9125 18.2232 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00143073 0.00477109 0.0085254 0.00525671 0.00214977 10
reco:wclsdatahd:WireCellToolkit 49.5298 53.4825 56.5454 53.5616 2.11818 10
reco:wirefilter:WireFilter 0.0158645 0.0269913 0.0394674 0.0266177 0.00644765 10
reco:gaushit:GausHitFinder 0.508566 0.744383 1.02753 0.701676 0.174474 10
reco:nhitsfilter:NumberOfHitsFilter 0.000239015 0.000422345 0.000787703 0.00036051 0.000178673 10
reco:reco3d:SpacePointSolver 0.14735 0.674594 1.29798 0.670092 0.349323 10
reco:hitpdune:DisambigFromSpacePoints 0.15308 0.634359 1.40009 0.485665 0.408287 10
reco:pandora:StandardPandora 3.97852 10.6696 19.8797 8.50183 5.3459 10
reco:pandoraWriter:StandardPandora 0.114648 0.27072 0.393814 0.269368 0.0815438 10
reco:pandoraTrack:LArPandoraTrackCreation 0.570777 1.41061 2.54648 1.30078 0.704592 10
reco:pandoraShower:LArPandoraShowerCreation 0.388022 1.27717 3.4541 0.928182 0.932415 10
reco:pandoracalo:Calorimetry 0.249472 0.769203 1.40713 0.685877 0.372287 10
reco:pandoracalonosce:Calorimetry 0.231191 0.707774 1.35623 0.622222 0.382174 10
reco:pandoraShowercalo:ShowerCalorimetry 0.264434 1.26312 3.43996 0.860101 0.908672 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.258851 1.28356 3.31367 0.954134 0.848666 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.027949 0.0704733 0.103638 0.0742915 0.0217872 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0281409 0.0689349 0.103424 0.0722105 0.0216057 10
reco:emtrkmichelid:EmTrackMichelId 16.4888 26.3057 37.5894 24.189 6.99365 10
[art]:TriggerResults:TriggerResultInserter 3.593e-05 6.04961e-05 0.000103425 5.9893e-05 1.88485e-05 10
end_path:out1:RootOutput 8.315e-06 1.26337e-05 3.716e-05 9.2875e-06 8.46255e-06 10
end_path:out1:RootOutput(write) 1.0058 1.53255 2.13702 1.40684 0.324982 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6222.71 MB
Peak resident set size usage (VmHWM): 4029.05 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12729236
-rw-r--r--. 1 dune osgvo 231254 Dec 17 16:23 jobscript.log
-rw-r--r--. 1 dune osgvo 201 Dec 17 16:23 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo 519 Dec 17 16:23 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 3574 Dec 17 16:23 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo 139264 Dec 17 16:23 mem.db
-rw-r--r--. 1 dune osgvo 28672 Dec 17 16:23 time.db
-rw-r--r--. 1 dune osgvo 6599227234 Dec 17 16:23 pdhd_prod_beam__267379_80_1_20251212T161835Z_gen_g4_IonScintPDExt.root_262726_114_1_20251215T212431Z_PDInt.root_268896_150_1_20251217T193551Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo 37190800 Dec 17 16:23 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo 0 Dec 17 16:04 debugprod.log
-rw-r--r--. 1 dune osgvo 519 Dec 17 16:04 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 6397872206 Dec 17 16:04 temp_detsim.root
-rw-r--r--. 1 dune osgvo 122 Dec 17 14:35 all-input-dids.txt
