Jobsub ID 47125.78@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
] D [ aux ] <Resampler:resmp0> EOS at call=37
[21:17:48.964] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[21:17:48.964] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[21:17:48.964] D [ glue ] frame sink sees EOS
[21:17:48.964] D [ pgraph ] <Pgrapher:> graph execution complete
[21:17:48.964] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.44 sec
[21:17:48.964] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.29 sec
[21:17:48.964] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.77 sec
[21:17:48.964] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.73 sec
[21:17:48.964] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.46 sec
[21:17:48.964] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.89 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.82 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.8 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Aux::Resampler : 0.75 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Aux::Resampler : 0.73 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Aux::Resampler : 0.73 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Aux::Resampler : 0.72 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:17:48.965] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:17:48.965] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:17:48.965] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[21:17:48.965] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[21:17:48.965] I [ timer ] Timer: Total node execution : 79.21999987401068 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 59934 traces tagged "gauss"
FrameSaver: q=9.92588e+06 n=1260922 tag=gauss
wclsFrameSaver: saving 73146 traces tagged "wiener"
FrameSaver: q=1.03688e+07 n=1207511 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 4697 XUs and 4778 XVs -> 197 XUVs
C:0 T:1 3376 XUs and 3785 XVs -> 231 XUVs
C:0 T:2 2317 XUs and 1505 XVs -> 108 XUVs
C:0 T:3 796 XUs and 992 XVs -> 45 XUVs
C:0 T:4 180 XUs and 221 XVs -> 10 XUVs
C:0 T:5 951 XUs and 1022 XVs -> 25 XUVs
C:0 T:6 765 XUs and 882 XVs -> 67 XUVs
C:0 T:7 271 XUs and 282 XVs -> 13 XUVs
C:0 T:8 2183 XUs and 2945 XVs -> 153 XUVs
C:0 T:9 5543 XUs and 5630 XVs -> 229 XUVs
C:0 T:10 1141 XUs and 1334 XVs -> 61 XUVs
C:0 T:11 510 XUs and 640 XVs -> 33 XUVs
C:0 T:12 2850 XUs and 3356 XVs -> 166 XUVs
C:0 T:13 3786 XUs and 3910 XVs -> 285 XUVs
C:0 T:14 3435 XUs and 4525 XVs -> 167 XUVs
C:0 T:15 655 XUs and 465 XVs -> 43 XUVs
1833 XUVs total
1542 collection wire objects
1833 potential space points
Neighbour search...
18051 tests to find 8200 neighbours
Iterating with no regularization...
Begin: 4.86698e+08
0 4.70759e+08
1 4.70432e+08
Now with regularization...
Begin: 4.62529e+08
0 4.62497e+08
16-Sep-2025 21:19:18 BST Closed output file "np02vd_raw_run039388_0233_df-s05-d2_dw_0_20250916T180554_reco_stage1_20250916T201918_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 238.518 283.556 388.295 273.077 43.1399 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.8793e-05 7.53054e-05 0.000204724 6.7843e-05 3.11936e-05 19
produce:tpcrawdecoder:PDVDTPCReader 106.274 134.818 182.544 129.917 20.95 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.422256 0.488393 0.74637 0.4524 0.0790641 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000289595 0.000344256 0.000624242 0.00032076 8.03197e-05 19
produce:ophit:OpHitFinder 0.000108716 0.000218774 0.00105621 0.000141563 0.000237609 19
produce:opflash:OpFlashFinderVerticalDrift 3.6097e-05 5.67797e-05 0.000251579 4.261e-05 4.79237e-05 19
produce:wclsdatavd:WireCellToolkit 62.7897 78.156 111.146 74.169 12.0112 19
produce:gaushit:GausHitFinder 0.877703 1.42462 1.9526 1.40282 0.278548 19
produce:nhitsfilter:NumberOfHitsFilter 0.000330791 0.000468319 0.000727098 0.00041077 0.000114153 19
produce:reco3d:SpacePointSolver 7.92371 15.6866 25.9618 14.2654 4.7151 19
produce:hitpdune:DisambigFromSpacePoints 0.0936548 0.212707 0.410183 0.192541 0.0805468 19
produce:pandora:StandardPandora 12.9686 46.8186 93.7859 36.9935 22.6123 19
produce:pandoraTrack:LArPandoraTrackCreation 0.728237 1.61851 3.38724 1.4592 0.713557 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0212875 0.0295314 0.0456417 0.0268997 0.00710039 19
[art]:TriggerResults:TriggerResultInserter 2.3111e-05 3.9114e-05 9.5585e-05 3.6361e-05 1.47894e-05 19
end_path:out1:RootOutput 7.177e-06 1.11298e-05 3.2912e-05 9.029e-06 5.69624e-06 19
end_path:out1:RootOutput(write) 3.71769 4.25597 5.00051 4.21163 0.321174 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4819.68 MB
Peak resident set size usage (VmHWM): 2911.14 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0233_df-s05-d2_dw_0_20250916T180554_reco_stage1_20250916T201918_keepup.root
\tHists: np02vd_raw_run039388_0233_df-s05-d2_dw_0_20250916T180554_reco_stage1_20250916T201919_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0233_df-s05-d2_dw_0_20250916T180554_reco_stage1_20250916T201918_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0233_df-s05-d2_dw_0_20250916T180554_reco_stage1_20250916T201918_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": 1758053959.0,
"core.end_time": 1758053959.0,
"core.events": [
17982,
17986,
17990,
17994,
17998,
18002,
18006,
18010,
18014,
18018,
18022,
18026,
18030,
18034,
18038,
18042,
18046,
18050,
18054
],
"core.event_count": 19,
"core.first_event_number": 17982,
"core.last_event_number": 18054,
"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_0233_df-s05-d2_dw_0_20250916T180554.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0233_df-s05-d2_dw_0_20250916T180554_reco_stage1_20250916T201919_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": 1758053959.0,
"core.end_time": 1758053959.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_0233_df-s05-d2_dw_0_20250916T180554.hdf5"
}
]
} 