Jobsub ID 40869.148@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
t call=18
[10:09:18.581] D [ aux ] <Resampler:resmp0> EOS at call=37
[10:09:18.581] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[10:09:18.581] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[10:09:18.581] D [ glue ] frame sink sees EOS
[10:09:18.581] D [ pgraph ] <Pgrapher:> graph execution complete
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.82 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.52 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.95 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.84 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.69 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.49 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.34 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.77 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Aux::Resampler : 1.02 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Aux::Resampler : 1.02 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Aux::Resampler : 0.94 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Aux::Resampler : 0.72 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[10:09:18.581] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:09:18.581] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:09:18.581] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:09:18.581] I [ timer ] Timer: Total node execution : 66.16000006347895 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 36520 traces tagged "gauss"
FrameSaver: q=5.33519e+06 n=719976 tag=gauss
wclsFrameSaver: saving 43979 traces tagged "wiener"
FrameSaver: q=5.61511e+06 n=694638 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 405 XUs and 411 XVs -> 19 XUVs
C:0 T:1 252 XUs and 182 XVs -> 11 XUVs
C:0 T:2 318 XUs and 229 XVs -> 7 XUVs
C:0 T:3 193 XUs and 158 XVs -> 6 XUVs
C:0 T:4 1912 XUs and 2362 XVs -> 146 XUVs
C:0 T:5 689 XUs and 1320 XVs -> 79 XUVs
C:0 T:6 518 XUs and 483 XVs -> 17 XUVs
C:0 T:7 313 XUs and 357 XVs -> 9 XUVs
C:0 T:8 596 XUs and 646 XVs -> 41 XUVs
C:0 T:9 664 XUs and 1229 XVs -> 36 XUVs
C:0 T:10 1246 XUs and 1358 XVs -> 93 XUVs
C:0 T:11 1650 XUs and 2320 XVs -> 173 XUVs
C:0 T:12 280 XUs and 238 XVs -> 13 XUVs
C:0 T:13 1910 XUs and 2398 XVs -> 85 XUVs
C:0 T:14 563 XUs and 470 XVs -> 67 XUVs
C:0 T:15 1345 XUs and 1398 XVs -> 94 XUVs
896 XUVs total
733 collection wire objects
896 potential space points
Neighbour search...
5878 tests to find 2570 neighbours
Iterating with no regularization...
Begin: 3.20942e+08
0 3.16094e+08
1 3.15722e+08
2 3.15722e+08
Now with regularization...
Begin: 3.08083e+08
0 3.08082e+08
17-Sep-2025 10:10:08 UTC Closed output file "np02vd_raw_run039388_0467_df-s05-d0_dw_0_20250916T230116_reco_stage1_20250917T101008_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 129.987 196.206 330.152 180.089 51.7756 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.4882e-05 0.000117979 0.000251859 0.000103846 4.22452e-05 19
produce:tpcrawdecoder:PDVDTPCReader 16.8613 20.5252 32.8179 19.0291 3.81116 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.389979 0.393346 0.397645 0.393782 0.0022524 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000248554 0.000574651 0.00368389 0.000355935 0.000752477 19
produce:ophit:OpHitFinder 0.000183345 0.000338143 0.000897629 0.000284929 0.00018403 19
produce:opflash:OpFlashFinderVerticalDrift 4.664e-05 9.65142e-05 0.000328453 7.4212e-05 7.05193e-05 19
produce:wclsdatavd:WireCellToolkit 54.7677 77.3315 100.441 75.9407 12.6187 19
produce:gaushit:GausHitFinder 1.03758 1.70213 2.511 1.74271 0.370577 19
produce:nhitsfilter:NumberOfHitsFilter 0.00023947 0.000386101 0.00068494 0.000357618 0.000102744 19
produce:reco3d:SpacePointSolver 9.396 17.0563 29.7502 16.1093 5.29887 19
produce:hitpdune:DisambigFromSpacePoints 0.149968 0.281441 0.620688 0.256265 0.108931 19
produce:pandora:StandardPandora 28.7748 71.4233 169.426 55.2932 37.0538 19
produce:pandoraTrack:LArPandoraTrackCreation 0.66503 1.54497 3.83989 1.37922 0.714678 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.023172 0.0406961 0.055443 0.0419596 0.0076922 19
[art]:TriggerResults:TriggerResultInserter 2.2644e-05 4.7038e-05 0.000102153 4.5538e-05 1.69036e-05 19
end_path:out1:RootOutput 8.182e-06 1.66835e-05 3.4892e-05 1.4342e-05 6.88499e-06 19
end_path:out1:RootOutput(write) 4.12455 5.8215 7.52009 5.85473 0.750984 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4852.86 MB
Peak resident set size usage (VmHWM): 2696.26 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0467_df-s05-d0_dw_0_20250916T230116_reco_stage1_20250917T101008_keepup.root
\tHists: np02vd_raw_run039388_0467_df-s05-d0_dw_0_20250916T230116_reco_stage1_20250917T101008_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0467_df-s05-d0_dw_0_20250916T230116_reco_stage1_20250917T101008_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0467_df-s05-d0_dw_0_20250916T230116_reco_stage1_20250917T101008_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": 1758103810.0,
"core.end_time": 1758103810.0,
"core.events": [
35916,
35920,
35924,
35928,
35932,
35936,
35940,
35944,
35948,
35952,
35956,
35960,
35964,
35968,
35972,
35976,
35980,
35984,
35988
],
"core.event_count": 19,
"core.first_event_number": 35916,
"core.last_event_number": 35988,
"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_0467_df-s05-d0_dw_0_20250916T230116.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0467_df-s05-d0_dw_0_20250916T230116_reco_stage1_20250917T101008_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": 1758103810.0,
"core.end_time": 1758103810.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_0467_df-s05-d0_dw_0_20250916T230116.hdf5"
}
]
} 