Jobsub ID 47495.5@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
nibusSigProc:anode0sigproc0> EOS at call=39 anode=0
[16:01:00.083] D [ glue ] <FrameFanin:nfsp> EOS at call=39 with 8
[16:01:00.083] D [ glue ] frame sink sees EOS
[16:01:00.083] D [ pgraph ] <Pgrapher:> graph execution complete
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.39 sec
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.19 sec
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.07 sec
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.92 sec
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.17 sec
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.98 sec
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.6 sec
[16:01:00.083] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.41 sec
[16:01:00.083] I [ timer ] Timer: WireCell::Aux::Resampler : 1.19 sec
[16:01:00.083] I [ timer ] Timer: WireCell::Aux::Resampler : 1.19 sec
[16:01:00.083] I [ timer ] Timer: WireCell::Aux::Resampler : 1.19 sec
[16:01:00.083] I [ timer ] Timer: WireCell::Aux::Resampler : 1.18 sec
[16:01:00.084] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[16:01:00.084] I [ timer ] Timer: WireCell::Gen::Retagger : 0.02 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:01:00.084] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:01:00.084] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:01:00.084] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:01:00.084] I [ timer ] Timer: Total node execution : 88.52999966032803 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 57803 traces tagged "gauss"
FrameSaver: q=8.97948e+06 n=1126215 tag=gauss
wclsFrameSaver: saving 71058 traces tagged "wiener"
FrameSaver: q=9.4702e+06 n=1074023 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 132 XUs and 208 XVs -> 9 XUVs
C:0 T:1 568 XUs and 710 XVs -> 25 XUVs
C:0 T:2 1967 XUs and 2131 XVs -> 78 XUVs
C:0 T:3 2222 XUs and 2441 XVs -> 111 XUVs
C:0 T:4 2760 XUs and 2794 XVs -> 170 XUVs
C:0 T:5 3422 XUs and 2933 XVs -> 91 XUVs
C:0 T:6 621 XUs and 686 XVs -> 40 XUVs
C:0 T:7 655 XUs and 595 XVs -> 28 XUVs
C:0 T:8 1286 XUs and 935 XVs -> 100 XUVs
C:0 T:9 2269 XUs and 1952 XVs -> 146 XUVs
C:0 T:10 3707 XUs and 4614 XVs -> 185 XUVs
C:0 T:11 2284 XUs and 2354 XVs -> 180 XUVs
C:0 T:12 1189 XUs and 1181 XVs -> 44 XUVs
C:0 T:13 1428 XUs and 2279 XVs -> 112 XUVs
C:0 T:14 3432 XUs and 4437 XVs -> 239 XUVs
C:0 T:15 4375 XUs and 3674 XVs -> 274 XUVs
1832 XUVs total
1478 collection wire objects
1832 potential space points
Neighbour search...
17934 tests to find 9082 neighbours
Iterating with no regularization...
Begin: 7.74803e+08
0 7.49918e+08
1 7.49442e+08
Now with regularization...
Begin: 7.37664e+08
0 7.37636e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 16:02:50 CEST Closed output file "np02vd_raw_run039388_0726_df-s05-d0_dw_0_20250917T042844_reco_stage1_20250917T140250_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 91.6462 353.57 443.893 361.41 70.0706 20
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.0847e-05 6.30986e-05 0.000128207 5.8985e-05 1.69512e-05 20
produce:tpcrawdecoder:PDVDTPCReader 42.7049 158.015 193.413 157.964 30.5077 20
produce:triggerrawdecoder:PDVDTriggerReader4 0.297259 0.397552 0.566294 0.385046 0.0726187 20
produce:pdvddaphne:DAPHNEReaderPDVD 0.000384099 0.000418224 0.000791151 0.000396137 8.63582e-05 20
produce:ophit:OpHitFinder 0.000110039 0.000160628 0.00079123 0.000124221 0.000145562 20
produce:opflash:OpFlashFinderVerticalDrift 4.5025e-05 6.40982e-05 0.000332057 5.06815e-05 6.15337e-05 20
produce:wclsdatavd:WireCellToolkit 34.717 96.7404 117.855 100.027 15.9943 20
produce:gaushit:GausHitFinder 1.15889 1.62942 2.24327 1.59506 0.31637 20
produce:nhitsfilter:NumberOfHitsFilter 0.000110927 0.000368657 0.000524878 0.000371883 8.57366e-05 20
produce:reco3d:SpacePointSolver 3.11266 16.1442 23.8611 16.2997 4.95043 20
produce:hitpdune:DisambigFromSpacePoints 0.0725924 0.244985 0.371749 0.241834 0.0782544 20
produce:pandora:StandardPandora 7.34209 73.519 120.785 69.3872 26.4624 20
produce:pandoraTrack:LArPandoraTrackCreation 0.407322 1.32402 2.28899 1.25158 0.521813 20
produce:pandoraGnocalo:GnocchiCalorimetry 0.0129011 0.0339887 0.0447992 0.0351479 0.00788606 20
[art]:TriggerResults:TriggerResultInserter 1.6212e-05 2.45045e-05 5.2913e-05 2.4715e-05 7.97177e-06 20
end_path:out1:RootOutput 3.518e-06 7.48135e-06 2.2342e-05 6.9325e-06 3.50078e-06 20
end_path:out1:RootOutput(write) 1.59102 5.48766 6.11516 5.6719 0.909844 20
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4726.76 MB
Peak resident set size usage (VmHWM): 2844.25 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0726_df-s05-d0_dw_0_20250917T042844_reco_stage1_20250917T140250_keepup.root
\tHists: np02vd_raw_run039388_0726_df-s05-d0_dw_0_20250917T042844_reco_stage1_20250917T140250_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0726_df-s05-d0_dw_0_20250917T042844_reco_stage1_20250917T140250_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0726_df-s05-d0_dw_0_20250917T042844_reco_stage1_20250917T140250_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": 1758117770.0,
"core.end_time": 1758117770.0,
"core.events": [
55892,
55896,
55900,
55904,
55908,
55912,
55916,
55920,
55924,
55928,
55932,
55936,
55940,
55944,
55948,
55952,
55956,
55960,
55964,
55968
],
"core.event_count": 20,
"core.first_event_number": 55892,
"core.last_event_number": 55968,
"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_0726_df-s05-d0_dw_0_20250917T042844.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0726_df-s05-d0_dw_0_20250917T042844_reco_stage1_20250917T140250_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": 1758117770.0,
"core.end_time": 1758117770.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_0726_df-s05-d0_dw_0_20250917T042844.hdf5"
}
]
} 