Jobsub ID 40378.172@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
all=18
[13:39:18.564] D [ aux ] <Resampler:resmp0> EOS at call=37
[13:39:18.564] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[13:39:18.564] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[13:39:18.564] D [ glue ] frame sink sees EOS
[13:39:18.564] D [ pgraph ] <Pgrapher:> graph execution complete
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.89 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.32 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.29 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.19 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.89 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.46 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.19 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.12 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Aux::Resampler : 1.18 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Aux::Resampler : 1.15 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Aux::Resampler : 1.07 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Aux::Resampler : 0.67 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:39:18.564] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[13:39:18.564] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[13:39:18.564] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[13:39:18.564] I [ timer ] Timer: Total node execution : 59.44999989680946 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 46957 traces tagged "gauss"
FrameSaver: q=6.83058e+06 n=911612 tag=gauss
wclsFrameSaver: saving 56397 traces tagged "wiener"
FrameSaver: q=7.17167e+06 n=875811 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1085 XUs and 1067 XVs -> 49 XUVs
C:0 T:1 406 XUs and 422 XVs -> 34 XUVs
C:0 T:2 790 XUs and 1049 XVs -> 35 XUVs
C:0 T:3 1332 XUs and 1410 XVs -> 62 XUVs
C:0 T:4 1061 XUs and 846 XVs -> 50 XUVs
C:0 T:5 576 XUs and 821 XVs -> 21 XUVs
C:0 T:6 1402 XUs and 1155 XVs -> 42 XUVs
C:0 T:7 537 XUs and 624 XVs -> 33 XUVs
C:0 T:8 1369 XUs and 2473 XVs -> 114 XUVs
C:0 T:9 648 XUs and 1047 XVs -> 74 XUVs
C:0 T:10 1939 XUs and 2559 XVs -> 133 XUVs
C:0 T:11 48 XUs and 58 XVs -> 4 XUVs
C:0 T:12 875 XUs and 1252 XVs -> 102 XUVs
C:0 T:13 1858 XUs and 2087 XVs -> 170 XUVs
C:0 T:14 1826 XUs and 2539 XVs -> 197 XUVs
C:0 T:15 1743 XUs and 2074 XVs -> 142 XUVs
1262 XUVs total
1040 collection wire objects
1262 potential space points
Neighbour search...
12016 tests to find 5980 neighbours
Iterating with no regularization...
Begin: 4.72436e+08
0 4.60998e+08
1 4.60848e+08
Now with regularization...
Begin: 4.50421e+08
0 4.50408e+08
16-Sep-2025 13:40:11 CEST Closed output file "np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409_reco_stage1_20250916T114011_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 106.511 145.087 206.21 140.218 26.2203 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.4921e-05 8.78366e-05 0.000133981 8.1711e-05 2.00794e-05 19
produce:tpcrawdecoder:PDVDTPCReader 5.58972 7.38173 7.79803 7.47426 0.487632 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.00675831 0.0151238 0.079279 0.00901709 0.0164514 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000280132 0.000341818 0.000657355 0.000312313 8.17798e-05 19
produce:ophit:OpHitFinder 0.000140831 0.000228897 0.000854657 0.000188171 0.000154393 19
produce:opflash:OpFlashFinderVerticalDrift 5.054e-05 8.08784e-05 0.000339872 6.4011e-05 6.27027e-05 19
produce:wclsdatavd:WireCellToolkit 53.0101 64.5496 72.9899 65.396 5.5797 19
produce:gaushit:GausHitFinder 0.773253 1.21634 1.85055 1.20515 0.229054 19
produce:nhitsfilter:NumberOfHitsFilter 0.000182521 0.000293824 0.000590794 0.000289832 8.29134e-05 19
produce:reco3d:SpacePointSolver 6.79183 13.7272 19.5447 13.8636 3.02585 19
produce:hitpdune:DisambigFromSpacePoints 0.0635662 0.20045 0.314601 0.198902 0.0594918 19
produce:pandora:StandardPandora 24.5736 52.4239 105.311 53.8745 21.4891 19
produce:pandoraTrack:LArPandoraTrackCreation 0.263502 0.861772 1.4684 0.811536 0.286322 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0142415 0.0278342 0.0471405 0.024148 0.0100806 19
[art]:TriggerResults:TriggerResultInserter 1.2221e-05 2.34418e-05 4.221e-05 2.073e-05 7.49644e-06 19
end_path:out1:RootOutput 5.83e-06 9.12474e-06 2.325e-05 7.45e-06 4.5706e-06 19
end_path:out1:RootOutput(write) 3.61714 4.65012 6.34277 4.42101 0.730226 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5049.01 MB
Peak resident set size usage (VmHWM): 3089.53 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409_reco_stage1_20250916T114011_keepup.root
\tHists: np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409_reco_stage1_20250916T114012_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409_reco_stage1_20250916T114011_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409_reco_stage1_20250916T114011_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_10_00d00",
"core.data_tier": "full-reconstructed",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1758022812.0,
"core.end_time": 1758022812.0,
"core.events": [
71591,
71595,
71599,
71603,
71607,
71611,
71615,
71619,
71623,
71627,
71631,
71635,
71639,
71643,
71647,
71651,
71655,
71659,
71663
],
"core.event_count": 19,
"core.first_event_number": 71591,
"core.last_event_number": 71663,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409_reco_stage1_20250916T114012_keepup_hists.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "root",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_10_00d00",
"core.data_tier": "root-tuple-virtual",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1758022812.0,
"core.end_time": 1758022812.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0930_df-s05-d3_dw_0_20250916T103409.hdf5"
}
]
} 