Jobsub ID 48994.46@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
> see EOS at call=40
[21:06:28.437] D [ aux ] <Resampler:resmp0> EOS at call=81
[21:06:28.437] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[21:06:28.437] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[21:06:28.437] D [ glue ] frame sink sees EOS
[21:06:28.437] D [ pgraph ] <Pgrapher:> graph execution complete
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.94 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.11 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.45 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.42 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Aux::Resampler : 0.36 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Aux::Resampler : 0.36 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:06:28.437] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[21:06:28.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:06:28.437] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[21:06:28.437] I [ timer ] Timer: Total node execution : 41.39999916031957 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 21235 traces tagged "gauss"
FrameSaver: q=3.46181e+06 n=511159 tag=gauss
wclsFrameSaver: saving 26207 traces tagged "wiener"
FrameSaver: q=3.68991e+06 n=495883 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 365 XUs and 590 XVs -> 26 XUVs
C:0 T:1 583 XUs and 460 XVs -> 21 XUVs
C:0 T:2 446 XUs and 445 XVs -> 21 XUVs
C:0 T:3 644 XUs and 523 XVs -> 24 XUVs
C:0 T:4 5502 XUs and 14008 XVs -> 450 XUVs
C:0 T:5 401 XUs and 598 XVs -> 8 XUVs
C:0 T:6 10135 XUs and 25209 XVs -> 934 XUVs
C:0 T:7 806 XUs and 982 XVs -> 37 XUVs
1521 XUVs total
947 collection wire objects
1521 potential space points
Neighbour search...
43267 tests to find 11710 neighbours
Iterating with no regularization...
Begin: 1.8092e+09
0 1.63495e+09
1 1.63054e+09
2 1.63036e+09
Now with regularization...
Begin: 1.6212e+09
0 1.62116e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 21:07:05 UTC Closed output file "np02vd_raw_run039499_0022_df-s04-d3_dw_0_20250918T182559_reco_stage1_20250918T210705_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 67.4308 106.219 217.814 95.8677 34.1637 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.5012e-05 0.000155481 0.000455018 0.000124042 7.83002e-05 41
produce:tpcrawdecoder:PDVDTPCReader 7.48288 8.27238 12.6494 7.81674 1.1235 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.392187 0.396396 0.402242 0.395708 0.00240754 41
produce:pdvddaphne:DAPHNEReaderPDVD 3.53916 4.01178 4.52415 4.03967 0.230201 41
produce:ophit:OpHitFinder 0.0456194 0.0583401 0.0680727 0.0584572 0.00521286 41
produce:opflash:OpFlashFinderVerticalDrift 0.00909811 0.0179737 0.0382101 0.0172184 0.00587182 41
produce:wclsdatavd:WireCellToolkit 36.6487 48.1792 104.382 42.7683 14.0055 41
produce:gaushit:GausHitFinder 0.420636 0.914102 1.33909 0.93552 0.229541 41
produce:nhitsfilter:NumberOfHitsFilter 0.000122182 0.00023428 0.000494098 0.000218554 7.59566e-05 41
produce:reco3d:SpacePointSolver 2.25479 8.18004 14.8555 7.92438 2.76216 41
produce:hitpdune:DisambigFromSpacePoints 0.0376353 0.116537 0.35368 0.0955971 0.0666589 41
produce:pandora:StandardPandora 8.70795 31.9316 107.753 25.7361 21.792 41
produce:pandoraTrack:LArPandoraTrackCreation 0.140974 0.477752 1.09046 0.439789 0.239708 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0135436 0.0256681 0.0413521 0.0244591 0.00734592 41
[art]:TriggerResults:TriggerResultInserter 2.117e-05 3.81832e-05 8.5971e-05 3.6671e-05 1.04628e-05 41
end_path:out1:RootOutput 3.93e-06 1.04034e-05 3.0931e-05 9.95e-06 4.7468e-06 41
end_path:out1:RootOutput(write) 2.83064 3.61141 4.60643 3.57067 0.356451 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4904.5 MB
Peak resident set size usage (VmHWM): 2823.75 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0022_df-s04-d3_dw_0_20250918T182559_reco_stage1_20250918T210705_keepup.root
\tHists: np02vd_raw_run039499_0022_df-s04-d3_dw_0_20250918T182559_reco_stage1_20250918T210706_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0022_df-s04-d3_dw_0_20250918T182559_reco_stage1_20250918T210705_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0022_df-s04-d3_dw_0_20250918T182559_reco_stage1_20250918T210705_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": 1758229626.0,
"core.end_time": 1758229626.0,
"core.events": [
5366,
5372,
5378,
5384,
5390,
5396,
5402,
5408,
5414,
5420,
5426,
5432,
5438,
5444,
5450,
5456,
5462,
5468,
5474,
5480,
5486,
5492,
5498,
5504,
5510,
5516,
5522,
5528,
5534,
5540,
5546,
5552,
5558,
5564,
5570,
5576,
5582,
5588,
5594,
5600,
5606
],
"core.event_count": 41,
"core.first_event_number": 5366,
"core.last_event_number": 5606,
"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_0022_df-s04-d3_dw_0_20250918T182559.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0022_df-s04-d3_dw_0_20250918T182559_reco_stage1_20250918T210706_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": 1758229626.0,
"core.end_time": 1758229626.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_0022_df-s04-d3_dw_0_20250918T182559.hdf5"
}
]
} 