Jobsub ID 41697.30@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
ode=0
[09:06:55.019] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[09:06:55.019] D [ glue ] frame sink sees EOS
[09:06:55.019] D [ pgraph ] <Pgrapher:> graph execution complete
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.84 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.16 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.5 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.86 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Aux::Resampler : 0.28 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:06:55.019] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:06:55.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:06:55.019] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:06:55.019] I [ timer ] Timer: Total node execution : 44.54999967291951 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22779 traces tagged "gauss"
FrameSaver: q=4.12374e+06 n=510577 tag=gauss
wclsFrameSaver: saving 28702 traces tagged "wiener"
FrameSaver: q=4.38882e+06 n=486730 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 229 XUs and 306 XVs -> 12 XUVs
C:0 T:1 1034 XUs and 1572 XVs -> 60 XUVs
C:0 T:2 872 XUs and 803 XVs -> 31 XUVs
C:0 T:3 1360 XUs and 1795 XVs -> 46 XUVs
C:0 T:4 861 XUs and 890 XVs -> 23 XUVs
C:0 T:5 9453 XUs and 11533 XVs -> 849 XUVs
C:0 T:6 1467 XUs and 1652 XVs -> 108 XUVs
C:0 T:7 3125 XUs and 3400 XVs -> 118 XUVs
1247 XUVs total
841 collection wire objects
1247 potential space points
Neighbour search...
30145 tests to find 8070 neighbours
Iterating with no regularization...
Begin: 4.21177e+09
0 4.15464e+09
1 4.15337e+09
Now with regularization...
Begin: 4.05825e+09
0 4.05812e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 09:07:34 BST Closed output file "np02vd_raw_run039433_0356_df-s05-d4_dw_0_20250918T055733_reco_stage1_20250918T080734_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 58.7399 99.9176 351.256 88.6312 51.2724 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.1262e-05 0.000152108 0.000293789 0.000127899 5.47324e-05 47
produce:tpcrawdecoder:PDVDTPCReader 6.75561 7.82984 10.3734 7.62271 0.815504 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.302711 0.310837 0.337534 0.309746 0.00657872 47
produce:pdvddaphne:DAPHNEReaderPDVD 3.53121 4.10645 4.61507 4.15524 0.245793 47
produce:ophit:OpHitFinder 0.0389825 0.062853 0.106922 0.0636994 0.00925547 47
produce:opflash:OpFlashFinderVerticalDrift 0.000950296 0.0157739 0.0327487 0.0159331 0.00526277 47
produce:wclsdatavd:WireCellToolkit 31.7489 44.8844 73.971 39.033 11.818 47
produce:gaushit:GausHitFinder 0.464533 0.88176 1.88415 0.886286 0.234911 47
produce:nhitsfilter:NumberOfHitsFilter 0.000127618 0.00021554 0.00057764 0.000205965 6.98771e-05 47
produce:reco3d:SpacePointSolver 2.29022 6.69728 16.4297 6.25999 2.81212 47
produce:hitpdune:DisambigFromSpacePoints 0.0251944 0.1072 0.622205 0.0833992 0.0876072 47
produce:pandora:StandardPandora 6.56667 31.131 264.041 20.0979 42.6356 47
produce:pandoraTrack:LArPandoraTrackCreation 0.137161 0.377017 1.72455 0.334688 0.239674 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.0120247 0.0218159 0.0373018 0.0216237 0.00584204 47
[art]:TriggerResults:TriggerResultInserter 2.7241e-05 4.10624e-05 0.000123621 3.783e-05 1.48376e-05 47
end_path:out1:RootOutput 6.111e-06 1.36248e-05 5.7969e-05 1.1572e-05 1.02733e-05 47
end_path:out1:RootOutput(write) 2.99929 3.46095 4.53922 3.31266 0.388058 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4408.84 MB
Peak resident set size usage (VmHWM): 2452.89 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0356_df-s05-d4_dw_0_20250918T055733_reco_stage1_20250918T080734_keepup.root
\tHists: np02vd_raw_run039433_0356_df-s05-d4_dw_0_20250918T055733_reco_stage1_20250918T080734_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0356_df-s05-d4_dw_0_20250918T055733_reco_stage1_20250918T080734_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0356_df-s05-d4_dw_0_20250918T055733_reco_stage1_20250918T080734_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": 1758182855.0,
"core.end_time": 1758182855.0,
"core.events": [
102016,
102022,
102028,
102034,
102040,
102046,
102052,
102058,
102064,
102070,
102076,
102082,
102088,
102094,
102100,
102106,
102112,
102118,
102124,
102130,
102136,
102142,
102148,
102154,
102160,
102166,
102172,
102178,
102184,
102190,
102196,
102202,
102208,
102214,
102220,
102226,
102232,
102238,
102244,
102250,
102256,
102262,
102268,
102274,
102280,
102286,
102292
],
"core.event_count": 47,
"core.first_event_number": 102016,
"core.last_event_number": 102292,
"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_0356_df-s05-d4_dw_0_20250918T055733.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0356_df-s05-d4_dw_0_20250918T055733_reco_stage1_20250918T080734_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": 1758182855.0,
"core.end_time": 1758182855.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_0356_df-s05-d4_dw_0_20250918T055733.hdf5"
}
]
} 