Jobsub ID 49050.123@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
<Resampler:resmp0> EOS at call=81
[01:13:51.746] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[01:13:51.746] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[01:13:51.746] D [ glue ] frame sink sees EOS
[01:13:51.746] D [ pgraph ] <Pgrapher:> graph execution complete
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.52 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.32 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.85 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.31 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Aux::Resampler : 0.33 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:13:51.746] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[01:13:51.746] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:13:51.746] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[01:13:51.746] I [ timer ] Timer: Total node execution : 34.330000000074506 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 16777 traces tagged "gauss"
FrameSaver: q=2.68039e+06 n=386162 tag=gauss
wclsFrameSaver: saving 21715 traces tagged "wiener"
FrameSaver: q=2.897e+06 n=367611 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 379 XUs and 568 XVs -> 39 XUVs
C:0 T:1 312 XUs and 471 XVs -> 40 XUVs
C:0 T:2 229 XUs and 128 XVs -> 3 XUVs
C:0 T:3 937 XUs and 1014 XVs -> 49 XUVs
C:0 T:4 2862 XUs and 4466 XVs -> 236 XUVs
C:0 T:5 3882 XUs and 3939 XVs -> 373 XUVs
C:0 T:6 283 XUs and 634 XVs -> 19 XUVs
C:0 T:7 6643 XUs and 8663 XVs -> 583 XUVs
1342 XUVs total
859 collection wire objects
1342 potential space points
Neighbour search...
50736 tests to find 14520 neighbours
Iterating with no regularization...
Begin: 6.23486e+08
0 5.66456e+08
1 5.62801e+08
2 5.62689e+08
Now with regularization...
Begin: 5.49948e+08
0 5.49888e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
19-Sep-2025 01:14:16 BST Closed output file "np02vd_raw_run039499_0070_df-s05-d3_dw_0_20250918T200455_reco_stage1_20250919T001416_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 78.7861 204.702 2726.29 131.684 401.277 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.7677e-05 0.000324903 0.0058028 0.000135625 0.000897856 41
produce:tpcrawdecoder:PDVDTPCReader 28.2505 40.2565 53.0367 40.4843 6.73931 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.388238 0.449497 0.663047 0.42416 0.0659409 41
produce:pdvddaphne:DAPHNEReaderPDVD 6.09756 9.24724 12.1536 9.10983 1.42242 41
produce:ophit:OpHitFinder 0.0424846 0.0624809 0.107522 0.0601053 0.0119928 41
produce:opflash:OpFlashFinderVerticalDrift 0.0062843 0.0151831 0.0516117 0.0147842 0.0067406 41
produce:wclsdatavd:WireCellToolkit 29.5209 46.4558 124.997 39.2247 18.0468 41
produce:gaushit:GausHitFinder 0.460412 0.89066 2.2769 0.822939 0.323022 41
produce:nhitsfilter:NumberOfHitsFilter 0.000119675 0.000289647 0.00171321 0.000233049 0.000249548 41
produce:reco3d:SpacePointSolver 2.30832 8.47911 36.4229 7.23433 5.73533 41
produce:hitpdune:DisambigFromSpacePoints 0.0265974 0.133697 0.877817 0.0950995 0.13934 41
produce:pandora:StandardPandora 4.63343 94.8332 2508.34 20.6055 382.931 41
produce:pandoraTrack:LArPandoraTrackCreation 0.13049 0.505114 2.86435 0.344616 0.460751 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0103226 0.0236556 0.0775822 0.0208342 0.0113098 41
[art]:TriggerResults:TriggerResultInserter 1.7252e-05 3.97171e-05 9.3235e-05 3.5717e-05 1.54008e-05 41
end_path:out1:RootOutput 4.859e-06 1.0376e-05 4.3081e-05 7.454e-06 7.793e-06 41
end_path:out1:RootOutput(write) 2.1393 3.31689 4.40704 3.31785 0.43268 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 7400.71 MB
Peak resident set size usage (VmHWM): 5453.5 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0070_df-s05-d3_dw_0_20250918T200455_reco_stage1_20250919T001416_keepup.root
\tHists: np02vd_raw_run039499_0070_df-s05-d3_dw_0_20250918T200455_reco_stage1_20250919T001417_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0070_df-s05-d3_dw_0_20250918T200455_reco_stage1_20250919T001416_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0070_df-s05-d3_dw_0_20250918T200455_reco_stage1_20250919T001416_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": 1758240858.0,
"core.end_time": 1758240858.0,
"core.events": [
17151,
17157,
17163,
17169,
17175,
17181,
17187,
17193,
17199,
17205,
17211,
17217,
17223,
17229,
17235,
17241,
17247,
17253,
17259,
17265,
17271,
17277,
17283,
17289,
17295,
17301,
17307,
17313,
17319,
17325,
17331,
17337,
17343,
17349,
17355,
17361,
17367,
17373,
17379,
17385,
17391
],
"core.event_count": 41,
"core.first_event_number": 17151,
"core.last_event_number": 17391,
"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_0070_df-s05-d3_dw_0_20250918T200455.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0070_df-s05-d3_dw_0_20250918T200455_reco_stage1_20250919T001417_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": 1758240858.0,
"core.end_time": 1758240858.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_0070_df-s05-d3_dw_0_20250918T200455.hdf5"
}
]
} 