Jobsub ID 236737.95@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
] <FrameFanin:nfsp> EOS at call=45 with 8 
[18:26:45.293] D [  glue  ] frame sink sees EOS
[18:26:45.293] D [ pgraph ] <Pgrapher:> graph execution complete 
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.21 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.85 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.54 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.52 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.96 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.88 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.86 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.67 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.26 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.25 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.24 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.23 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.03 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:26:45.293] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[18:26:45.293] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[18:26:45.293] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[18:26:45.293] I [ timer  ] Timer: Total node execution : 67.57000118866563 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 56362 traces tagged "gauss"
FrameSaver: q=1.41346e+07 n=1186840 tag=gauss
wclsFrameSaver: saving 70602 traces tagged "wiener"
FrameSaver: q=1.51451e+07 n=1134919 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 508 XUs and 502 XVs -> 22 XUVs
C:0 T:1 652 XUs and 926 XVs -> 28 XUVs
C:0 T:2 776 XUs and 1192 XVs -> 37 XUVs
C:0 T:3 1652 XUs and 2349 XVs -> 112 XUVs
C:0 T:4 544 XUs and 739 XVs -> 21 XUVs
C:0 T:5 12701 XUs and 15989 XVs -> 798 XUVs
C:0 T:6 1386 XUs and 1875 XVs -> 152 XUVs
C:0 T:7 7778 XUs and 12404 XVs -> 459 XUVs
C:0 T:8 1149 XUs and 1702 XVs -> 60 XUVs
C:0 T:9 1823 XUs and 1844 XVs -> 91 XUVs
C:0 T:10 1534 XUs and 1667 XVs -> 87 XUVs
C:0 T:11 1196 XUs and 1324 XVs -> 49 XUVs
C:0 T:12 959 XUs and 677 XVs -> 41 XUVs
C:0 T:13 2619 XUs and 2958 XVs -> 168 XUVs
C:0 T:14 481 XUs and 574 XVs -> 19 XUVs
C:0 T:15 775 XUs and 917 XVs -> 47 XUVs
2191 XUVs total
1593 collection wire objects
2191 potential space points
Neighbour search...
40971 tests to find 13920 neighbours
Iterating with no regularization...
Begin: 5.6354e+09
0 5.4125e+09
1 5.39592e+09
2 5.39585e+09
Now with regularization...
Begin: 5.36323e+09
0 5.3632e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
03-Nov-2025 18:27:43 GMT  Closed output file "np02vd_raw_run040346_3612_df-s04-d3_dw_0_20251103T145036_reco_stage1_20251103T182743_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        266.135       409.954       580.907       384.458        87.03         23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      5.6171e-05    7.77422e-05   0.000117125   7.2606e-05    1.54122e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               173.037       291.481       465.13        270.525       78.1481        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.964003       1.73591       4.36181       1.5647       0.746196        23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000356281   0.000393856   0.000731484   0.000377342   7.3067e-05       23     
produce:ophit:OpHitFinder                       5.0975e-05    8.4468e-05    0.000477826   5.9245e-05    8.48826e-05      23     
produce:opflash:OpFlashFinderVerticalDrift      4.1716e-05    6.06047e-05   0.000281401   4.9852e-05    4.74624e-05      23     
produce:wclsdatavd:WireCellToolkit                52.8031       76.7438       124.983       67.5861       18.5845        23     
produce:gaushit:GausHitFinder                    0.832061       1.07503       1.52592       1.02087      0.189651        23     
produce:nhitsfilter:NumberOfHitsFilter          0.00021225    0.000353949   0.000533283   0.000341867   7.06466e-05      23     
produce:reco3d:SpacePointSolver                   5.70975       9.32245       15.1374       8.83195       2.40795        23     
produce:hitpdune:DisambigFromSpacePoints         0.0991112      0.15988      0.258462      0.147456      0.0439456       23     
produce:pandora:StandardPandora                   11.707        24.3669       88.4327       19.8948       15.2658        23     
produce:pandoraTrack:LArPandoraTrackCreation     0.479979      0.985809       2.07151      0.833988      0.451206        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0165895     0.0266586     0.0420971     0.0248851    0.00604578       23     
[art]:TriggerResults:TriggerResultInserter       1.841e-05    3.16576e-05   5.5366e-05     3.187e-05    6.74709e-06      23     
end_path:out1:RootOutput                         7.585e-06    9.62026e-06    2.285e-05     8.888e-06    2.94473e-06      23     
end_path:out1:RootOutput(write)                   3.57285       4.0145        5.36802       3.75092       0.48213        23     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 5119.51 MB
  Peak resident set size usage (VmHWM): 3076.22 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3612_df-s04-d3_dw_0_20251103T145036_reco_stage1_20251103T182743_keepup.root
\tHists: np02vd_raw_run040346_3612_df-s04-d3_dw_0_20251103T145036_reco_stage1_20251103T182748_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3612_df-s04-d3_dw_0_20251103T145036_reco_stage1_20251103T182743_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3612_df-s04-d3_dw_0_20251103T145036_reco_stage1_20251103T182743_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": 1762194468.0,
    "core.end_time": 1762194468.0,
    "core.events": [
      333251,
      333255,
      333259,
      333263,
      333267,
      333271,
      333275,
      333279,
      333283,
      333287,
      333291,
      333295,
      333299,
      333303,
      333307,
      333311,
      333315,
      333319,
      333323,
      333327,
      333331,
      333335,
      333339
    ],
    "core.event_count": 23,
    "core.first_event_number": 333251,
    "core.last_event_number": 333339,
    "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_3612_df-s04-d3_dw_0_20251103T145036.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3612_df-s04-d3_dw_0_20251103T145036_reco_stage1_20251103T182748_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": 1762194468.0,
    "core.end_time": 1762194468.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_3612_df-s04-d3_dw_0_20251103T145036.hdf5"
    }
  ]
}