Jobsub ID 49243.31@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
.181] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[05:05:30.181] D [ aux ] <Resampler:resmp0> EOS at call=81
[05:05:30.181] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[05:05:30.181] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[05:05:30.181] D [ glue ] frame sink sees EOS
[05:05:30.181] D [ pgraph ] <Pgrapher:> graph execution complete
[05:05:30.181] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.37 sec
[05:05:30.181] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.14 sec
[05:05:30.181] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.02 sec
[05:05:30.181] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.57 sec
[05:05:30.181] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[05:05:30.181] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[05:05:30.182] I [ timer ] Timer: WireCell::Aux::Resampler : 0.18 sec
[05:05:30.182] I [ timer ] Timer: WireCell::Aux::Resampler : 0.15 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[05:05:30.182] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[05:05:30.182] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[05:05:30.182] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[05:05:30.182] I [ timer ] Timer: Total node execution : 20.879999903962016 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 14360 traces tagged "gauss"
FrameSaver: q=2.37875e+06 n=325960 tag=gauss
wclsFrameSaver: saving 18359 traces tagged "wiener"
FrameSaver: q=2.56431e+06 n=313195 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 276 XUs and 296 XVs -> 16 XUVs
C:0 T:1 931 XUs and 953 XVs -> 47 XUVs
C:0 T:2 1610 XUs and 1424 XVs -> 57 XUVs
C:0 T:3 140 XUs and 288 XVs -> 5 XUVs
C:0 T:4 610 XUs and 1228 XVs -> 50 XUVs
C:0 T:5 7159 XUs and 6285 XVs -> 566 XUVs
C:0 T:6 182 XUs and 291 XVs -> 8 XUVs
C:0 T:7 15 XUs and 19 XVs -> 0 XUVs
749 XUVs total
400 collection wire objects
749 potential space points
Neighbour search...
17991 tests to find 5248 neighbours
Iterating with no regularization...
Begin: 7.44476e+08
0 7.08171e+08
1 7.07192e+08
2 7.0712e+08
Now with regularization...
Begin: 6.86175e+08
0 6.86143e+08
19-Sep-2025 05:05:39 BST Closed output file "np02vd_raw_run039499_0162_df-s04-d1_dw_0_20250918T230705_reco_stage1_20250919T040539_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 38.607 144.177 3436.9 56.5621 520.897 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.114e-05 8.79972e-05 0.000225932 8.4301e-05 2.83386e-05 41
produce:tpcrawdecoder:PDVDTPCReader 5.33303 5.76041 6.48267 5.65618 0.330408 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.296537 0.30529 0.391102 0.299894 0.015259 41
produce:pdvddaphne:DAPHNEReaderPDVD 2.2327 2.59838 2.85255 2.63426 0.140504 41
produce:ophit:OpHitFinder 0.0303917 0.0418991 0.0519881 0.04221 0.00427259 41
produce:opflash:OpFlashFinderVerticalDrift 0.00460698 0.00945035 0.0167884 0.00940382 0.0023353 41
produce:wclsdatavd:WireCellToolkit 21.3853 27.4036 66.0802 24.7153 7.94869 41
produce:gaushit:GausHitFinder 0.252574 0.592737 2.29071 0.544311 0.30254 41
produce:nhitsfilter:NumberOfHitsFilter 7.3251e-05 0.00012535 0.000375954 0.000105771 5.93683e-05 41
produce:reco3d:SpacePointSolver 2.05461 5.97646 47.3564 4.96412 6.73498 41
produce:hitpdune:DisambigFromSpacePoints 0.0180696 0.0921718 1.31818 0.0603485 0.19571 41
produce:pandora:StandardPandora 2.51533 98.7278 3302.42 15.379 506.712 41
produce:pandoraTrack:LArPandoraTrackCreation 0.0909516 0.372637 4.9134 0.250709 0.726156 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.00647525 0.0151289 0.0604664 0.0140455 0.00828932 41
[art]:TriggerResults:TriggerResultInserter 1.321e-05 2.76596e-05 8.3231e-05 2.6471e-05 1.15141e-05 41
end_path:out1:RootOutput 3.29e-06 6.16e-06 2.3361e-05 5.68e-06 3.07527e-06 41
end_path:out1:RootOutput(write) 1.795 2.25979 3.45873 2.21876 0.289074 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5654.76 MB
Peak resident set size usage (VmHWM): 3672.16 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0162_df-s04-d1_dw_0_20250918T230705_reco_stage1_20250919T040539_keepup.root
\tHists: np02vd_raw_run039499_0162_df-s04-d1_dw_0_20250918T230705_reco_stage1_20250919T040539_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0162_df-s04-d1_dw_0_20250918T230705_reco_stage1_20250919T040539_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0162_df-s04-d1_dw_0_20250918T230705_reco_stage1_20250919T040539_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": 1758254740.0,
"core.end_time": 1758254740.0,
"core.events": [
39480,
39486,
39492,
39498,
39504,
39510,
39516,
39522,
39528,
39534,
39540,
39546,
39552,
39558,
39564,
39570,
39576,
39582,
39588,
39594,
39600,
39606,
39612,
39618,
39624,
39630,
39636,
39642,
39648,
39654,
39660,
39666,
39672,
39678,
39684,
39690,
39696,
39702,
39708,
39714,
39720
],
"core.event_count": 41,
"core.first_event_number": 39480,
"core.last_event_number": 39720,
"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_0162_df-s04-d1_dw_0_20250918T230705.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0162_df-s04-d1_dw_0_20250918T230705_reco_stage1_20250919T040539_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": 1758254740.0,
"core.end_time": 1758254740.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_0162_df-s04-d1_dw_0_20250918T230705.hdf5"
}
]
}