Jobsub ID 41739.125@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
at call=93 anode=0
[09:29:10.951] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[09:29:10.951] D [ glue ] frame sink sees EOS
[09:29:10.951] D [ pgraph ] <Pgrapher:> graph execution complete
[09:29:10.951] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.76 sec
[09:29:10.951] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.36 sec
[09:29:10.951] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.27 sec
[09:29:10.951] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.8 sec
[09:29:10.951] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[09:29:10.951] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[09:29:10.951] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[09:29:10.951] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[09:29:10.952] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:29:10.952] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:29:10.952] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:29:10.952] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:29:10.952] I [ timer ] Timer: Total node execution : 49.46000054292381 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 14239 traces tagged "gauss"
FrameSaver: q=2.9705e+06 n=368948 tag=gauss
wclsFrameSaver: saving 17775 traces tagged "wiener"
FrameSaver: q=3.18107e+06 n=359366 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 569 XUs and 489 XVs -> 33 XUVs
C:0 T:1 57 XUs and 46 XVs -> 1 XUVs
C:0 T:2 460 XUs and 410 XVs -> 18 XUVs
C:0 T:3 470 XUs and 522 XVs -> 14 XUVs
C:0 T:4 113 XUs and 309 XVs -> 8 XUVs
C:0 T:5 11204 XUs and 13739 XVs -> 1011 XUVs
C:0 T:6 253 XUs and 369 XVs -> 7 XUVs
C:0 T:7 287 XUs and 368 XVs -> 20 XUVs
1112 XUVs total
642 collection wire objects
1112 potential space points
Neighbour search...
28876 tests to find 7290 neighbours
Iterating with no regularization...
Begin: 3.8758e+09
0 3.79419e+09
1 3.79078e+09
Now with regularization...
Begin: 3.69118e+09
0 3.69102e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 09:29:33 UTC Closed output file "np02vd_raw_run039433_0394_df-s05-d1_dw_0_20250918T073127_reco_stage1_20250918T092933_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 54.8997 88.9735 134.53 84.5064 20.2274 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.4022e-05 0.000126975 0.000482347 0.000100601 6.42976e-05 47
produce:tpcrawdecoder:PDVDTPCReader 7.48252 8.19646 9.7207 7.95784 0.587814 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.392215 0.396382 0.410054 0.395241 0.0041747 47
produce:pdvddaphne:DAPHNEReaderPDVD 3.493 3.93691 4.25762 3.92803 0.183889 47
produce:ophit:OpHitFinder 0.0417331 0.0610723 0.0763299 0.0612115 0.00674653 47
produce:opflash:OpFlashFinderVerticalDrift 0.00122815 0.0162978 0.0865385 0.0153634 0.0114782 47
produce:wclsdatavd:WireCellToolkit 31.0078 44.1149 74.9984 39.7556 11.3341 47
produce:gaushit:GausHitFinder 0.447529 0.78146 1.37453 0.80642 0.214566 47
produce:nhitsfilter:NumberOfHitsFilter 0.000107892 0.00019541 0.000505707 0.000194062 6.12825e-05 47
produce:reco3d:SpacePointSolver 2.16819 6.00572 10.8536 6.18238 2.13747 47
produce:hitpdune:DisambigFromSpacePoints 0.0276013 0.0902466 0.289683 0.0845788 0.0454287 47
produce:pandora:StandardPandora 5.33807 21.7578 64.7862 20.0994 12.4642 47
produce:pandoraTrack:LArPandoraTrackCreation 0.11145 0.362021 0.910073 0.326843 0.172402 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.011273 0.0212305 0.0362792 0.0223214 0.00625729 47
[art]:TriggerResults:TriggerResultInserter 2.5321e-05 4.07301e-05 8.2041e-05 3.623e-05 1.49708e-05 47
end_path:out1:RootOutput 4.11e-06 8.81157e-06 2.775e-05 9.5e-06 3.76127e-06 47
end_path:out1:RootOutput(write) 2.34426 3.20436 4.21305 3.07212 0.421686 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4861.6 MB
Peak resident set size usage (VmHWM): 2817.28 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0394_df-s05-d1_dw_0_20250918T073127_reco_stage1_20250918T092933_keepup.root
\tHists: np02vd_raw_run039433_0394_df-s05-d1_dw_0_20250918T073127_reco_stage1_20250918T092933_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0394_df-s05-d1_dw_0_20250918T073127_reco_stage1_20250918T092933_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0394_df-s05-d1_dw_0_20250918T073127_reco_stage1_20250918T092933_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": 1758187774.0,
"core.end_time": 1758187774.0,
"core.events": [
112951,
112957,
112963,
112969,
112975,
112981,
112987,
112993,
112999,
113005,
113011,
113017,
113023,
113029,
113035,
113041,
113047,
113053,
113059,
113065,
113071,
113077,
113083,
113089,
113095,
113101,
113107,
113113,
113119,
113125,
113131,
113137,
113143,
113149,
113155,
113161,
113167,
113173,
113179,
113185,
113191,
113197,
113203,
113209,
113215,
113221,
113227
],
"core.event_count": 47,
"core.first_event_number": 112951,
"core.last_event_number": 113227,
"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-d1_dw_0_20250918T073127.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0394_df-s05-d1_dw_0_20250918T073127_reco_stage1_20250918T092933_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": 1758187774.0,
"core.end_time": 1758187774.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-d1_dw_0_20250918T073127.hdf5"
}
]
} 