Jobsub ID 243386.90@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
[09:46:11.411] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=47 anode=0
[09:46:11.411] D [ glue ] <FrameFanin:nfsp> EOS at call=47 with 8
[09:46:11.411] D [ glue ] frame sink sees EOS
[09:46:11.411] D [ pgraph ] <Pgrapher:> graph execution complete
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.92 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.46 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.33 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.21 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.14 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.87 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.78 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.66 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Aux::Resampler : 0.25 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:11.411] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:11.411] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:11.411] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:46:11.411] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:46:11.411] I [ timer ] Timer: Total node execution : 50.43999985978007 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 31793 traces tagged "gauss"
FrameSaver: q=7.957e+06 n=689272 tag=gauss
wclsFrameSaver: saving 39642 traces tagged "wiener"
FrameSaver: q=8.62561e+06 n=659081 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 125 XUs and 182 XVs -> 10 XUVs
C:0 T:1 1951 XUs and 1358 XVs -> 40 XUVs
C:0 T:2 454 XUs and 364 XVs -> 23 XUVs
C:0 T:3 10325 XUs and 10984 XVs -> 826 XUVs
C:0 T:4 3203 XUs and 2979 XVs -> 189 XUVs
C:0 T:5 305 XUs and 377 XVs -> 14 XUVs
C:0 T:6 811 XUs and 1051 XVs -> 32 XUVs
C:0 T:7 42 XUs and 38 XVs -> 0 XUVs
C:0 T:8 338 XUs and 661 XVs -> 23 XUVs
C:0 T:9 498 XUs and 518 XVs -> 27 XUVs
C:0 T:10 196 XUs and 319 XVs -> 23 XUVs
C:0 T:11 588 XUs and 635 XVs -> 36 XUVs
C:0 T:12 424 XUs and 693 XVs -> 51 XUVs
C:0 T:13 814 XUs and 1252 XVs -> 64 XUVs
C:0 T:14 509 XUs and 535 XVs -> 43 XUVs
C:0 T:15 693 XUs and 1327 XVs -> 65 XUVs
1466 XUVs total
975 collection wire objects
1466 potential space points
Neighbour search...
37358 tests to find 11168 neighbours
Iterating with no regularization...
Begin: 4.92184e+09
0 4.69033e+09
1 4.67373e+09
2 4.67335e+09
Now with regularization...
Begin: 4.63067e+09
0 4.63054e+09
05-Nov-2025 09:46:38 UTC Closed output file "np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442_reco_stage1_20251105T094638_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 92.5689 138.618 298.341 125.778 48.9026 24
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.7792e-05 0.000138409 0.000333032 0.000107101 7.66176e-05 24
produce:tpcrawdecoder:PDVDTPCReader 14.0981 15.5267 20.6761 15.0838 1.37854 24
produce:triggerrawdecoder:PDVDTriggerReader4 0.674513 0.697553 0.717154 0.697082 0.0100441 24
produce:pdvddaphne:DAPHNEReaderPDVD 0.000336518 0.000502503 0.00156499 0.000442358 0.000255751 24
produce:ophit:OpHitFinder 7.903e-05 0.000217183 0.00104463 0.000163136 0.000211918 24
produce:opflash:OpFlashFinderVerticalDrift 5.0056e-05 9.74053e-05 0.000428006 8.0872e-05 7.10482e-05 24
produce:wclsdatavd:WireCellToolkit 51.0983 67.9766 110.583 58.7491 17.2862 24
produce:gaushit:GausHitFinder 0.707899 1.31947 1.84872 1.27557 0.276985 24
produce:nhitsfilter:NumberOfHitsFilter 0.00013957 0.000280406 0.000570541 0.00027551 7.65247e-05 24
produce:reco3d:SpacePointSolver 6.62078 11.7593 18.9461 11.3147 3.54255 24
produce:hitpdune:DisambigFromSpacePoints 0.0974053 0.214126 0.456824 0.20662 0.0872869 24
produce:pandora:StandardPandora 12.23 35.3152 170.118 24.5684 34.1197 24
produce:pandoraTrack:LArPandoraTrackCreation 0.442857 1.02018 1.87108 0.943591 0.458215 24
produce:pandoraGnocalo:GnocchiCalorimetry 0.0218124 0.0349546 0.0509511 0.0327288 0.00882 24
[art]:TriggerResults:TriggerResultInserter 2.634e-05 4.51125e-05 9.9099e-05 4.5889e-05 1.45139e-05 24
end_path:out1:RootOutput 5.278e-06 1.39243e-05 3.4212e-05 1.25995e-05 5.80918e-06 24
end_path:out1:RootOutput(write) 3.88277 4.67961 5.40016 4.64622 0.397834 24
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6565.09 MB
Peak resident set size usage (VmHWM): 4420.64 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442_reco_stage1_20251105T094638_keepup.root
\tHists: np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442_reco_stage1_20251105T094638_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442_reco_stage1_20251105T094638_keepup.root
Ran successfully
{
"name": "np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442_reco_stage1_20251105T094638_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_11_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": 1762335999.0,
"core.end_time": 1762335999.0,
"core.events": [
36963,
36967,
36971,
36975,
36979,
36983,
36987,
36991,
36995,
36999,
37003,
37007,
37011,
37015,
37019,
37023,
37027,
37031,
37035,
37039,
37043,
37047,
37051,
37055
],
"core.event_count": 24,
"core.first_event_number": 36963,
"core.last_event_number": 37055,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40361
],
"core.runs_subruns": [
4036100001
],
"dune.daq_test": true,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442_reco_stage1_20251105T094638_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_11_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": 1762335999.0,
"core.end_time": 1762335999.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40361
],
"core.runs_subruns": [
4036100001
],
"dune.daq_test": true,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040361_0399_df-s04-d3_dw_0_20251105T022442.hdf5"
}
]
} 