Jobsub ID 41739.79@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
[11:48:38.437] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[11:48:38.437] D [ glue ] frame sink sees EOS
[11:48:38.437] D [ pgraph ] <Pgrapher:> graph execution complete
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.53 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.1 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.47 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.2 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Aux::Resampler : 1.89 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Aux::Resampler : 1.73 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Aux::Resampler : 1.66 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Aux::Resampler : 1.62 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:48:38.437] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:48:38.437] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:48:38.437] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:48:38.437] I [ timer ] Timer: Total node execution : 67.24000111967325 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 20856 traces tagged "gauss"
FrameSaver: q=2.50241e+06 n=441631 tag=gauss
wclsFrameSaver: saving 25530 traces tagged "wiener"
FrameSaver: q=2.62222e+06 n=425852 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1601 XUs and 1870 XVs -> 97 XUVs
C:0 T:1 833 XUs and 504 XVs -> 28 XUVs
C:0 T:2 905 XUs and 982 XVs -> 36 XUVs
C:0 T:3 1607 XUs and 1576 XVs -> 54 XUVs
C:0 T:4 666 XUs and 907 XVs -> 27 XUVs
C:0 T:5 387 XUs and 384 XVs -> 25 XUVs
C:0 T:6 1095 XUs and 1132 XVs -> 44 XUVs
C:0 T:7 376 XUs and 608 XVs -> 21 XUVs
332 XUVs total
292 collection wire objects
332 potential space points
Neighbour search...
2330 tests to find 1098 neighbours
Iterating with no regularization...
Begin: 3.36683e+07
0 3.20551e+07
1 3.20547e+07
Now with regularization...
Begin: 3.11422e+07
0 3.1142e+07
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 11:49:12 BST Closed output file "np02vd_raw_run039433_0387_df-s05-d5_dw_0_20250918T071405_reco_stage1_20250918T104912_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 103.089 205.188 971.889 145.116 175.77 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.3468e-05 0.000117429 0.000342577 0.000104602 4.17086e-05 48
produce:tpcrawdecoder:PDVDTPCReader 25.7853 44.4615 79.5387 42.6174 9.94912 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.386625 0.487588 1.02781 0.431859 0.1368 48
produce:pdvddaphne:DAPHNEReaderPDVD 7.78118 11.2194 16.6483 11.4454 1.97546 48
produce:ophit:OpHitFinder 0.0441189 0.0678707 0.099103 0.0689453 0.00930162 48
produce:opflash:OpFlashFinderVerticalDrift 0.00709729 0.0159979 0.0277413 0.016675 0.0049582 48
produce:wclsdatavd:WireCellToolkit 40.0312 56.952 145.751 47.9057 18.5353 48
produce:gaushit:GausHitFinder 0.553049 1.10218 3.32047 0.953798 0.516298 48
produce:nhitsfilter:NumberOfHitsFilter 0.000128182 0.000326599 0.0006779 0.000265136 0.000152218 48
produce:reco3d:SpacePointSolver 2.3916 9.61901 33.4416 7.57608 7.16322 48
produce:hitpdune:DisambigFromSpacePoints 0.0330665 0.168892 1.31522 0.105245 0.210593 48
produce:pandora:StandardPandora 5.93334 76.6258 786.368 23.4117 154.478 48
produce:pandoraTrack:LArPandoraTrackCreation 0.0806838 0.775102 7.07975 0.446939 1.11017 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.0108784 0.0292015 0.0637901 0.0282421 0.0116959 48
[art]:TriggerResults:TriggerResultInserter 1.9978e-05 3.59558e-05 0.000102894 3.20805e-05 1.51295e-05 48
end_path:out1:RootOutput 4.538e-06 6.99823e-06 3.8092e-05 5.761e-06 5.90706e-06 48
end_path:out1:RootOutput(write) 2.34542 3.62618 4.82998 3.55816 0.492324 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6651.71 MB
Peak resident set size usage (VmHWM): 4699.18 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0387_df-s05-d5_dw_0_20250918T071405_reco_stage1_20250918T104912_keepup.root
\tHists: np02vd_raw_run039433_0387_df-s05-d5_dw_0_20250918T071405_reco_stage1_20250918T104913_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0387_df-s05-d5_dw_0_20250918T071405_reco_stage1_20250918T104912_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0387_df-s05-d5_dw_0_20250918T071405_reco_stage1_20250918T104912_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": 1758192554.0,
"core.end_time": 1758192554.0,
"core.events": [
110939,
110945,
110951,
110957,
110963,
110969,
110975,
110981,
110987,
110993,
110999,
111005,
111011,
111017,
111023,
111029,
111035,
111041,
111047,
111053,
111059,
111065,
111071,
111077,
111083,
111089,
111095,
111101,
111107,
111113,
111119,
111125,
111131,
111137,
111143,
111149,
111155,
111161,
111167,
111173,
111179,
111185,
111191,
111197,
111203,
111209,
111215,
111221
],
"core.event_count": 48,
"core.first_event_number": 110939,
"core.last_event_number": 111221,
"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_0387_df-s05-d5_dw_0_20250918T071405.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0387_df-s05-d5_dw_0_20250918T071405_reco_stage1_20250918T104913_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": 1758192554.0,
"core.end_time": 1758192554.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_0387_df-s05-d5_dw_0_20250918T071405.hdf5"
}
]
} 