Jobsub ID 47410.159@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
EOS at call=41 anode=0
[11:12:20.564] D [ glue ] <FrameFanin:nfsp> EOS at call=41 with 8
[11:12:20.564] D [ glue ] frame sink sees EOS
[11:12:20.564] D [ pgraph ] <Pgrapher:> graph execution complete
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.52 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.91 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.71 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.59 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.05 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.87 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.62 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.32 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Aux::Resampler : 1.18 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Aux::Resampler : 0.85 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Aux::Resampler : 0.78 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Aux::Resampler : 0.64 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[11:12:20.564] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:12:20.564] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:12:20.564] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:12:20.564] I [ timer ] Timer: Total node execution : 63.080000557005405 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 56567 traces tagged "gauss"
FrameSaver: q=9.37528e+06 n=1172753 tag=gauss
wclsFrameSaver: saving 69058 traces tagged "wiener"
FrameSaver: q=9.88948e+06 n=1131726 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 250 XUs and 353 XVs -> 14 XUVs
C:0 T:1 455 XUs and 582 XVs -> 18 XUVs
C:0 T:2 558 XUs and 836 XVs -> 21 XUVs
C:0 T:3 627 XUs and 890 XVs -> 51 XUVs
C:0 T:4 280 XUs and 347 XVs -> 10 XUVs
C:0 T:5 916 XUs and 809 XVs -> 36 XUVs
C:0 T:6 2058 XUs and 2216 XVs -> 99 XUVs
C:0 T:7 642 XUs and 724 XVs -> 27 XUVs
C:0 T:8 860 XUs and 1213 XVs -> 189 XUVs
C:0 T:9 3125 XUs and 4702 XVs -> 569 XUVs
C:0 T:10 3665 XUs and 3908 XVs -> 570 XUVs
C:0 T:11 2587 XUs and 3298 XVs -> 469 XUVs
C:0 T:12 12629 XUs and 17979 XVs -> 2594 XUVs
C:0 T:13 5929 XUs and 4482 XVs -> 281 XUVs
C:0 T:14 2666 XUs and 4135 XVs -> 331 XUVs
C:0 T:15 8462 XUs and 10567 XVs -> 1619 XUVs
6898 XUVs total
1740 collection wire objects
6898 potential space points
Neighbour search...
648756 tests to find 296030 neighbours
Iterating with no regularization...
Begin: 4.77484e+08
0 4.53737e+08
1 4.5171e+08
2 4.51269e+08
Now with regularization...
Begin: 4.41762e+08
0 4.41546e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 11:13:46 BST Closed output file "np02vd_raw_run039388_0664_df-s05-d1_dw_0_20250917T031132_reco_stage1_20250917T101346_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 31.4193 139.427 190.584 145.995 39.0675 21
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.0602e-05 0.000118909 0.000291687 0.000103504 4.5994e-05 21
produce:tpcrawdecoder:PDVDTPCReader 8.67947 14.1728 25.0626 14.0758 2.95025 21
produce:triggerrawdecoder:PDVDTriggerReader4 0.298416 0.303475 0.321233 0.302072 0.00474089 21
produce:pdvddaphne:DAPHNEReaderPDVD 0.000237014 0.000423734 0.00100726 0.00042698 0.000149254 21
produce:ophit:OpHitFinder 0.00019723 0.000310061 0.00117023 0.000252954 0.000209391 21
produce:opflash:OpFlashFinderVerticalDrift 4.6938e-05 9.17643e-05 0.000457997 7.3849e-05 8.32816e-05 21
produce:wclsdatavd:WireCellToolkit 13.592 62.3204 80.317 65.8416 16.6456 21
produce:gaushit:GausHitFinder 0.4687 1.25947 1.90532 1.24302 0.365633 21
produce:nhitsfilter:NumberOfHitsFilter 0.000145974 0.000360262 0.000579745 0.000362178 9.98294e-05 21
produce:reco3d:SpacePointSolver 2.24833 13.3355 20.2988 14.1806 4.24183 21
produce:hitpdune:DisambigFromSpacePoints 0.0444779 0.191399 0.321863 0.177701 0.0682754 21
produce:pandora:StandardPandora 4.2697 42.2624 74.4946 39.0979 18.841 21
produce:pandoraTrack:LArPandoraTrackCreation 0.203808 0.938151 1.57609 0.944907 0.313645 21
produce:pandoraGnocalo:GnocchiCalorimetry 0.0109854 0.0299218 0.0533035 0.0275615 0.00983884 21
[art]:TriggerResults:TriggerResultInserter 1.9557e-05 3.67443e-05 0.000116138 3.0768e-05 2.20767e-05 21
end_path:out1:RootOutput 5.35e-06 1.06371e-05 3.75e-05 8.867e-06 6.40633e-06 21
end_path:out1:RootOutput(write) 1.18681 4.57105 6.31053 4.77335 1.24067 21
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4683.35 MB
Peak resident set size usage (VmHWM): 2700.46 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0664_df-s05-d1_dw_0_20250917T031132_reco_stage1_20250917T101346_keepup.root
\tHists: np02vd_raw_run039388_0664_df-s05-d1_dw_0_20250917T031132_reco_stage1_20250917T101346_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0664_df-s05-d1_dw_0_20250917T031132_reco_stage1_20250917T101346_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0664_df-s05-d1_dw_0_20250917T031132_reco_stage1_20250917T101346_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": 1758104026.0,
"core.end_time": 1758104026.0,
"core.events": [
51213,
51217,
51221,
51225,
51229,
51233,
51237,
51241,
51245,
51249,
51253,
51257,
51261,
51265,
51269,
51273,
51277,
51281,
51285,
51289,
51293
],
"core.event_count": 21,
"core.first_event_number": 51213,
"core.last_event_number": 51293,
"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_0664_df-s05-d1_dw_0_20250917T031132.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0664_df-s05-d1_dw_0_20250917T031132_reco_stage1_20250917T101346_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": 1758104026.0,
"core.end_time": 1758104026.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_0664_df-s05-d1_dw_0_20250917T031132.hdf5"
}
]
} 