Jobsub ID 46794.75@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
ll=18
[21:46:31.015] D [ aux ] <Resampler:resmp0> EOS at call=37
[21:46:31.015] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[21:46:31.015] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[21:46:31.016] D [ glue ] frame sink sees EOS
[21:46:31.016] D [ pgraph ] <Pgrapher:> graph execution complete
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.22 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.97 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.74 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.52 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.47 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.65 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.48 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Aux::Resampler : 0.92 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Aux::Resampler : 0.89 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Aux::Resampler : 0.86 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Aux::Resampler : 0.84 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[21:46:31.016] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:46:31.016] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[21:46:31.016] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[21:46:31.016] I [ timer ] Timer: Total node execution : 63.59999970346689 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 45038 traces tagged "gauss"
FrameSaver: q=8.09479e+06 n=922406 tag=gauss
wclsFrameSaver: saving 54911 traces tagged "wiener"
FrameSaver: q=8.51222e+06 n=878376 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 198 XUs and 203 XVs -> 9 XUVs
C:0 T:1 107 XUs and 88 XVs -> 3 XUVs
C:0 T:2 84 XUs and 77 XVs -> 2 XUVs
C:0 T:3 44 XUs and 56 XVs -> 1 XUVs
C:0 T:4 7986 XUs and 10586 XVs -> 492 XUVs
C:0 T:5 1970 XUs and 1546 XVs -> 70 XUVs
C:0 T:6 700 XUs and 1180 XVs -> 32 XUVs
C:0 T:7 1258 XUs and 1235 XVs -> 38 XUVs
C:0 T:8 541 XUs and 658 XVs -> 30 XUVs
C:0 T:9 778 XUs and 1010 XVs -> 69 XUVs
C:0 T:10 1284 XUs and 1636 XVs -> 104 XUVs
C:0 T:11 2304 XUs and 2132 XVs -> 289 XUVs
C:0 T:12 2652 XUs and 3653 XVs -> 179 XUVs
C:0 T:13 981 XUs and 1549 XVs -> 77 XUVs
C:0 T:14 1234 XUs and 1425 XVs -> 110 XUVs
C:0 T:15 1836 XUs and 2065 XVs -> 136 XUVs
1641 XUVs total
1272 collection wire objects
1641 potential space points
Neighbour search...
21503 tests to find 7754 neighbours
Iterating with no regularization...
Begin: 3.2678e+09
0 2.97235e+09
1 2.96743e+09
2 2.96738e+09
Now with regularization...
Begin: 2.93193e+09
0 2.93189e+09
15-Sep-2025 21:47:20 CEST Closed output file "np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105_reco_stage1_20250915T194720_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 115.596 166.763 296.863 145.63 49.4935 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.5955e-05 0.000105246 0.000288507 8.7863e-05 4.82499e-05 19
produce:tpcrawdecoder:PDVDTPCReader 7.92563 9.11799 10.8469 8.79796 0.892823 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.0594776 0.0656645 0.0780176 0.064009 0.0057362 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000273945 0.000358556 0.000917241 0.00032341 0.000138429 19
produce:ophit:OpHitFinder 0.000149777 0.00026524 0.0011158 0.000204821 0.000207723 19
produce:opflash:OpFlashFinderVerticalDrift 5.0206e-05 9.16336e-05 0.000452205 6.581e-05 8.62343e-05 19
produce:wclsdatavd:WireCellToolkit 62.3368 71.1453 84.5739 70.3073 6.49186 19
produce:gaushit:GausHitFinder 1.07192 1.57258 2.43134 1.49029 0.34339 19
produce:nhitsfilter:NumberOfHitsFilter 0.000261887 0.000408582 0.00085784 0.000377062 0.000145626 19
produce:reco3d:SpacePointSolver 9.3589 15.7849 25.8873 13.8679 4.58262 19
produce:hitpdune:DisambigFromSpacePoints 0.12785 0.271505 0.582754 0.24558 0.113344 19
produce:pandora:StandardPandora 27.9508 61.6302 169.668 49.3839 39.5924 19
produce:pandoraTrack:LArPandoraTrackCreation 0.50492 1.27448 2.42848 1.17589 0.442486 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0247987 0.0382507 0.0499054 0.0373803 0.00754017 19
[art]:TriggerResults:TriggerResultInserter 3.2859e-05 5.42966e-05 0.000162136 4.8293e-05 2.74925e-05 19
end_path:out1:RootOutput 7.722e-06 1.44441e-05 5.1548e-05 1.2759e-05 8.95648e-06 19
end_path:out1:RootOutput(write) 5.31126 5.80936 6.77893 5.76918 0.388479 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5308.68 MB
Peak resident set size usage (VmHWM): 3393.15 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105_reco_stage1_20250915T194720_keepup.root
\tHists: np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105_reco_stage1_20250915T194720_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105_reco_stage1_20250915T194720_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105_reco_stage1_20250915T194720_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": 1757965640.0,
"core.end_time": 1757965640.0,
"core.events": [
11175,
11179,
11183,
11187,
11191,
11195,
11199,
11203,
11207,
11211,
11215,
11219,
11223,
11227,
11231,
11235,
11239,
11243,
11247
],
"core.event_count": 19,
"core.first_event_number": 11175,
"core.last_event_number": 11247,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105_reco_stage1_20250915T194720_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": 1757965640.0,
"core.end_time": 1757965640.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0145_df-s05-d3_dw_0_20250915T180105.hdf5"
}
]
} 