Jobsub ID 242278.126@dunegpschedd01.fnal.gov

Jobsub ID	242278.126@dunegpschedd01.fnal.gov
Workflow ID	9538
Stage ID	1
User name	ykermaid@fnal.gov
HTCondor Group	group_dune.prod_mcsim
Requested	Processors	2
	GPU	No
	RSS bytes	4193255424 (3999 MiB)
	Wall seconds limit	18000 (5 hours)
Submitted time	2025-11-03 10:40:44
Site	UK_Oxford
Entry	DUNE_UK_SGrid_Oxford_arc01
Last heartbeat	2025-11-03 12:32:52
From worker node	Hostname	t2wn013.physics.ox.ac.uk
	cpuinfo	AMD EPYC 7713P 64-Core Processor
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	2
	RSS bytes	4194304000 (4000 MiB)
	Wall seconds limit	257400 (71 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-11-03 10:43:36
Input files	vd-protodune:np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135.hdf5
Jobscript	Exit code	0
	Real time	1h (6361s)
	CPU time	1h (4507s = 70%)
	Max RSS bytes	4078817280 (3889 MiB)
Outputting started	2025-11-03 12:29:38
Output files	vd-protodune-det-reco:np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135_reco_stage1_20251103T122921_keepup.root
Finished	2025-11-03 12:32:52
Saved logs	justin-logs:242278.126-dunegpschedd01.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

te 
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 46.58 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.9 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.84 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.55 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.43 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.01 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.66 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.55 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.32 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.31 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.31 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.3 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[12:26:27.649] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:26:27.649] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[12:26:27.649] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[12:26:27.649] I [ timer  ] Timer: Total node execution : 140.80000237375498 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 50884 traces tagged "gauss"
FrameSaver: q=2.20618e+07 n=1308464 tag=gauss
wclsFrameSaver: saving 65509 traces tagged "wiener"
FrameSaver: q=2.35339e+07 n=1252724 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1936 XUs and 2311 XVs -> 117 XUVs
C:0 T:1 642 XUs and 602 XVs -> 33 XUVs
C:0 T:2 339 XUs and 189 XVs -> 8 XUVs
C:0 T:3 80 XUs and 103 XVs -> 0 XUVs
C:0 T:4 353 XUs and 345 XVs -> 9 XUVs
C:0 T:5 55042 XUs and 106263 XVs -> 5190 XUVs
C:0 T:6 667 XUs and 586 XVs -> 26 XUVs
C:0 T:7 3127 XUs and 3234 XVs -> 139 XUVs
C:0 T:8 1043 XUs and 1233 XVs -> 86 XUVs
C:0 T:9 602 XUs and 825 XVs -> 31 XUVs
C:0 T:10 2477 XUs and 3001 XVs -> 117 XUVs
C:0 T:11 724 XUs and 904 XVs -> 54 XUVs
C:0 T:12 1057 XUs and 958 XVs -> 109 XUVs
C:0 T:13 308 XUs and 1116 XVs -> 40 XUVs
C:0 T:14 1537 XUs and 1696 XVs -> 84 XUVs
C:0 T:15 354 XUs and 617 XVs -> 36 XUVs
6079 XUVs total
2755 collection wire objects
6079 potential space points
Neighbour search...
285581 tests to find 59132 neighbours
Iterating with no regularization...
Begin: 3.82327e+11
0 3.70747e+11
1 3.69988e+11
2 3.69981e+11
Now with regularization...
Begin: 3.68991e+11
0 3.68989e+11
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
03-Nov-2025 12:29:21 GMT  Closed output file "np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135_reco_stage1_20251103T122921_keepup.root"

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        177.695       270.704       402.681       246.218       66.3653        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.8743e-05    9.55756e-05   0.000193013   8.9583e-05    2.32502e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               46.6436       77.033        145.171       67.1951       28.2864        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.567223      0.690177      0.902827      0.675632      0.100374        23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000441554   0.000536364   0.00114728    0.00051189    0.000134634      23     
produce:ophit:OpHitFinder                        7.776e-05    0.000134731   0.000896954   9.4072e-05    0.000163576      23     
produce:opflash:OpFlashFinderVerticalDrift      6.6528e-05    0.000105605   0.000607365   7.6167e-05    0.000108304      23     
produce:wclsdatavd:WireCellToolkit                74.9487       107.946       175.576       87.5068       34.2076        23     
produce:gaushit:GausHitFinder                     1.58072       2.23824       3.94684       2.09734      0.596824        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000311663   0.000415313   0.000664685   0.000406747   9.38204e-05      23     
produce:reco3d:SpacePointSolver                   11.4977       17.9064       31.7298       16.8536       4.68893        23     
produce:hitpdune:DisambigFromSpacePoints         0.175371      0.313503      0.619085      0.311103      0.106978        23     
produce:pandora:StandardPandora                   21.5087       55.7089       137.902       50.023        31.4325        23     
produce:pandoraTrack:LArPandoraTrackCreation      0.85212       1.59343       4.09082       1.40735      0.685964        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0290904     0.0569193     0.0922597     0.0557398     0.0127348       23     
[art]:TriggerResults:TriggerResultInserter       2.617e-05    4.37687e-05   9.9813e-05    3.8805e-05    1.54757e-05      23     
end_path:out1:RootOutput                         4.659e-06    1.07727e-05   5.9486e-05     6.573e-06    1.22089e-05      23     
end_path:out1:RootOutput(write)                   5.6339        7.13676       8.2245        7.09306       0.55875        23     
==================================================================================================================================

====================================================================================================
MemoryTracker summary (base-10 MB units used)

  Peak virtual memory usage (VmPeak)  : 6159.67 MB
  Peak resident set size usage (VmHWM): 4078.82 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135_reco_stage1_20251103T122921_keepup.root
\tHists: np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135_reco_stage1_20251103T122921_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135_reco_stage1_20251103T122921_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135_reco_stage1_20251103T122921_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": 1762172962.0,
    "core.end_time": 1762172962.0,
    "core.events": [
      302971,
      302975,
      302979,
      302983,
      302987,
      302991,
      302995,
      302999,
      303003,
      303007,
      303011,
      303015,
      303019,
      303023,
      303027,
      303031,
      303035,
      303039,
      303043,
      303047,
      303051,
      303055,
      303059
    ],
    "core.event_count": 23,
    "core.first_event_number": 302971,
    "core.last_event_number": 303059,
    "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_3283_df-s04-d3_dw_0_20251103T100135.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3283_df-s04-d3_dw_0_20251103T100135_reco_stage1_20251103T122921_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": 1762172962.0,
    "core.end_time": 1762172962.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_3283_df-s04-d3_dw_0_20251103T100135.hdf5"
    }
  ]
}