Jobsub ID 41739.127@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
] <FrameFanin:nfsp> EOS at call=95 with 8
[09:27:58.143] D [ glue ] frame sink sees EOS
[09:27:58.143] D [ pgraph ] <Pgrapher:> graph execution complete
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.56 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.3 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.22 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.96 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Aux::Resampler : 0.25 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:27:58.143] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:27:58.143] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:27:58.143] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:27:58.143] I [ timer ] Timer: Total node execution : 42.97000089660287 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 24018 traces tagged "gauss"
FrameSaver: q=6.83986e+06 n=647242 tag=gauss
wclsFrameSaver: saving 30251 traces tagged "wiener"
FrameSaver: q=7.52536e+06 n=633583 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1243 XUs and 1519 XVs -> 36 XUVs
C:0 T:1 559 XUs and 448 XVs -> 39 XUVs
C:0 T:2 373 XUs and 483 XVs -> 8 XUVs
C:0 T:3 383 XUs and 426 XVs -> 10 XUVs
C:0 T:4 28391 XUs and 40329 XVs -> 3131 XUVs
C:0 T:5 19567 XUs and 22920 XVs -> 1574 XUVs
C:0 T:6 540 XUs and 492 XVs -> 10 XUVs
C:0 T:7 1041 XUs and 883 XVs -> 40 XUVs
4848 XUVs total
1684 collection wire objects
4848 potential space points
Neighbour search...
209816 tests to find 44366 neighbours
Iterating with no regularization...
Begin: 1.49593e+10
0 1.38928e+10
1 1.37897e+10
2 1.37868e+10
Now with regularization...
Begin: 1.36204e+10
0 1.36197e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 09:29:29 UTC Closed output file "np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039_reco_stage1_20250918T092929_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 34.3955 86.1234 955.878 55.0798 131.349 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.2189e-05 0.000103236 0.000318941 8.78225e-05 4.58825e-05 48
produce:tpcrawdecoder:PDVDTPCReader 6.62318 7.1712 10.1599 6.85787 0.853848 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.387052 0.393929 0.455991 0.390402 0.0112151 48
produce:pdvddaphne:DAPHNEReaderPDVD 2.72719 3.23348 3.59152 3.27059 0.19024 48
produce:ophit:OpHitFinder 0.0315283 0.0442212 0.0532704 0.0452856 0.00468656 48
produce:opflash:OpFlashFinderVerticalDrift 0.0041772 0.00942983 0.0158563 0.010102 0.00282235 48
produce:wclsdatavd:WireCellToolkit 16.0499 29.0654 56.7015 24.7476 9.12882 48
produce:gaushit:GausHitFinder 0.210055 0.554722 1.21717 0.491769 0.214709 48
produce:nhitsfilter:NumberOfHitsFilter 7.8839e-05 0.000143498 0.000269527 0.000135034 3.98414e-05 48
produce:reco3d:SpacePointSolver 1.43146 4.76523 18.0321 3.92884 3.02708 48
produce:hitpdune:DisambigFromSpacePoints 0.0126449 0.0712145 0.321879 0.0546644 0.0612634 48
produce:pandora:StandardPandora 2.95858 38.3472 882.737 11.2931 125.635 48
produce:pandoraTrack:LArPandoraTrackCreation 0.0556866 0.260387 0.848838 0.193343 0.191461 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.00484111 0.0138943 0.0316416 0.0135863 0.00552507 48
[art]:TriggerResults:TriggerResultInserter 1.5924e-05 3.61946e-05 0.000160542 3.13775e-05 2.09659e-05 48
end_path:out1:RootOutput 3.756e-06 8.76206e-06 4.0321e-05 7.962e-06 6.47444e-06 48
end_path:out1:RootOutput(write) 1.47159 2.16744 2.89102 2.1518 0.314474 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5917.54 MB
Peak resident set size usage (VmHWM): 3712.66 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039_reco_stage1_20250918T092929_keepup.root
\tHists: np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039_reco_stage1_20250918T092929_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039_reco_stage1_20250918T092929_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039_reco_stage1_20250918T092929_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": 1758187770.0,
"core.end_time": 1758187770.0,
"core.events": [
112864,
112870,
112876,
112882,
112888,
112894,
112900,
112906,
112912,
112918,
112924,
112930,
112936,
112942,
112948,
112954,
112960,
112966,
112972,
112978,
112984,
112990,
112996,
113002,
113008,
113014,
113020,
113026,
113032,
113038,
113044,
113050,
113056,
113062,
113068,
113074,
113080,
113086,
113092,
113098,
113104,
113110,
113116,
113122,
113128,
113134,
113140,
113146
],
"core.event_count": 48,
"core.first_event_number": 112864,
"core.last_event_number": 113146,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039_reco_stage1_20250918T092929_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": 1758187770.0,
"core.end_time": 1758187770.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0394_df-s05-d4_dw_0_20250918T073039.hdf5"
}
]
} 