Jobsub ID 209528.1@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
0 
[15:20:18.522] D [  aux   ] <Resampler:resmp0> EOS at call=81 
[15:20:18.522] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0 
[15:20:18.522] D [  glue  ] <FrameFanin:nfsp> EOS at call=81 with 8 
[15:20:18.522] D [  glue  ] frame sink sees EOS
[15:20:18.522] D [ pgraph ] <Pgrapher:> graph execution complete 
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.59 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.37 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.54 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.36 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.24 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.23 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.23 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.22 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:20:18.523] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[15:20:18.523] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:20:18.523] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[15:20:18.523] I [ timer  ] Timer: Total node execution : 28.830000134184957 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 25171 traces tagged "gauss"
FrameSaver: q=4.1064e+06 n=599792 tag=gauss
wclsFrameSaver: saving 31433 traces tagged "wiener"
FrameSaver: q=4.50017e+06 n=583223 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 647 XUs and 558 XVs -> 17 XUVs
C:0 T:1 9 XUs and 17 XVs -> 0 XUVs
C:0 T:2 1084 XUs and 1299 XVs -> 48 XUVs
C:0 T:3 1579 XUs and 1477 XVs -> 62 XUVs
C:0 T:4 1541 XUs and 1351 XVs -> 91 XUVs
C:0 T:5 17623 XUs and 16256 XVs -> 1384 XUVs
C:0 T:6 4001 XUs and 4103 XVs -> 177 XUVs
C:0 T:7 4187 XUs and 4031 XVs -> 173 XUVs
1952 XUVs total
1094 collection wire objects
1952 potential space points
Neighbour search...
69526 tests to find 17698 neighbours
Iterating with no regularization...
Begin: 1.86297e+09
0 1.77631e+09
1 1.77254e+09
2 1.7724e+09
Now with regularization...
Begin: 1.73232e+09
0 1.7322e+09
30-Sep-2025 15:20:53 UTC  Closed output file "np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937_reco_stage1_20250930T152053_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        41.6535       113.496       1382.22       59.0453       207.766        41     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.4347e-05    0.000136504   0.000315304   0.000118608   5.98696e-05      41     
produce:tpcrawdecoder:PDVDTPCReader               7.16425       10.4383        23.15        9.16277       4.0994         41     
produce:triggerrawdecoder:PDVDTriggerReader4     0.392833      0.439206      0.793746      0.404176      0.0969052       41     
produce:pdvddaphne:DAPHNEReaderPDVD               2.37205       3.07597       5.15445       2.89976      0.579532        41     
produce:ophit:OpHitFinder                        0.0261049     0.040026      0.0544763     0.0410537    0.00614471       41     
produce:opflash:OpFlashFinderVerticalDrift      0.00392161     0.0119521     0.0269225     0.0110441    0.00539143       41     
produce:wclsdatavd:WireCellToolkit                 20.37        31.8615       66.4897       28.2113       11.5431        41     
produce:gaushit:GausHitFinder                    0.277374      0.586452       1.39231      0.530045      0.228712        41     
produce:nhitsfilter:NumberOfHitsFilter          8.6129e-05    0.000284314   0.00126798    0.000195153   0.000251467      41     
produce:reco3d:SpacePointSolver                   1.6046        5.87225       23.5806       4.67845       4.16669        41     
produce:hitpdune:DisambigFromSpacePoints         0.0228187     0.0985645     0.645387      0.0575164     0.122841        41     
produce:pandora:StandardPandora                   3.60425       58.4066       1294.13       13.9219       200.025        41     
produce:pandoraTrack:LArPandoraTrackCreation     0.0637164     0.504674       5.1992       0.270454      0.847943        41     
produce:pandoraGnocalo:GnocchiCalorimetry       0.00464437     0.0147201     0.0365421     0.0143469    0.00619464       41     
[art]:TriggerResults:TriggerResultInserter      1.2819e-05    3.49197e-05   9.7546e-05    3.0906e-05    1.65979e-05      41     
end_path:out1:RootOutput                         3.896e-06    8.69166e-06   2.2985e-05     7.932e-06    3.62208e-06      41     
end_path:out1:RootOutput(write)                   1.64174       2.11107       2.84926       2.07552      0.316374        41     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 6171.46 MB
  Peak resident set size usage (VmHWM): 3900.81 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937_reco_stage1_20250930T152053_keepup.root
\tHists: np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937_reco_stage1_20250930T152053_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937_reco_stage1_20250930T152053_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937_reco_stage1_20250930T152053_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": 1759245655.0,
    "core.end_time": 1759245655.0,
    "core.events": [
      153776,
      153780,
      153784,
      153788,
      153792,
      153796,
      153800,
      153804,
      153808,
      153812,
      153816,
      153820,
      153824,
      153828,
      153832,
      153836,
      153840,
      153844,
      153848,
      153852,
      153856,
      153860,
      153864,
      153868,
      153872,
      153876,
      153880,
      153884,
      153888,
      153892,
      153896,
      153900,
      153904,
      153908,
      153912,
      153916,
      153920,
      153924,
      153928,
      153932,
      153936
    ],
    "core.event_count": 41,
    "core.first_event_number": 153776,
    "core.last_event_number": 153936,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39663
    ],
    "core.runs_subruns": [
      3966300001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937_reco_stage1_20250930T152053_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": 1759245655.0,
    "core.end_time": 1759245655.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39663
    ],
    "core.runs_subruns": [
      3966300001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039663_0939_df-s04-d0_dw_0_20250927T142937.hdf5"
    }
  ]
}