Jobsub ID 46968.83@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
15:02:08.463] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[15:02:08.463] D [ glue ] frame sink sees EOS
[15:02:08.463] D [ pgraph ] <Pgrapher:> graph execution complete
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.56 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.69 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.41 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.99 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.6 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.23 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.36 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.86 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Aux::Resampler : 0.9 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Aux::Resampler : 0.89 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Aux::Resampler : 0.87 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Aux::Resampler : 0.56 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:02:08.463] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[15:02:08.463] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:02:08.463] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[15:02:08.463] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[15:02:08.463] I [ timer ] Timer: Total node execution : 82.00999882258475 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 62308 traces tagged "gauss"
FrameSaver: q=1.16246e+07 n=1416559 tag=gauss
wclsFrameSaver: saving 78280 traces tagged "wiener"
FrameSaver: q=1.25795e+07 n=1353499 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1292 XUs and 932 XVs -> 174 XUVs
C:0 T:1 2204 XUs and 2102 XVs -> 223 XUVs
C:0 T:2 1109 XUs and 514 XVs -> 168 XUVs
C:0 T:3 356 XUs and 309 XVs -> 13 XUVs
C:0 T:4 870 XUs and 1409 XVs -> 32 XUVs
C:0 T:5 1312 XUs and 1621 XVs -> 76 XUVs
C:0 T:6 730 XUs and 773 XVs -> 39 XUVs
C:0 T:7 1800 XUs and 2467 XVs -> 108 XUVs
C:0 T:8 22308 XUs and 56213 XVs -> 6593 XUVs
C:0 T:9 13579 XUs and 20997 XVs -> 2948 XUVs
C:0 T:10 10140 XUs and 20006 XVs -> 3796 XUVs
C:0 T:11 2676 XUs and 3496 XVs -> 818 XUVs
C:0 T:12 8187 XUs and 8540 XVs -> 812 XUVs
C:0 T:13 12093 XUs and 19438 XVs -> 1767 XUVs
C:0 T:14 10512 XUs and 24244 XVs -> 2104 XUVs
C:0 T:15 3354 XUs and 2763 XVs -> 170 XUVs
19841 XUVs total
3050 collection wire objects
19841 potential space points
Neighbour search...
2293835 tests to find 993672 neighbours
Iterating with no regularization...
Begin: 8.72186e+08
0 7.5036e+08
1 7.41406e+08
2 7.39872e+08
3 7.39348e+08
Now with regularization...
Begin: 7.23433e+08
0 7.2298e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
16-Sep-2025 15:04:57 CEST Closed output file "np02vd_raw_run039275_0346_df-s02-d1_dw_0_20250902T023738_reco_stage1_20250916T130457_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 153.967 215.689 340.209 199.336 54.1597 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.924e-05 0.000143422 0.000355941 0.00012176 7.59899e-05 18
produce:tpcrawdecoder:PDVDTPCReader 7.10025 7.97641 14.2475 7.61082 1.5484 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.00608782 0.00814139 0.0177494 0.00691098 0.00338076 18
produce:pdvddaphne:DAPHNEReaderPDVD 3.49643 4.24527 4.99961 4.16522 0.406167 18
produce:ophit:OpHitFinder 0.0481002 0.0656399 0.0808042 0.0672995 0.00824258 18
produce:opflash:OpFlashFinderVerticalDrift 0.00842051 0.0169891 0.0271279 0.016056 0.00567394 18
produce:wclsdatavd:WireCellToolkit 62.0186 77.2739 88.6063 76.1667 7.58135 18
produce:gaushit:GausHitFinder 1.20987 1.70784 2.35174 1.69736 0.319958 18
produce:nhitsfilter:NumberOfHitsFilter 0.000230009 0.000857785 0.00203309 0.000766619 0.000462332 18
produce:reco3d:SpacePointSolver 12.6723 20.2781 32.6096 20.006 4.85821 18
produce:hitpdune:DisambigFromSpacePoints 0.180323 0.338429 0.63162 0.306279 0.131029 18
produce:pandora:StandardPandora 51.8443 94.4401 198.646 74.4577 42.9128 18
produce:pandoraTrack:LArPandoraTrackCreation 1.0267 3.13736 5.82229 3.01501 1.34267 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0233192 0.0471643 0.0873487 0.0509559 0.0173996 18
[art]:TriggerResults:TriggerResultInserter 2.9735e-05 8.2432e-05 0.000196258 6.86895e-05 4.78486e-05 18
end_path:out1:RootOutput 4.627e-06 1.89093e-05 5.5294e-05 1.4502e-05 1.32263e-05 18
end_path:out1:RootOutput(write) 5.09876 6.04499 7.06319 6.20392 0.556158 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5131.32 MB
Peak resident set size usage (VmHWM): 3202.55 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039275_0346_df-s02-d1_dw_0_20250902T023738_reco_stage1_20250916T130457_keepup.root
\tHists: np02vd_raw_run039275_0346_df-s02-d1_dw_0_20250902T023738_reco_stage1_20250916T130457_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039275_0346_df-s02-d1_dw_0_20250902T023738_reco_stage1_20250916T130457_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039275_0346_df-s02-d1_dw_0_20250902T023738_reco_stage1_20250916T130457_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": 1758027898.0,
"core.end_time": 1758027898.0,
"core.events": [
124563,
124583,
124603,
124623,
124643,
124663,
124683,
124703,
124723,
124743,
124763,
124783,
124803,
124823,
124843,
124863,
124883,
124903
],
"core.event_count": 18,
"core.first_event_number": 124563,
"core.last_event_number": 124903,
"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_0346_df-s02-d1_dw_0_20250902T023738.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039275_0346_df-s02-d1_dw_0_20250902T023738_reco_stage1_20250916T130457_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": 1758027898.0,
"core.end_time": 1758027898.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_0346_df-s02-d1_dw_0_20250902T023738.hdf5"
}
]
} 