Jobsub ID 41395.41@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
node0sigproc0> EOS at call=95 anode=0
[03:45:55.223] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[03:45:55.223] D [ glue ] frame sink sees EOS
[03:45:55.223] D [ pgraph ] <Pgrapher:> graph execution complete
[03:45:55.223] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.11 sec
[03:45:55.223] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.7 sec
[03:45:55.223] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.6 sec
[03:45:55.223] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.98 sec
[03:45:55.223] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[03:45:55.223] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[03:45:55.223] I [ timer ] Timer: WireCell::Aux::Resampler : 0.4 sec
[03:45:55.223] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[03:45:55.223] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[03:45:55.223] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[03:45:55.223] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[03:45:55.223] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[03:45:55.224] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[03:45:55.224] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[03:45:55.224] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[03:45:55.224] I [ timer ] Timer: Total node execution : 24.029999850317836 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 15973 traces tagged "gauss"
FrameSaver: q=3.17006e+06 n=374033 tag=gauss
wclsFrameSaver: saving 20152 traces tagged "wiener"
FrameSaver: q=3.44113e+06 n=364274 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 818 XUs and 588 XVs -> 78 XUVs
C:0 T:1 813 XUs and 650 XVs -> 106 XUVs
C:0 T:2 5763 XUs and 4747 XVs -> 277 XUVs
C:0 T:3 245 XUs and 196 XVs -> 10 XUVs
C:0 T:4 153 XUs and 146 XVs -> 10 XUVs
C:0 T:5 1270 XUs and 829 XVs -> 30 XUVs
C:0 T:6 357 XUs and 264 XVs -> 21 XUVs
C:0 T:7 572 XUs and 663 XVs -> 22 XUVs
554 XUVs total
434 collection wire objects
554 potential space points
Neighbour search...
7112 tests to find 2766 neighbours
Iterating with no regularization...
Begin: 4.69697e+09
0 4.48303e+09
1 4.44864e+09
2 4.44864e+09
Now with regularization...
Begin: 4.41519e+09
0 4.41517e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 03:46:11 CEST Closed output file "np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614_reco_stage1_20250918T014611_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 39.4407 75.2136 376.341 62.7294 51.5329 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.956e-05 0.00011571 0.000359051 9.624e-05 5.10836e-05 48
produce:tpcrawdecoder:PDVDTPCReader 5.33679 6.34595 8.48422 6.05649 0.862804 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.264228 0.272577 0.29959 0.270127 0.00785141 48
produce:pdvddaphne:DAPHNEReaderPDVD 2.89208 3.36246 4.07127 3.37769 0.229053 48
produce:ophit:OpHitFinder 0.0316339 0.0504491 0.0740449 0.0499591 0.00902446 48
produce:opflash:OpFlashFinderVerticalDrift 0.000976471 0.0110236 0.0181508 0.0111886 0.00350318 48
produce:wclsdatavd:WireCellToolkit 21.4309 31.2812 63.1134 25.6496 10.3958 48
produce:gaushit:GausHitFinder 0.308587 0.702744 2.66848 0.665588 0.3408 48
produce:nhitsfilter:NumberOfHitsFilter 8.589e-05 0.00017513 0.000655461 0.00016761 7.7394e-05 48
produce:reco3d:SpacePointSolver 1.1208 5.48806 17.9096 5.06527 3.2305 48
produce:hitpdune:DisambigFromSpacePoints 0.015977 0.0922094 0.36325 0.0654639 0.0771231 48
produce:pandora:StandardPandora 2.62314 24.5969 280.256 14.4185 40.902 48
produce:pandoraTrack:LArPandoraTrackCreation 0.0642701 0.298722 0.884768 0.23996 0.186357 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.00599009 0.0168573 0.0413321 0.0155807 0.006663 48
[art]:TriggerResults:TriggerResultInserter 1.684e-05 2.79386e-05 9.772e-05 2.4325e-05 1.21567e-05 48
end_path:out1:RootOutput 4.96e-06 1.09477e-05 3.682e-05 9.225e-06 5.79202e-06 48
end_path:out1:RootOutput(write) 2.22803 2.67542 3.45088 2.61448 0.316027 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6137.37 MB
Peak resident set size usage (VmHWM): 4233.09 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614_reco_stage1_20250918T014611_keepup.root
\tHists: np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614_reco_stage1_20250918T014611_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614_reco_stage1_20250918T014611_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614_reco_stage1_20250918T014611_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": 1758159972.0,
"core.end_time": 1758159972.0,
"core.events": [
57990,
57996,
58002,
58008,
58014,
58020,
58026,
58032,
58038,
58044,
58050,
58056,
58062,
58068,
58074,
58080,
58086,
58092,
58098,
58104,
58110,
58116,
58122,
58128,
58134,
58140,
58146,
58152,
58158,
58164,
58170,
58176,
58182,
58188,
58194,
58200,
58206,
58212,
58218,
58224,
58230,
58236,
58242,
58248,
58254,
58260,
58266,
58272
],
"core.event_count": 48,
"core.first_event_number": 57990,
"core.last_event_number": 58272,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614_reco_stage1_20250918T014611_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": 1758159972.0,
"core.end_time": 1758159972.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0202_df-s05-d0_dw_0_20250917T234614.hdf5"
}
]
}