Jobsub ID 41739.26@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[08:39:58.439] D [ glue ] frame sink sees EOS
[08:39:58.439] D [ pgraph ] <Pgrapher:> graph execution complete
[08:39:58.439] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.7 sec
[08:39:58.439] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.32 sec
[08:39:58.439] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.18 sec
[08:39:58.439] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.82 sec
[08:39:58.439] I [ timer ] Timer: WireCell::Aux::Resampler : 0.23 sec
[08:39:58.439] I [ timer ] Timer: WireCell::Aux::Resampler : 0.22 sec
[08:39:58.439] I [ timer ] Timer: WireCell::Aux::Resampler : 0.22 sec
[08:39:58.439] I [ timer ] Timer: WireCell::Aux::Resampler : 0.22 sec
[08:39:58.440] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:39:58.440] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[08:39:58.440] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[08:39:58.440] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:39:58.440] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[08:39:58.440] I [ timer ] Timer: Total node execution : 45.959999503567815 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 27693 traces tagged "gauss"
FrameSaver: q=6.05071e+06 n=685888 tag=gauss
wclsFrameSaver: saving 35137 traces tagged "wiener"
FrameSaver: q=6.56679e+06 n=661938 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2076 XUs and 1999 XVs -> 48 XUVs
C:0 T:1 409 XUs and 347 XVs -> 20 XUVs
C:0 T:2 354 XUs and 542 XVs -> 20 XUVs
C:0 T:3 36398 XUs and 58793 XVs -> 3232 XUVs
C:0 T:4 624 XUs and 855 XVs -> 49 XUVs
C:0 T:5 317 XUs and 231 XVs -> 9 XUVs
C:0 T:6 8310 XUs and 10613 XVs -> 717 XUVs
C:0 T:7 266 XUs and 283 XVs -> 8 XUVs
4103 XUVs total
1911 collection wire objects
4103 potential space points
Neighbour search...
112397 tests to find 25736 neighbours
Iterating with no regularization...
Begin: 1.40751e+10
0 1.31065e+10
1 1.30628e+10
2 1.30623e+10
Now with regularization...
Begin: 1.29708e+10
0 1.29706e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 08:41:12 UTC Closed output file "np02vd_raw_run039433_0376_df-s05-d3_dw_0_20250918T064858_reco_stage1_20250918T084112_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 39.86 64.5487 131.267 59.6325 22.8595 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.4698e-05 0.000131524 0.000361106 0.000115925 5.07134e-05 47
produce:tpcrawdecoder:PDVDTPCReader 6.794 7.56256 10.7601 7.18493 1.02804 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.392302 0.396394 0.413186 0.39605 0.00362001 47
produce:pdvddaphne:DAPHNEReaderPDVD 2.87429 3.3048 3.6027 3.33949 0.18063 47
produce:ophit:OpHitFinder 0.0355043 0.0459011 0.0581394 0.0452322 0.00530549 47
produce:opflash:OpFlashFinderVerticalDrift 0.00261187 0.0103634 0.0193606 0.0102698 0.0032488 47
produce:wclsdatavd:WireCellToolkit 18.5274 30.8788 55.9227 26.6966 9.74336 47
produce:gaushit:GausHitFinder 0.239672 0.553115 1.07718 0.553342 0.173552 47
produce:nhitsfilter:NumberOfHitsFilter 0.000115084 0.00031436 0.00165317 0.000232702 0.000251517 47
produce:reco3d:SpacePointSolver 0.858422 4.48512 10.4703 4.13527 1.85862 47
produce:hitpdune:DisambigFromSpacePoints 0.0127086 0.064048 0.226998 0.051903 0.0454423 47
produce:pandora:StandardPandora 1.60939 14.6171 58.72 9.50687 13.5495 47
produce:pandoraTrack:LArPandoraTrackCreation 0.0439022 0.304876 1.41989 0.243663 0.264333 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.0050014 0.0150479 0.0284489 0.0145099 0.00543211 47
[art]:TriggerResults:TriggerResultInserter 1.6565e-05 4.35716e-05 0.000119571 3.5003e-05 2.34588e-05 47
end_path:out1:RootOutput 3.926e-06 1.17977e-05 3.7306e-05 1.1367e-05 5.04512e-06 47
end_path:out1:RootOutput(write) 1.45876 2.27176 3.14934 2.21411 0.433671 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5197.15 MB
Peak resident set size usage (VmHWM): 3026.35 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0376_df-s05-d3_dw_0_20250918T064858_reco_stage1_20250918T084112_keepup.root
\tHists: np02vd_raw_run039433_0376_df-s05-d3_dw_0_20250918T064858_reco_stage1_20250918T084112_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0376_df-s05-d3_dw_0_20250918T064858_reco_stage1_20250918T084112_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0376_df-s05-d3_dw_0_20250918T064858_reco_stage1_20250918T084112_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": 1758184873.0,
"core.end_time": 1758184873.0,
"core.events": [
107967,
107973,
107979,
107985,
107991,
107997,
108003,
108009,
108015,
108021,
108027,
108033,
108039,
108045,
108051,
108057,
108063,
108069,
108075,
108081,
108087,
108093,
108099,
108105,
108111,
108117,
108123,
108129,
108135,
108141,
108147,
108153,
108159,
108165,
108171,
108177,
108183,
108189,
108195,
108201,
108207,
108213,
108219,
108225,
108231,
108237,
108243
],
"core.event_count": 47,
"core.first_event_number": 107967,
"core.last_event_number": 108243,
"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_0376_df-s05-d3_dw_0_20250918T064858.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0376_df-s05-d3_dw_0_20250918T064858_reco_stage1_20250918T084112_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": 1758184873.0,
"core.end_time": 1758184873.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_0376_df-s05-d3_dw_0_20250918T064858.hdf5"
}
]
}