Jobsub ID 47125.148@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
sSigProc:anode0sigproc0> EOS at call=37 anode=0
[20:56:50.391] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[20:56:50.391] D [ glue ] frame sink sees EOS
[20:56:50.391] D [ pgraph ] <Pgrapher:> graph execution complete
[20:56:50.391] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.24 sec
[20:56:50.391] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.89 sec
[20:56:50.391] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.87 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.71 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.04 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.01 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.65 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.07 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Aux::Resampler : 1.03 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Aux::Resampler : 1.01 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Aux::Resampler : 0.98 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Aux::Resampler : 0.96 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:56:50.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:56:50.392] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:56:50.392] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:56:50.392] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:56:50.392] I [ timer ] Timer: Total node execution : 94.52999950014055 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 62164 traces tagged "gauss"
FrameSaver: q=9.40482e+06 n=1146949 tag=gauss
wclsFrameSaver: saving 76312 traces tagged "wiener"
FrameSaver: q=9.88486e+06 n=1083193 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1088 XUs and 1257 XVs -> 57 XUVs
C:0 T:1 953 XUs and 1226 XVs -> 60 XUVs
C:0 T:2 559 XUs and 491 XVs -> 37 XUVs
C:0 T:3 24 XUs and 37 XVs -> 0 XUVs
C:0 T:4 4966 XUs and 6284 XVs -> 155 XUVs
C:0 T:5 888 XUs and 1060 XVs -> 64 XUVs
C:0 T:6 1739 XUs and 2066 XVs -> 38 XUVs
C:0 T:7 2600 XUs and 2043 XVs -> 108 XUVs
C:0 T:8 2436 XUs and 3324 XVs -> 211 XUVs
C:0 T:9 1967 XUs and 1985 XVs -> 109 XUVs
C:0 T:10 2916 XUs and 3369 XVs -> 199 XUVs
C:0 T:11 1015 XUs and 1257 XVs -> 50 XUVs
C:0 T:12 2196 XUs and 3165 XVs -> 169 XUVs
C:0 T:13 3320 XUs and 3270 XVs -> 222 XUVs
C:0 T:14 2867 XUs and 3655 XVs -> 155 XUVs
C:0 T:15 2568 XUs and 2707 XVs -> 135 XUVs
1769 XUVs total
1486 collection wire objects
1769 potential space points
Neighbour search...
10597 tests to find 5334 neighbours
Iterating with no regularization...
Begin: 5.02089e+08
0 4.91493e+08
1 4.91225e+08
Now with regularization...
Begin: 4.81268e+08
0 4.81248e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
16-Sep-2025 20:58:32 BST Closed output file "np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138_reco_stage1_20250916T195832_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 144.195 219.89 409.08 198.368 75.5665 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.9506e-05 7.65058e-05 0.00016515 6.9992e-05 2.24996e-05 19
produce:tpcrawdecoder:PDVDTPCReader 17.8542 18.459 20.1454 18.3732 0.447841 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.418153 0.427399 0.453196 0.424684 0.00848232 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000347024 0.000392689 0.000679891 0.000379261 7.0283e-05 19
produce:ophit:OpHitFinder 0.00010499 0.000174325 0.000792917 0.000122651 0.000149421 19
produce:opflash:OpFlashFinderVerticalDrift 4.0693e-05 5.83934e-05 0.000278096 4.6184e-05 5.18577e-05 19
produce:wclsdatavd:WireCellToolkit 75.2686 96.1391 113.923 95.4906 11.1808 19
produce:gaushit:GausHitFinder 1.10039 1.79873 2.93844 1.72395 0.492957 19
produce:nhitsfilter:NumberOfHitsFilter 0.00033894 0.000499542 0.000654307 0.000488424 9.93862e-05 19
produce:reco3d:SpacePointSolver 9.86058 19.7526 36.8305 17.344 7.55657 19
produce:hitpdune:DisambigFromSpacePoints 0.119396 0.288713 0.711393 0.223758 0.161184 19
produce:pandora:StandardPandora 21.3682 75.557 230.279 63.8092 60.2169 19
produce:pandoraTrack:LArPandoraTrackCreation 0.63926 2.11433 9.60131 1.5676 1.99048 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0211385 0.036288 0.0663935 0.0357884 0.0108508 19
[art]:TriggerResults:TriggerResultInserter 2.4215e-05 3.71043e-05 7.1327e-05 3.5225e-05 9.64431e-06 19
end_path:out1:RootOutput 8.296e-06 1.11143e-05 2.5139e-05 1.0268e-05 3.54347e-06 19
end_path:out1:RootOutput(write) 4.71494 5.26392 6.00155 5.2045 0.36314 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5308.36 MB
Peak resident set size usage (VmHWM): 3409.99 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138_reco_stage1_20250916T195832_keepup.root
\tHists: np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138_reco_stage1_20250916T195832_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138_reco_stage1_20250916T195832_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138_reco_stage1_20250916T195832_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": 1758052712.0,
"core.end_time": 1758052712.0,
"core.events": [
18348,
18352,
18356,
18360,
18364,
18368,
18372,
18376,
18380,
18384,
18388,
18392,
18396,
18400,
18404,
18408,
18412,
18416,
18420
],
"core.event_count": 19,
"core.first_event_number": 18348,
"core.last_event_number": 18420,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138_reco_stage1_20250916T195832_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": 1758052712.0,
"core.end_time": 1758052712.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0238_df-s05-d0_dw_0_20250916T181138.hdf5"
}
]
} 