Jobsub ID 41052.29@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
15:49:55.793] D [ aux ] <Resampler:resmp0> EOS at call=37
[15:49:55.793] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[15:49:55.793] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[15:49:55.793] D [ glue ] frame sink sees EOS
[15:49:55.793] D [ pgraph ] <Pgrapher:> graph execution complete
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.68 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.4 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.87 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.56 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.34 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.33 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.29 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.25 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Aux::Resampler : 0.81 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Aux::Resampler : 0.8 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Aux::Resampler : 0.77 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Aux::Resampler : 0.75 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:49:55.793] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:49:55.793] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:49:55.793] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[15:49:55.793] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[15:49:55.793] I [ timer ] Timer: Total node execution : 56.88999978452921 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 43069 traces tagged "gauss"
FrameSaver: q=6.41501e+06 n=850244 tag=gauss
wclsFrameSaver: saving 51773 traces tagged "wiener"
FrameSaver: q=6.73616e+06 n=818039 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 434 XUs and 727 XVs -> 11 XUVs
C:0 T:1 941 XUs and 1104 XVs -> 85 XUVs
C:0 T:2 827 XUs and 526 XVs -> 28 XUVs
C:0 T:3 450 XUs and 613 XVs -> 29 XUVs
C:0 T:4 376 XUs and 367 XVs -> 11 XUVs
C:0 T:5 1701 XUs and 1430 XVs -> 63 XUVs
C:0 T:6 938 XUs and 1142 XVs -> 60 XUVs
C:0 T:7 944 XUs and 1319 XVs -> 65 XUVs
C:0 T:8 1971 XUs and 2716 XVs -> 114 XUVs
C:0 T:9 2185 XUs and 1834 XVs -> 127 XUVs
C:0 T:10 2344 XUs and 2017 XVs -> 234 XUVs
C:0 T:11 462 XUs and 537 XVs -> 31 XUVs
C:0 T:12 968 XUs and 891 XVs -> 46 XUVs
C:0 T:13 2049 XUs and 1988 XVs -> 110 XUVs
C:0 T:14 1143 XUs and 1373 XVs -> 98 XUVs
C:0 T:15 367 XUs and 474 XVs -> 32 XUVs
1144 XUVs total
907 collection wire objects
1144 potential space points
Neighbour search...
14322 tests to find 7630 neighbours
Iterating with no regularization...
Begin: 2.81894e+08
0 2.71145e+08
1 2.70278e+08
2 2.70254e+08
Now with regularization...
Begin: 2.66421e+08
0 2.66413e+08
17-Sep-2025 15:50:45 UTC Closed output file "np02vd_raw_run039388_0367_df-s05-d0_dw_0_20250916T205449_reco_stage1_20250917T155045_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 128.394 160.533 200.824 159.984 22.3528 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.0397e-05 6.59965e-05 0.000117194 5.725e-05 1.55138e-05 19
produce:tpcrawdecoder:PDVDTPCReader 17.4653 23.0389 34.994 22.3562 3.98757 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.311657 0.331722 0.364097 0.332414 0.0133881 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000226764 0.000292218 0.000516148 0.000271871 6.99784e-05 19
produce:ophit:OpHitFinder 8.9612e-05 0.000132172 0.000545204 0.000100883 0.000100058 19
produce:opflash:OpFlashFinderVerticalDrift 3.3073e-05 4.87659e-05 0.000230852 3.4466e-05 4.36362e-05 19
produce:wclsdatavd:WireCellToolkit 56.0507 65.0116 91.1411 63.2694 7.83734 19
produce:gaushit:GausHitFinder 0.769957 1.14407 1.43859 1.18053 0.180226 19
produce:nhitsfilter:NumberOfHitsFilter 0.000257483 0.000348688 0.000519615 0.000351914 7.26502e-05 19
produce:reco3d:SpacePointSolver 7.21838 14.6728 21.3116 14.8612 3.5043 19
produce:hitpdune:DisambigFromSpacePoints 0.0803977 0.195352 0.309477 0.197912 0.0531507 19
produce:pandora:StandardPandora 29.4591 50.044 82.0994 50.6068 15.612 19
produce:pandoraTrack:LArPandoraTrackCreation 0.475408 0.943608 1.40795 0.9624 0.246291 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0187108 0.0316529 0.0465924 0.0293238 0.00699469 19
[art]:TriggerResults:TriggerResultInserter 1.3716e-05 1.96154e-05 5.243e-05 1.6963e-05 8.25104e-06 19
end_path:out1:RootOutput 3.136e-06 4.65995e-06 2.1731e-05 3.697e-06 4.03378e-06 19
end_path:out1:RootOutput(write) 4.24019 5.07913 10.4733 4.67539 1.42602 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4681.67 MB
Peak resident set size usage (VmHWM): 2714.03 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0367_df-s05-d0_dw_0_20250916T205449_reco_stage1_20250917T155045_keepup.root
\tHists: np02vd_raw_run039388_0367_df-s05-d0_dw_0_20250916T205449_reco_stage1_20250917T155046_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0367_df-s05-d0_dw_0_20250916T205449_reco_stage1_20250917T155045_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0367_df-s05-d0_dw_0_20250916T205449_reco_stage1_20250917T155045_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": 1758124246.0,
"core.end_time": 1758124246.0,
"core.events": [
28220,
28224,
28228,
28232,
28236,
28240,
28244,
28248,
28252,
28256,
28260,
28264,
28268,
28272,
28276,
28280,
28284,
28288,
28292
],
"core.event_count": 19,
"core.first_event_number": 28220,
"core.last_event_number": 28292,
"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_0367_df-s05-d0_dw_0_20250916T205449.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0367_df-s05-d0_dw_0_20250916T205449_reco_stage1_20250917T155046_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": 1758124246.0,
"core.end_time": 1758124246.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_0367_df-s05-d0_dw_0_20250916T205449.hdf5"
}
]
}