Jobsub ID 48994.59@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
] <ChannelSelector:chsel0> see EOS at call=39
[22:46:22.254] D [ aux ] <Resampler:resmp0> EOS at call=79
[22:46:22.254] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[22:46:22.254] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[22:46:22.254] D [ glue ] frame sink sees EOS
[22:46:22.254] D [ pgraph ] <Pgrapher:> graph execution complete
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.4 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.37 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.02 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.91 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Aux::Resampler : 0.6 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Aux::Resampler : 0.6 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Aux::Resampler : 0.58 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Aux::Resampler : 0.57 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:46:22.254] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:46:22.254] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:46:22.254] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:46:22.255] I [ timer ] Timer: Total node execution : 58.07999983243644 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22484 traces tagged "gauss"
FrameSaver: q=4.92171e+06 n=563962 tag=gauss
wclsFrameSaver: saving 28385 traces tagged "wiener"
FrameSaver: q=5.33376e+06 n=547298 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 53 XUs and 77 XVs -> 4 XUVs
C:0 T:1 389 XUs and 421 XVs -> 13 XUVs
C:0 T:2 1092 XUs and 1088 XVs -> 52 XUVs
C:0 T:3 1774 XUs and 1863 XVs -> 99 XUVs
C:0 T:4 151 XUs and 262 XVs -> 4 XUVs
C:0 T:5 10886 XUs and 14771 XVs -> 954 XUVs
C:0 T:6 73 XUs and 77 XVs -> 6 XUVs
C:0 T:7 7139 XUs and 12335 XVs -> 588 XUVs
1720 XUVs total
1141 collection wire objects
1720 potential space points
Neighbour search...
71908 tests to find 18978 neighbours
Iterating with no regularization...
Begin: 3.02278e+10
0 3.01097e+10
1 3.01085e+10
Now with regularization...
Begin: 3.00906e+10
0 3.00906e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 22:47:07 BST Closed output file "np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954_reco_stage1_20250918T214707_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 78.3446 164.129 676.516 146.775 96.9008 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.957e-05 0.000162005 0.000416802 0.000148714 6.43486e-05 40
produce:tpcrawdecoder:PDVDTPCReader 16.1767 37.6317 86.9429 35.6055 12.6925 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.371003 0.447339 0.668419 0.416366 0.0707369 40
produce:pdvddaphne:DAPHNEReaderPDVD 5.02053 8.5244 12.7258 8.66206 2.01128 40
produce:ophit:OpHitFinder 0.043316 0.0597868 0.0722904 0.0593616 0.00619262 40
produce:opflash:OpFlashFinderVerticalDrift 0.00699462 0.0145796 0.0223834 0.01445 0.00321547 40
produce:wclsdatavd:WireCellToolkit 28.6483 50.2894 88.4277 45.6935 14.7912 40
produce:gaushit:GausHitFinder 0.315359 0.902294 1.80706 0.888949 0.306574 40
produce:nhitsfilter:NumberOfHitsFilter 0.000107382 0.000253439 0.000524214 0.000242786 9.20533e-05 40
produce:reco3d:SpacePointSolver 1.84437 8.54884 28.0739 8.07143 4.85774 40
produce:hitpdune:DisambigFromSpacePoints 0.0178542 0.158189 0.88256 0.14449 0.149249 40
produce:pandora:StandardPandora 3.96265 53.4129 552.392 28.4377 86.2585 40
produce:pandoraTrack:LArPandoraTrackCreation 0.0937871 0.552167 2.09537 0.521912 0.407746 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.00790402 0.0233528 0.0472413 0.0214564 0.00817511 40
[art]:TriggerResults:TriggerResultInserter 2.1811e-05 4.53799e-05 0.000127459 3.8963e-05 2.02735e-05 40
end_path:out1:RootOutput 3.987e-06 1.1717e-05 3.9504e-05 1.1206e-05 6.14509e-06 40
end_path:out1:RootOutput(write) 2.79611 3.53126 4.27612 3.46855 0.326461 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4620.66 MB
Peak resident set size usage (VmHWM): 2695.26 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954_reco_stage1_20250918T214707_keepup.root
\tHists: np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954_reco_stage1_20250918T214707_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954_reco_stage1_20250918T214707_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954_reco_stage1_20250918T214707_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": 1758232028.0,
"core.end_time": 1758232028.0,
"core.events": [
5858,
5864,
5870,
5876,
5882,
5888,
5894,
5900,
5906,
5912,
5918,
5924,
5930,
5936,
5942,
5948,
5954,
5960,
5966,
5972,
5978,
5984,
5990,
5996,
6002,
6008,
6014,
6020,
6026,
6032,
6038,
6044,
6050,
6056,
6062,
6068,
6074,
6080,
6086,
6092
],
"core.event_count": 40,
"core.first_event_number": 5858,
"core.last_event_number": 6092,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954_reco_stage1_20250918T214707_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": 1758232028.0,
"core.end_time": 1758232028.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0024_df-s04-d3_dw_0_20250918T182954.hdf5"
}
]
} 