Jobsub ID 242278.172@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
[11:46:55.526] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=47 anode=0
[11:46:55.526] D [ glue ] <FrameFanin:nfsp> EOS at call=47 with 8
[11:46:55.526] D [ glue ] frame sink sees EOS
[11:46:55.526] D [ pgraph ] <Pgrapher:> graph execution complete
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.43 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.27 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.08 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.89 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.86 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.78 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.75 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.71 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Aux::Resampler : 0.2 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Aux::Resampler : 0.2 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[11:46:55.526] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:46:55.526] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:46:55.526] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:46:55.526] I [ timer ] Timer: Total node execution : 56.62999997287989 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 32055 traces tagged "gauss"
FrameSaver: q=7.79819e+06 n=659705 tag=gauss
wclsFrameSaver: saving 39952 traces tagged "wiener"
FrameSaver: q=8.38022e+06 n=627320 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 52 XUs and 48 XVs -> 1 XUVs
C:0 T:1 1581 XUs and 1612 XVs -> 97 XUVs
C:0 T:2 299 XUs and 320 XVs -> 11 XUVs
C:0 T:3 24 XUs and 31 XVs -> 0 XUVs
C:0 T:4 308 XUs and 278 XVs -> 22 XUVs
C:0 T:5 859 XUs and 1070 XVs -> 65 XUVs
C:0 T:6 4567 XUs and 6349 XVs -> 366 XUVs
C:0 T:7 680 XUs and 1198 XVs -> 48 XUVs
C:0 T:8 1343 XUs and 3374 XVs -> 235 XUVs
C:0 T:9 1078 XUs and 1362 XVs -> 71 XUVs
C:0 T:10 1635 XUs and 2121 XVs -> 249 XUVs
C:0 T:11 760 XUs and 797 XVs -> 53 XUVs
C:0 T:12 917 XUs and 671 XVs -> 43 XUVs
C:0 T:13 495 XUs and 487 XVs -> 22 XUVs
C:0 T:14 396 XUs and 447 XVs -> 25 XUVs
C:0 T:15 508 XUs and 444 XVs -> 18 XUVs
1326 XUVs total
956 collection wire objects
1326 potential space points
Neighbour search...
23928 tests to find 8970 neighbours
Iterating with no regularization...
Begin: 4.73247e+09
0 4.63821e+09
1 4.63712e+09
Now with regularization...
Begin: 4.58036e+09
0 4.5803e+09
03-Nov-2025 11:47:19 GMT Closed output file "np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234_reco_stage1_20251103T114719_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 94.8754 139.917 305.867 125.389 46.2616 24
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 0.000117816 0.000139664 0.000201454 0.000131615 2.05546e-05 24
produce:tpcrawdecoder:PDVDTPCReader 16.4989 19.1751 23.2752 18.1477 2.34866 24
produce:triggerrawdecoder:PDVDTriggerReader4 0.738958 0.786946 0.910387 0.776602 0.0370783 24
produce:pdvddaphne:DAPHNEReaderPDVD 0.00106672 0.0011212 0.00170347 0.00109409 0.000122814 24
produce:ophit:OpHitFinder 0.000109738 0.000172038 0.00107656 0.000124407 0.000190296 24
produce:opflash:OpFlashFinderVerticalDrift 0.000106029 0.000144404 0.000656903 0.000123245 0.000107145 24
produce:wclsdatavd:WireCellToolkit 50.8491 71.3436 111.474 63.4856 16.2246 24
produce:gaushit:GausHitFinder 0.634125 1.18744 2.0688 1.08583 0.367011 24
produce:nhitsfilter:NumberOfHitsFilter 0.000243372 0.000377165 0.000654432 0.000356763 9.19414e-05 24
produce:reco3d:SpacePointSolver 5.00172 9.74024 18.1419 8.96524 3.31161 24
produce:hitpdune:DisambigFromSpacePoints 0.0717522 0.179179 0.464763 0.157027 0.0859974 24
produce:pandora:StandardPandora 8.86336 32.2786 146.77 21.5597 32.2136 24
produce:pandoraTrack:LArPandoraTrackCreation 0.41855 1.37739 3.78468 1.06561 0.955174 24
produce:pandoraGnocalo:GnocchiCalorimetry 0.0163289 0.0284313 0.0500613 0.0264579 0.00820855 24
[art]:TriggerResults:TriggerResultInserter 2.5834e-05 3.56967e-05 8.744e-05 3.33805e-05 1.13661e-05 24
end_path:out1:RootOutput 8.543e-06 1.09619e-05 2.6091e-05 9.7945e-06 3.629e-06 24
end_path:out1:RootOutput(write) 3.27733 3.75347 4.83584 3.69707 0.351748 24
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6411.86 MB
Peak resident set size usage (VmHWM): 4372.43 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234_reco_stage1_20251103T114719_keepup.root
\tHists: np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234_reco_stage1_20251103T114721_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234_reco_stage1_20251103T114719_keepup.root
Ran successfully
{
"name": "np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234_reco_stage1_20251103T114719_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_11_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": 1762170442.0,
"core.end_time": 1762170442.0,
"core.events": [
304132,
304136,
304140,
304144,
304148,
304152,
304156,
304160,
304164,
304168,
304172,
304176,
304180,
304184,
304188,
304192,
304196,
304200,
304204,
304208,
304212,
304216,
304220,
304224
],
"core.event_count": 24,
"core.first_event_number": 304132,
"core.last_event_number": 304224,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40346
],
"core.runs_subruns": [
4034600001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234_reco_stage1_20251103T114721_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_11_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": 1762170442.0,
"core.end_time": 1762170442.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40346
],
"core.runs_subruns": [
4034600001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040346_3295_df-s04-d0_dw_0_20251103T101234.hdf5"
}
]
} 