Jobsub ID 47012.53@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
8:56:09.366] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[18:56:09.366] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[18:56:09.366] D [ glue ] frame sink sees EOS
[18:56:09.366] D [ pgraph ] <Pgrapher:> graph execution complete
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.83 sec
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.51 sec
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.39 sec
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.29 sec
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.27 sec
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.97 sec
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.82 sec
[18:56:09.366] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.66 sec
[18:56:09.366] I [ timer ] Timer: WireCell::Aux::Resampler : 1 sec
[18:56:09.367] I [ timer ] Timer: WireCell::Aux::Resampler : 0.96 sec
[18:56:09.367] I [ timer ] Timer: WireCell::Aux::Resampler : 0.92 sec
[18:56:09.367] I [ timer ] Timer: WireCell::Aux::Resampler : 0.9 sec
[18:56:09.367] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:56:09.367] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:56:09.367] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:56:09.367] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:56:09.367] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[18:56:09.367] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[18:56:09.367] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[18:56:09.367] I [ timer ] Timer: Total node execution : 73.58000069484115 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 48312 traces tagged "gauss"
FrameSaver: q=8.05844e+06 n=1009418 tag=gauss
wclsFrameSaver: saving 58160 traces tagged "wiener"
FrameSaver: q=8.53679e+06 n=971910 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 270 XUs and 439 XVs -> 12 XUVs
C:0 T:1 164 XUs and 171 XVs -> 10 XUVs
C:0 T:2 1648 XUs and 1853 XVs -> 55 XUVs
C:0 T:3 856 XUs and 893 XVs -> 27 XUVs
C:0 T:4 141 XUs and 190 XVs -> 2 XUVs
C:0 T:5 755 XUs and 385 XVs -> 34 XUVs
C:0 T:6 645 XUs and 421 XVs -> 29 XUVs
C:0 T:7 398 XUs and 236 XVs -> 10 XUVs
C:0 T:8 1058 XUs and 1024 XVs -> 36 XUVs
C:0 T:9 2743 XUs and 2694 XVs -> 106 XUVs
C:0 T:10 1372 XUs and 1672 XVs -> 76 XUVs
C:0 T:11 9791 XUs and 22660 XVs -> 2534 XUVs
C:0 T:12 4543 XUs and 7662 XVs -> 863 XUVs
C:0 T:13 4698 XUs and 7286 XVs -> 818 XUVs
C:0 T:14 4927 XUs and 5708 XVs -> 985 XUVs
C:0 T:15 2941 XUs and 2245 XVs -> 95 XUVs
5692 XUVs total
1314 collection wire objects
5692 potential space points
Neighbour search...
577578 tests to find 251238 neighbours
Iterating with no regularization...
Begin: 3.63784e+08
0 3.35643e+08
1 3.343e+08
2 3.3402e+08
Now with regularization...
Begin: 3.26628e+08
0 3.26472e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
16-Sep-2025 18:57:38 CEST Closed output file "np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729_reco_stage1_20250916T165738_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 126.872 186.504 277.615 174.253 37.4518 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.9356e-05 0.000129177 0.000285825 0.00011171 4.96289e-05 19
produce:tpcrawdecoder:PDVDTPCReader 8.07317 9.33627 11.4173 9.24367 0.849438 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.0507091 0.0639523 0.0893685 0.0600387 0.0114583 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000273415 0.000451114 0.00178461 0.000366996 0.000322891 19
produce:ophit:OpHitFinder 0.000144069 0.000368654 0.00217347 0.000239264 0.000439327 19
produce:opflash:OpFlashFinderVerticalDrift 4.7202e-05 0.000116022 0.000788448 7.217e-05 0.000161038 19
produce:wclsdatavd:WireCellToolkit 66.7544 80.8083 94.3625 79.8658 7.772 19
produce:gaushit:GausHitFinder 1.04718 1.68766 2.39097 1.73335 0.351565 19
produce:nhitsfilter:NumberOfHitsFilter 0.000289039 0.000658742 0.00175923 0.000516214 0.000361281 19
produce:reco3d:SpacePointSolver 10.7893 16.5479 25.8137 15.6033 4.40993 19
produce:hitpdune:DisambigFromSpacePoints 0.145853 0.283331 0.560153 0.263701 0.116545 19
produce:pandora:StandardPandora 30.8354 69.3233 135.895 64.0547 28.0297 19
produce:pandoraTrack:LArPandoraTrackCreation 0.902723 2.13414 3.69805 1.93106 0.818424 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0331423 0.0457888 0.0679097 0.0454879 0.010116 19
[art]:TriggerResults:TriggerResultInserter 3.4272e-05 8.29491e-05 0.00024365 6.6731e-05 5.45448e-05 19
end_path:out1:RootOutput 6.149e-06 2.28848e-05 0.000119431 1.8248e-05 2.37189e-05 19
end_path:out1:RootOutput(write) 5.59278 6.16739 6.75467 6.09684 0.336999 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5129.49 MB
Peak resident set size usage (VmHWM): 3197.21 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729_reco_stage1_20250916T165738_keepup.root
\tHists: np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729_reco_stage1_20250916T165739_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729_reco_stage1_20250916T165738_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729_reco_stage1_20250916T165738_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": 1758041859.0,
"core.end_time": 1758041859.0,
"core.events": [
8896,
8900,
8904,
8908,
8912,
8916,
8920,
8924,
8928,
8932,
8936,
8940,
8944,
8948,
8952,
8956,
8960,
8964,
8968
],
"core.event_count": 19,
"core.first_event_number": 8896,
"core.last_event_number": 8968,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729_reco_stage1_20250916T165739_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": 1758041859.0,
"core.end_time": 1758041859.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0116_df-s05-d0_dw_0_20250916T153729.hdf5"
}
]
} 