Jobsub ID 39337.31@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
Proc:anode0sigproc0> EOS at call=35 anode=0
[20:03:04.555] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[20:03:04.555] D [ glue ] frame sink sees EOS
[20:03:04.555] D [ pgraph ] <Pgrapher:> graph execution complete
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.94 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.75 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.72 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.44 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.37 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.19 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.69 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.79 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Aux::Resampler : 1.11 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Aux::Resampler : 1.1 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Aux::Resampler : 1.02 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Aux::Resampler : 0.95 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:04.555] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:03:04.555] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:03:04.555] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:03:04.555] I [ timer ] Timer: Total node execution : 74.12999891862273 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 59818 traces tagged "gauss"
FrameSaver: q=1.27185e+07 n=1415852 tag=gauss
wclsFrameSaver: saving 76287 traces tagged "wiener"
FrameSaver: q=1.36447e+07 n=1346624 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1065 XUs and 1223 XVs -> 51 XUVs
C:0 T:1 455 XUs and 392 XVs -> 23 XUVs
C:0 T:2 1003 XUs and 860 XVs -> 29 XUVs
C:0 T:3 512 XUs and 421 XVs -> 29 XUVs
C:0 T:4 170 XUs and 218 XVs -> 17 XUVs
C:0 T:5 226 XUs and 176 XVs -> 15 XUVs
C:0 T:6 119 XUs and 106 XVs -> 4 XUVs
C:0 T:7 537 XUs and 525 XVs -> 27 XUVs
C:0 T:8 26673 XUs and 51702 XVs -> 6993 XUVs
C:0 T:9 16490 XUs and 20344 XVs -> 2220 XUVs
C:0 T:10 8267 XUs and 20072 XVs -> 3408 XUVs
C:0 T:11 11420 XUs and 12684 XVs -> 1819 XUVs
C:0 T:12 8546 XUs and 13162 XVs -> 1688 XUVs
C:0 T:13 7176 XUs and 10366 XVs -> 1119 XUVs
C:0 T:14 2802 XUs and 4335 XVs -> 818 XUVs
C:0 T:15 13235 XUs and 20076 XVs -> 2119 XUVs
20379 XUVs total
3398 collection wire objects
20379 potential space points
Neighbour search...
2585293 tests to find 1112378 neighbours
Iterating with no regularization...
Begin: 3.99726e+09
0 3.80388e+09
1 3.78881e+09
2 3.78736e+09
Now with regularization...
Begin: 3.76169e+09
0 3.76104e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
13-Sep-2025 20:05:44 CEST Closed output file "np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401_reco_stage1_20250913T180544_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 126.755 204.281 306.422 197.163 55.0514 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.8771e-05 8.98998e-05 0.000170192 8.4586e-05 2.8913e-05 18
produce:tpcrawdecoder:PDVDTPCReader 7.25342 10.8482 62.0793 7.84834 12.4298 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.00111276 0.00178823 0.00685623 0.00141365 0.00127239 18
produce:pdvddaphne:DAPHNEReaderPDVD 3.98534 4.60778 5.72982 4.59889 0.483045 18
produce:ophit:OpHitFinder 0.0461855 0.0574691 0.0689316 0.0553539 0.00747856 18
produce:opflash:OpFlashFinderVerticalDrift 0.00868041 0.0141634 0.0225779 0.0135764 0.0033095 18
produce:wclsdatavd:WireCellToolkit 60.0781 71.1383 85.3227 71.5819 6.66184 18
produce:gaushit:GausHitFinder 0.827874 1.38001 2.03717 1.32592 0.357311 18
produce:nhitsfilter:NumberOfHitsFilter 0.000246175 0.000417893 0.00063899 0.000407627 9.82027e-05 18
produce:reco3d:SpacePointSolver 11.1724 19.0423 29.0367 17.6859 5.58098 18
produce:hitpdune:DisambigFromSpacePoints 0.134521 0.335106 0.599217 0.305997 0.128778 18
produce:pandora:StandardPandora 24.0406 90.0752 173.932 81.9543 44.8345 18
produce:pandoraTrack:LArPandoraTrackCreation 0.562931 1.34216 1.98879 1.42661 0.466893 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0223777 0.036177 0.057277 0.0340055 0.0100974 18
[art]:TriggerResults:TriggerResultInserter 1.885e-05 2.63231e-05 5.21e-05 2.245e-05 8.86191e-06 18
end_path:out1:RootOutput 4.11e-06 8.66006e-06 2.404e-05 7.615e-06 4.34253e-06 18
end_path:out1:RootOutput(write) 4.83896 5.35485 6.09039 5.17854 0.409532 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5173.95 MB
Peak resident set size usage (VmHWM): 3250.88 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401_reco_stage1_20250913T180544_keepup.root
\tHists: np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401_reco_stage1_20250913T180544_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401_reco_stage1_20250913T180544_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401_reco_stage1_20250913T180544_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": 1757786745.0,
"core.end_time": 1757786745.0,
"core.events": [
57602,
57622,
57642,
57662,
57682,
57702,
57722,
57742,
57762,
57782,
57802,
57822,
57842,
57862,
57882,
57902,
57922,
57942
],
"core.event_count": 18,
"core.first_event_number": 57602,
"core.last_event_number": 57942,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39275
],
"core.runs_subruns": [
3927500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401_reco_stage1_20250913T180544_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": 1757786745.0,
"core.end_time": 1757786745.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39275
],
"core.runs_subruns": [
3927500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039275_0160_df-s02-d0_dw_0_20250901T195401.hdf5"
}
]
} 