Jobsub ID 44835.54@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
r:resmp0> EOS at call=35
[14:00:35.496] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[14:00:35.496] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[14:00:35.496] D [ glue ] frame sink sees EOS
[14:00:35.496] D [ pgraph ] <Pgrapher:> graph execution complete
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.22 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.72 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.18 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.03 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.17 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.06 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.83 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.8 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Aux::Resampler : 0.72 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Aux::Resampler : 0.64 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Aux::Resampler : 0.63 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Aux::Resampler : 0.62 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:35.496] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[14:00:35.496] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[14:00:35.496] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[14:00:35.496] I [ timer ] Timer: Total node execution : 61.65000071935356 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 62000 traces tagged "gauss"
FrameSaver: q=1.21213e+07 n=1412474 tag=gauss
wclsFrameSaver: saving 77098 traces tagged "wiener"
FrameSaver: q=1.30559e+07 n=1358206 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 429 XUs and 536 XVs -> 20 XUVs
C:0 T:1 485 XUs and 1023 XVs -> 50 XUVs
C:0 T:2 1186 XUs and 1137 XVs -> 76 XUVs
C:0 T:3 1015 XUs and 1398 XVs -> 36 XUVs
C:0 T:4 308 XUs and 449 XVs -> 29 XUVs
C:0 T:5 23 XUs and 23 XVs -> 1 XUVs
C:0 T:6 236 XUs and 478 XVs -> 14 XUVs
C:0 T:7 727 XUs and 1333 XVs -> 43 XUVs
C:0 T:8 17838 XUs and 29454 XVs -> 3129 XUVs
C:0 T:9 11789 XUs and 27353 XVs -> 3159 XUVs
C:0 T:10 11485 XUs and 15142 XVs -> 2241 XUVs
C:0 T:11 7794 XUs and 10916 XVs -> 1023 XUVs
C:0 T:12 12671 XUs and 19145 XVs -> 1307 XUVs
C:0 T:13 7982 XUs and 12306 XVs -> 1436 XUVs
C:0 T:14 5632 XUs and 7042 XVs -> 1074 XUVs
C:0 T:15 10018 XUs and 22142 XVs -> 2587 XUVs
16225 XUVs total
2802 collection wire objects
16225 potential space points
Neighbour search...
1757693 tests to find 749100 neighbours
Iterating with no regularization...
Begin: 1.0776e+09
0 9.69228e+08
1 9.63245e+08
2 9.62234e+08
3 9.61885e+08
Now with regularization...
Begin: 9.46228e+08
0 9.45928e+08
11-Sep-2025 14:03:05 CEST Closed output file "np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948_reco_stage1_20250911T120305_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 114.834 173.157 284.027 156.614 46.4747 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 4.1001e-05 7.58848e-05 0.000221643 6.37705e-05 3.922e-05 18
produce:tpcrawdecoder:PDVDTPCReader 5.43398 5.97637 7.00506 5.95221 0.375521 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.000747889 0.005211 0.0336324 0.00146101 0.00758775 18
produce:pdvddaphne:DAPHNEReaderPDVD 2.6834 3.308 4.34101 3.19436 0.421521 18
produce:ophit:OpHitFinder 0.0303137 0.0389673 0.0469769 0.0385101 0.00405106 18
produce:opflash:OpFlashFinderVerticalDrift 0.00711361 0.00987907 0.0139269 0.00944245 0.00185711 18
produce:wclsdatavd:WireCellToolkit 49.6919 58.4116 64.5249 59.8224 4.52073 18
produce:gaushit:GausHitFinder 0.86284 1.22547 1.62205 1.22325 0.20903 18
produce:nhitsfilter:NumberOfHitsFilter 0.000238432 0.000312055 0.000570887 0.000290873 7.88988e-05 18
produce:reco3d:SpacePointSolver 13.1507 17.7182 27.5483 16.3846 4.17323 18
produce:hitpdune:DisambigFromSpacePoints 0.174981 0.26266 0.442674 0.234529 0.0701181 18
produce:pandora:StandardPandora 34.1657 80.7246 180.328 64.4298 40.9546 18
produce:pandoraTrack:LArPandoraTrackCreation 0.721125 1.17322 1.9437 1.09631 0.3416 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0202505 0.0280696 0.0481819 0.0264079 0.00675968 18
[art]:TriggerResults:TriggerResultInserter 1.635e-05 2.37654e-05 4.361e-05 2.04005e-05 7.72708e-06 18
end_path:out1:RootOutput 3.75e-06 7.81678e-06 2.591e-05 7.3555e-06 5.07182e-06 18
end_path:out1:RootOutput(write) 3.91915 4.2398 4.67573 4.1947 0.201571 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5308.41 MB
Peak resident set size usage (VmHWM): 3339.89 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948_reco_stage1_20250911T120305_keepup.root
\tHists: np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948_reco_stage1_20250911T120305_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948_reco_stage1_20250911T120305_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948_reco_stage1_20250911T120305_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": 1757592186.0,
"core.end_time": 1757592186.0,
"core.events": [
30979,
30999,
31019,
31039,
31059,
31079,
31099,
31119,
31139,
31159,
31179,
31199,
31219,
31239,
31259,
31279,
31299,
31319
],
"core.event_count": 18,
"core.first_event_number": 30979,
"core.last_event_number": 31319,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948_reco_stage1_20250911T120305_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": 1757592186.0,
"core.end_time": 1757592186.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_0086_df-s05-d5_dw_0_20250831T104948.hdf5"
}
]
} 