Jobsub ID 41150.63@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
c ] <OmnibusSigProc:anode0sigproc0> EOS at call=39 anode=0
[22:10:07.018] D [ glue ] <FrameFanin:nfsp> EOS at call=39 with 8
[22:10:07.018] D [ glue ] frame sink sees EOS
[22:10:07.018] D [ pgraph ] <Pgrapher:> graph execution complete
[22:10:07.018] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.59 sec
[22:10:07.018] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.38 sec
[22:10:07.018] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.86 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.4 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.2 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.79 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.69 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.64 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Aux::Resampler : 1.05 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Aux::Resampler : 1.02 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Aux::Resampler : 1.02 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Aux::Resampler : 1.02 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[22:10:07.019] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:10:07.019] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:10:07.019] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:10:07.019] I [ timer ] Timer: Total node execution : 71.67999913170934 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 45282 traces tagged "gauss"
FrameSaver: q=7.40331e+06 n=926653 tag=gauss
wclsFrameSaver: saving 54508 traces tagged "wiener"
FrameSaver: q=7.75321e+06 n=892403 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 578 XUs and 455 XVs -> 25 XUVs
C:0 T:1 183 XUs and 165 XVs -> 10 XUVs
C:0 T:2 189 XUs and 220 XVs -> 11 XUVs
C:0 T:3 107 XUs and 119 XVs -> 5 XUVs
C:0 T:4 261 XUs and 284 XVs -> 19 XUVs
C:0 T:5 641 XUs and 391 XVs -> 27 XUVs
C:0 T:6 905 XUs and 858 XVs -> 50 XUVs
C:0 T:7 1292 XUs and 1369 XVs -> 81 XUVs
C:0 T:8 1310 XUs and 1487 XVs -> 103 XUVs
C:0 T:9 867 XUs and 917 XVs -> 74 XUVs
C:0 T:10 3440 XUs and 3675 XVs -> 241 XUVs
C:0 T:11 1450 XUs and 1386 XVs -> 146 XUVs
C:0 T:12 1034 XUs and 1367 XVs -> 74 XUVs
C:0 T:13 1242 XUs and 1435 XVs -> 73 XUVs
C:0 T:14 1487 XUs and 1798 XVs -> 120 XUVs
C:0 T:15 3980 XUs and 5493 XVs -> 279 XUVs
1338 XUVs total
1128 collection wire objects
1338 potential space points
Neighbour search...
11496 tests to find 4846 neighbours
Iterating with no regularization...
Begin: 5.13997e+08
0 4.87543e+08
1 4.86871e+08
2 4.86861e+08
Now with regularization...
Begin: 4.79641e+08
0 4.79638e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 22:11:32 CEST Closed output file "np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229_reco_stage1_20250917T201132_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 43.4573 171.564 240.06 174.37 40.1443 20
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.85e-05 6.8609e-05 0.000164359 6.2332e-05 2.26154e-05 20
produce:tpcrawdecoder:PDVDTPCReader 11.375 24.1651 50.5625 18.9205 9.21921 20
produce:triggerrawdecoder:PDVDTriggerReader4 0.292718 0.308015 0.532754 0.29403 0.0520132 20
produce:pdvddaphne:DAPHNEReaderPDVD 0.000315012 0.000356899 0.00062177 0.000330617 7.45952e-05 20
produce:ophit:OpHitFinder 0.000107202 0.000147864 0.000660092 0.000116309 0.000118875 20
produce:opflash:OpFlashFinderVerticalDrift 4.8842e-05 6.31659e-05 0.000278604 5.1707e-05 4.94557e-05 20
produce:wclsdatavd:WireCellToolkit 15.1897 70.5968 86.8589 72.8151 13.4027 20
produce:gaushit:GausHitFinder 0.529256 1.32165 1.99017 1.35253 0.312208 20
produce:nhitsfilter:NumberOfHitsFilter 0.000130225 0.000349781 0.000580562 0.000352443 9.22232e-05 20
produce:reco3d:SpacePointSolver 3.12926 14.5659 21.8348 14.9217 4.48011 20
produce:hitpdune:DisambigFromSpacePoints 0.0691134 0.203578 0.309112 0.215039 0.0595017 20
produce:pandora:StandardPandora 11.1017 53.7206 106.957 54.909 21.1375 20
produce:pandoraTrack:LArPandoraTrackCreation 0.318522 1.18673 2.1011 1.2407 0.422023 20
produce:pandoraGnocalo:GnocchiCalorimetry 0.0150195 0.0333025 0.0474537 0.0336774 0.00761967 20
[art]:TriggerResults:TriggerResultInserter 1.8856e-05 2.32962e-05 7.0062e-05 2.05735e-05 1.08493e-05 20
end_path:out1:RootOutput 4.308e-06 7.799e-06 2.2432e-05 7.3635e-06 3.52829e-06 20
end_path:out1:RootOutput(write) 1.39431 5.43113 5.98662 5.6244 0.939739 20
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4617.76 MB
Peak resident set size usage (VmHWM): 2731.68 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229_reco_stage1_20250917T201132_keepup.root
\tHists: np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229_reco_stage1_20250917T201133_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229_reco_stage1_20250917T201132_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229_reco_stage1_20250917T201132_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": 1758139893.0,
"core.end_time": 1758139893.0,
"core.events": [
29292,
29296,
29300,
29304,
29308,
29312,
29316,
29320,
29324,
29328,
29332,
29336,
29340,
29344,
29348,
29352,
29356,
29360,
29364,
29368
],
"core.event_count": 20,
"core.first_event_number": 29292,
"core.last_event_number": 29368,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229_reco_stage1_20250917T201133_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": 1758139893.0,
"core.end_time": 1758139893.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0381_df-s05-d0_dw_0_20250916T211229.hdf5"
}
]
} 