Jobsub ID 42875.36@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
e ] <ChannelSelector:chsel0> see EOS at call=40
[19:39:52.168] D [ aux ] <Resampler:resmp0> EOS at call=81
[19:39:52.168] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[19:39:52.168] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[19:39:52.168] D [ glue ] frame sink sees EOS
[19:39:52.168] D [ pgraph ] <Pgrapher:> graph execution complete
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.25 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.12 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.92 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.83 sec
[19:39:52.168] I [ timer ] Timer: WireCell::Aux::Resampler : 0.45 sec
[19:39:52.168] I [ timer ] Timer: WireCell::Aux::Resampler : 0.44 sec
[19:39:52.168] I [ timer ] Timer: WireCell::Aux::Resampler : 0.44 sec
[19:39:52.168] I [ timer ] Timer: WireCell::Aux::Resampler : 0.44 sec
[19:39:52.168] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[19:39:52.168] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[19:39:52.168] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.169] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[19:39:52.169] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.169] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:39:52.169] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[19:39:52.169] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[19:39:52.169] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[19:39:52.169] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[19:39:52.169] I [ timer ] Timer: Total node execution : 59.90999986603856 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22926 traces tagged "gauss"
FrameSaver: q=4.33294e+06 n=552513 tag=gauss
wclsFrameSaver: saving 28677 traces tagged "wiener"
FrameSaver: q=4.68861e+06 n=536858 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 310 XUs and 442 XVs -> 17 XUVs
C:0 T:1 510 XUs and 577 XVs -> 28 XUVs
C:0 T:2 2743 XUs and 3380 XVs -> 107 XUVs
C:0 T:3 210 XUs and 343 XVs -> 6 XUVs
C:0 T:4 158 XUs and 196 XVs -> 5 XUVs
C:0 T:5 1345 XUs and 1287 XVs -> 57 XUVs
C:0 T:6 709 XUs and 617 XVs -> 35 XUVs
C:0 T:7 24981 XUs and 23164 XVs -> 2046 XUVs
2301 XUVs total
1034 collection wire objects
2301 potential space points
Neighbour search...
115039 tests to find 26718 neighbours
Iterating with no regularization...
Begin: 2.96103e+09
0 2.76719e+09
1 2.75462e+09
2 2.75431e+09
Now with regularization...
Begin: 2.71123e+09
0 2.7111e+09
19-Sep-2025 19:40:27 CEST Closed output file "np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230_reco_stage1_20250919T174027_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 76.3961 254.037 4393.56 120.178 672.135 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.1848e-05 8.53807e-05 0.000370535 7.4151e-05 4.74646e-05 41
produce:tpcrawdecoder:PDVDTPCReader 6.28496 30.2273 61.2827 30.7144 10.118 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.302202 0.361481 0.735743 0.325867 0.0841938 41
produce:pdvddaphne:DAPHNEReaderPDVD 4.88175 7.8464 11.1336 7.93946 1.69785 41
produce:ophit:OpHitFinder 0.0323401 0.0399803 0.0482274 0.0398003 0.00380788 41
produce:opflash:OpFlashFinderVerticalDrift 0.00518233 0.010458 0.0162993 0.0108208 0.00235845 41
produce:wclsdatavd:WireCellToolkit 28.7625 50.3364 99.6961 46.1801 14.1278 41
produce:gaushit:GausHitFinder 0.365467 0.702928 1.80605 0.626069 0.275609 41
produce:nhitsfilter:NumberOfHitsFilter 9.3016e-05 0.000211189 0.000627976 0.000163542 0.000138365 41
produce:reco3d:SpacePointSolver 2.25554 7.65315 43.3416 5.94305 6.78222 41
produce:hitpdune:DisambigFromSpacePoints 0.0216127 0.106553 0.770069 0.0605674 0.14263 41
produce:pandora:StandardPandora 5.83767 153.807 4221.36 16.3543 659.805 41
produce:pandoraTrack:LArPandoraTrackCreation 0.102752 0.473827 2.78231 0.276899 0.601702 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.00907744 0.0174503 0.0657824 0.0148404 0.00912093 41
[art]:TriggerResults:TriggerResultInserter 1.4567e-05 2.39623e-05 0.00014222 2.07e-05 1.896e-05 41
end_path:out1:RootOutput 3.948e-06 6.05539e-06 2.8514e-05 5.099e-06 4.22856e-06 41
end_path:out1:RootOutput(write) 2.15086 2.43067 3.25801 2.37367 0.218289 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 7690.63 MB
Peak resident set size usage (VmHWM): 5797.45 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230_reco_stage1_20250919T174027_keepup.root
\tHists: np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230_reco_stage1_20250919T174027_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230_reco_stage1_20250919T174027_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230_reco_stage1_20250919T174027_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": 1758303628.0,
"core.end_time": 1758303628.0,
"core.events": [
81742,
81748,
81754,
81760,
81766,
81772,
81778,
81784,
81790,
81796,
81802,
81808,
81814,
81820,
81826,
81832,
81838,
81844,
81850,
81856,
81862,
81868,
81874,
81880,
81886,
81892,
81898,
81904,
81910,
81916,
81922,
81928,
81934,
81940,
81946,
81952,
81958,
81964,
81970,
81976,
81982
],
"core.event_count": 41,
"core.first_event_number": 81742,
"core.last_event_number": 81982,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230_reco_stage1_20250919T174027_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": 1758303628.0,
"core.end_time": 1758303628.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0335_df-s05-d4_dw_0_20250919T045230.hdf5"
}
]
} 