Jobsub ID 42563.129@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
[23:17:09.375] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[23:17:09.375] D [ aux ] <Resampler:resmp0> EOS at call=81
[23:17:09.375] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[23:17:09.375] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[23:17:09.375] D [ glue ] frame sink sees EOS
[23:17:09.375] D [ pgraph ] <Pgrapher:> graph execution complete
[23:17:09.375] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.16 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.99 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.02 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.02 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[23:17:09.376] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[23:17:09.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:17:09.376] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[23:17:09.376] I [ timer ] Timer: Total node execution : 34.44000002555549 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 16931 traces tagged "gauss"
FrameSaver: q=2.57373e+06 n=381257 tag=gauss
wclsFrameSaver: saving 21264 traces tagged "wiener"
FrameSaver: q=2.74764e+06 n=368760 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 405 XUs and 567 XVs -> 23 XUVs
C:0 T:1 908 XUs and 905 XVs -> 26 XUVs
C:0 T:2 115 XUs and 109 XVs -> 2 XUVs
C:0 T:3 331 XUs and 370 XVs -> 23 XUVs
C:0 T:4 2292 XUs and 2115 XVs -> 72 XUVs
C:0 T:5 979 XUs and 1061 XVs -> 33 XUVs
C:0 T:6 4136 XUs and 4118 XVs -> 401 XUVs
C:0 T:7 232 XUs and 218 XVs -> 11 XUVs
591 XUVs total
410 collection wire objects
591 potential space points
Neighbour search...
15401 tests to find 4576 neighbours
Iterating with no regularization...
Begin: 4.46773e+09
0 4.45719e+09
1 4.45707e+09
Now with regularization...
Begin: 4.35355e+09
0 4.35324e+09
18-Sep-2025 23:17:30 UTC Closed output file "np02vd_raw_run039499_0053_df-s05-d3_dw_0_20250918T192935_reco_stage1_20250918T231730_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 53.9212 198.242 3825.46 84.7545 582.265 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.5933e-05 0.000152348 0.000395502 0.000137064 6.87548e-05 41
produce:tpcrawdecoder:PDVDTPCReader 7.71344 8.47473 13.2642 8.13796 0.951228 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.389689 0.397378 0.413375 0.396326 0.00574565 41
produce:pdvddaphne:DAPHNEReaderPDVD 3.05195 3.49728 4.25691 3.48106 0.234856 41
produce:ophit:OpHitFinder 0.0394042 0.050597 0.061549 0.0509586 0.00502097 41
produce:opflash:OpFlashFinderVerticalDrift 0.00683249 0.0139859 0.0255962 0.0137102 0.00404526 41
produce:wclsdatavd:WireCellToolkit 31.7286 44.1045 94.9412 38.1039 14.1972 41
produce:gaushit:GausHitFinder 0.270565 0.768719 2.18164 0.740854 0.313031 41
produce:nhitsfilter:NumberOfHitsFilter 8.0752e-05 0.000369459 0.000795585 0.000311559 0.000185788 41
produce:reco3d:SpacePointSolver 1.75274 7.72981 55.2466 6.7193 8.00649 41
produce:hitpdune:DisambigFromSpacePoints 0.0135563 0.138119 1.67359 0.0955079 0.250248 41
produce:pandora:StandardPandora 2.79529 129.579 3653.38 21.9676 564.342 41
produce:pandoraTrack:LArPandoraTrackCreation 0.0689466 0.449827 3.89694 0.351002 0.578289 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.00589653 0.0207619 0.0533215 0.0208387 0.00809739 41
[art]:TriggerResults:TriggerResultInserter 2.2821e-05 5.2035e-05 0.000171325 4.8961e-05 2.3374e-05 41
end_path:out1:RootOutput 4.5e-06 1.24759e-05 5.1692e-05 1.122e-05 6.81677e-06 41
end_path:out1:RootOutput(write) 2.3479 2.98379 3.9603 2.8669 0.362271 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5909.68 MB
Peak resident set size usage (VmHWM): 3848.3 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0053_df-s05-d3_dw_0_20250918T192935_reco_stage1_20250918T231730_keepup.root
\tHists: np02vd_raw_run039499_0053_df-s05-d3_dw_0_20250918T192935_reco_stage1_20250918T231731_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0053_df-s05-d3_dw_0_20250918T192935_reco_stage1_20250918T231730_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0053_df-s05-d3_dw_0_20250918T192935_reco_stage1_20250918T231730_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": 1758237451.0,
"core.end_time": 1758237451.0,
"core.events": [
12981,
12987,
12993,
12999,
13005,
13011,
13017,
13023,
13029,
13035,
13041,
13047,
13053,
13059,
13065,
13071,
13077,
13083,
13089,
13095,
13101,
13107,
13113,
13119,
13125,
13131,
13137,
13143,
13149,
13155,
13161,
13167,
13173,
13179,
13185,
13191,
13197,
13203,
13209,
13215,
13221
],
"core.event_count": 41,
"core.first_event_number": 12981,
"core.last_event_number": 13221,
"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_0053_df-s05-d3_dw_0_20250918T192935.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0053_df-s05-d3_dw_0_20250918T192935_reco_stage1_20250918T231731_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": 1758237451.0,
"core.end_time": 1758237451.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_0053_df-s05-d3_dw_0_20250918T192935.hdf5"
}
]
}