Jobsub ID 48913.9@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
79
[20:42:42.499] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=79 anode=1
[20:42:42.499] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[20:42:42.499] D [ aux ] <Resampler:resmp0> EOS at call=79
[20:42:42.499] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[20:42:42.499] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[20:42:42.499] D [ glue ] frame sink sees EOS
[20:42:42.499] D [ pgraph ] <Pgrapher:> graph execution complete
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.42 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.9 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.81 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.46 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Aux::Resampler : 1.58 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Aux::Resampler : 1.56 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Aux::Resampler : 1.51 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Aux::Resampler : 1.48 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:42:42.499] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:42:42.499] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:42:42.499] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:42:42.499] I [ timer ] Timer: Total node execution : 58.75000014714897 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 14750 traces tagged "gauss"
FrameSaver: q=1.81081e+06 n=327492 tag=gauss
wclsFrameSaver: saving 18062 traces tagged "wiener"
FrameSaver: q=1.89752e+06 n=318161 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 498 XUs and 534 XVs -> 33 XUVs
C:0 T:1 197 XUs and 161 XVs -> 16 XUVs
C:0 T:2 529 XUs and 545 XVs -> 19 XUVs
C:0 T:3 382 XUs and 874 XVs -> 12 XUVs
C:0 T:4 184 XUs and 221 XVs -> 5 XUVs
C:0 T:5 2216 XUs and 2277 XVs -> 144 XUVs
C:0 T:6 346 XUs and 271 XVs -> 5 XUVs
C:0 T:7 480 XUs and 423 XVs -> 14 XUVs
248 XUVs total
200 collection wire objects
248 potential space points
Neighbour search...
2940 tests to find 1324 neighbours
Iterating with no regularization...
Begin: 5.01952e+07
0 4.86678e+07
1 4.85691e+07
2 4.85662e+07
Now with regularization...
Begin: 4.77888e+07
0 4.7788e+07
18-Sep-2025 20:43:01 BST Closed output file "np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501_reco_stage1_20250918T194301_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 81.2066 140.447 350.437 129.974 48.883 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.2187e-05 9.54816e-05 0.000306051 8.986e-05 3.55463e-05 40
produce:tpcrawdecoder:PDVDTPCReader 12.2321 20.286 31.054 19.2355 5.05004 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.277528 0.29443 0.426677 0.279983 0.0325168 40
produce:pdvddaphne:DAPHNEReaderPDVD 5.76464 7.97028 10.9308 7.87167 1.17253 40
produce:ophit:OpHitFinder 0.0459609 0.068841 0.0821932 0.0695255 0.00656142 40
produce:opflash:OpFlashFinderVerticalDrift 0.00719066 0.0189782 0.0313261 0.0189518 0.00452427 40
produce:wclsdatavd:WireCellToolkit 41.2801 61.6608 133.526 54.4094 17.0203 40
produce:gaushit:GausHitFinder 0.470414 1.02744 1.69799 1.00561 0.242741 40
produce:nhitsfilter:NumberOfHitsFilter 0.000160081 0.000321653 0.000497935 0.000308876 7.50951e-05 40
produce:reco3d:SpacePointSolver 2.52719 7.20064 15.3459 6.74896 2.72952 40
produce:hitpdune:DisambigFromSpacePoints 0.0294612 0.148283 0.470247 0.137876 0.0845523 40
produce:pandora:StandardPandora 4.7055 37.6531 226.209 29.287 37.0906 40
produce:pandoraTrack:LArPandoraTrackCreation 0.167905 0.807701 2.22749 0.672596 0.488214 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.0123059 0.0258377 0.0439313 0.0255339 0.00653454 40
[art]:TriggerResults:TriggerResultInserter 2.0158e-05 4.04145e-05 0.000100526 3.9409e-05 1.18006e-05 40
end_path:out1:RootOutput 5.333e-06 8.52697e-06 3.0807e-05 7.925e-06 3.85201e-06 40
end_path:out1:RootOutput(write) 2.58976 3.25683 3.95952 3.3077 0.390154 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4749.18 MB
Peak resident set size usage (VmHWM): 2857.9 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501_reco_stage1_20250918T194301_keepup.root
\tHists: np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501_reco_stage1_20250918T194302_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501_reco_stage1_20250918T194301_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501_reco_stage1_20250918T194301_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": 1758224583.0,
"core.end_time": 1758224583.0,
"core.events": [
244,
250,
256,
262,
268,
274,
280,
286,
292,
298,
304,
310,
316,
322,
328,
334,
340,
346,
352,
358,
364,
370,
376,
382,
388,
394,
400,
406,
412,
418,
424,
430,
436,
442,
448,
454,
460,
466,
472,
478
],
"core.event_count": 40,
"core.first_event_number": 244,
"core.last_event_number": 478,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501_reco_stage1_20250918T194302_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": 1758224583.0,
"core.end_time": 1758224583.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0001_df-s05-d4_dw_0_20250918T174501.hdf5"
}
]
} 