Jobsub ID 41697.119@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
> EOS at call=91 anode=0
[12:07:14.441] D [ glue ] <FrameFanin:nfsp> EOS at call=91 with 8
[12:07:14.441] D [ glue ] frame sink sees EOS
[12:07:14.441] D [ pgraph ] <Pgrapher:> graph execution complete
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.6 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.07 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.39 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.33 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Aux::Resampler : 1.77 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Aux::Resampler : 1.71 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Aux::Resampler : 1.69 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Aux::Resampler : 1.24 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:07:14.442] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[12:07:14.442] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[12:07:14.442] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[12:07:14.442] I [ timer ] Timer: Total node execution : 58.84000042825937 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 20453 traces tagged "gauss"
FrameSaver: q=2.44518e+06 n=416407 tag=gauss
wclsFrameSaver: saving 24844 traces tagged "wiener"
FrameSaver: q=2.56129e+06 n=402387 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 296 XUs and 544 XVs -> 27 XUVs
C:0 T:1 477 XUs and 449 XVs -> 21 XUVs
C:0 T:2 542 XUs and 406 XVs -> 20 XUVs
C:0 T:3 1058 XUs and 1021 XVs -> 46 XUVs
C:0 T:4 988 XUs and 1071 XVs -> 78 XUVs
C:0 T:5 1744 XUs and 2173 XVs -> 101 XUVs
C:0 T:6 1133 XUs and 1040 XVs -> 49 XUVs
C:0 T:7 994 XUs and 1305 XVs -> 63 XUVs
405 XUVs total
323 collection wire objects
405 potential space points
Neighbour search...
3497 tests to find 2126 neighbours
Iterating with no regularization...
Begin: 7.53092e+07
0 7.39447e+07
1 7.39269e+07
Now with regularization...
Begin: 7.21573e+07
0 7.21566e+07
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 12:07:53 BST Closed output file "np02vd_raw_run039433_0369_df-s05-d4_dw_0_20250918T062930_reco_stage1_20250918T110753_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 83.2017 299.162 6973.84 146.188 996.133 46
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 9.6692e-05 0.000136305 0.00096822 0.000107357 0.00012855 46
produce:tpcrawdecoder:PDVDTPCReader 17.1193 55.862 144.637 50.5233 21.3501 46
produce:triggerrawdecoder:PDVDTriggerReader4 0.395156 0.484396 1.2971 0.443352 0.143056 46
produce:pdvddaphne:DAPHNEReaderPDVD 8.37776 12.4923 22.2178 12.2579 3.07234 46
produce:ophit:OpHitFinder 0.0487616 0.069317 0.0896944 0.0686763 0.00852552 46
produce:opflash:OpFlashFinderVerticalDrift 0.00471566 0.0180442 0.0265712 0.0172804 0.00496064 46
produce:wclsdatavd:WireCellToolkit 23.8585 47.4015 81.8551 41.9898 12.7887 46
produce:gaushit:GausHitFinder 0.389669 0.910455 3.05748 0.862015 0.42774 46
produce:nhitsfilter:NumberOfHitsFilter 9.6462e-05 0.000301969 0.00121935 0.000242461 0.000187914 46
produce:reco3d:SpacePointSolver 1.90344 7.5667 43.3283 6.3815 6.49309 46
produce:hitpdune:DisambigFromSpacePoints 0.0207785 0.117155 1.1521 0.0732855 0.171167 46
produce:pandora:StandardPandora 5.10785 169.892 6748.2 16.9353 980.997 46
produce:pandoraTrack:LArPandoraTrackCreation 0.0965308 0.65144 10.7332 0.312361 1.54611 46
produce:pandoraGnocalo:GnocchiCalorimetry 0.0119277 0.0255271 0.0734283 0.0251862 0.0110975 46
[art]:TriggerResults:TriggerResultInserter 1.7162e-05 3.49807e-05 8.2675e-05 3.1103e-05 1.19224e-05 46
end_path:out1:RootOutput 4.328e-06 6.45974e-06 2.0829e-05 6.0215e-06 2.52816e-06 46
end_path:out1:RootOutput(write) 2.4397 3.64277 4.70142 3.51324 0.575028 46
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4470.74 MB
Peak resident set size usage (VmHWM): 2523 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0369_df-s05-d4_dw_0_20250918T062930_reco_stage1_20250918T110753_keepup.root
\tHists: np02vd_raw_run039433_0369_df-s05-d4_dw_0_20250918T062930_reco_stage1_20250918T110754_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0369_df-s05-d4_dw_0_20250918T062930_reco_stage1_20250918T110753_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0369_df-s05-d4_dw_0_20250918T062930_reco_stage1_20250918T110753_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": 1758193675.0,
"core.end_time": 1758193675.0,
"core.events": [
105754,
105760,
105766,
105772,
105778,
105784,
105790,
105796,
105802,
105808,
105814,
105820,
105826,
105832,
105838,
105844,
105850,
105856,
105862,
105868,
105874,
105880,
105886,
105892,
105898,
105904,
105910,
105916,
105922,
105928,
105934,
105940,
105946,
105952,
105958,
105964,
105970,
105976,
105982,
105988,
105994,
106000,
106006,
106012,
106018,
106024
],
"core.event_count": 46,
"core.first_event_number": 105754,
"core.last_event_number": 106024,
"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_0369_df-s05-d4_dw_0_20250918T062930.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0369_df-s05-d4_dw_0_20250918T062930_reco_stage1_20250918T110754_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": 1758193675.0,
"core.end_time": 1758193675.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_0369_df-s05-d4_dw_0_20250918T062930.hdf5"
}
]
}