Jobsub ID 43648.23@dunegpschedd01.fnal.gov

Jobsub ID	43648.23@dunegpschedd01.fnal.gov
Workflow ID	2332
Stage ID	1
User name	ykermaid@fnal.gov
HTCondor Group	group_dune.prod.mcsim
Requested	Processors	1
	GPU	No
	RSS bytes	4193255424 (3999 MiB)
	Wall seconds limit	18000 (5 hours)
Submitted time	2025-09-09 09:14:58
Site	UK_Brunel
Entry	CMSHTPC_T2_UK_London_Brunel_dc2_22
Last heartbeat	2025-09-09 11:58:45
From worker node	Hostname	wn-b8-26-01.brunel.ac.uk
	cpuinfo	Intel(R) Xeon(R) CPU E5-2630 v3 @ 2.40GHz
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	4194304000 (4000 MiB)
	Wall seconds limit	171000 (47 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-09-09 10:22:41
Input files	vd-protodune:np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157.hdf5
Jobscript	Exit code	0
	Real time	1h (5679s)
	CPU time	1h (3750s = 66%)
	Max RSS bytes	2834280448 (2702 MiB)
Outputting started	2025-09-09 11:57:21
Output files	vd-protodune-det-reco:np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157_reco_stage1_20250909T115711_keepup.root
Finished	2025-09-09 11:58:45
Saved logs	justin-logs:43648.23-dunegpschedd01.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

mer: WireCell::SigProc::OmnibusSigProc : 10.14 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.63 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.38 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.72 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.54 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.54 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.23 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.66 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.43 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.43 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.42 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.4 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:55:54.606] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[12:55:54.606] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[12:55:54.606] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[12:55:54.606] I [ timer  ] Timer: Total node execution : 66.56000015884638 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 40516 traces tagged "gauss"
FrameSaver: q=8.61306e+06 n=922606 tag=gauss
wclsFrameSaver: saving 51304 traces tagged "wiener"
FrameSaver: q=9.10779e+06 n=878364 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 717 XUs and 897 XVs -> 39 XUVs
C:0 T:1 87 XUs and 151 XVs -> 8 XUVs
C:0 T:2 1412 XUs and 1110 XVs -> 42 XUVs
C:0 T:3 186 XUs and 223 XVs -> 9 XUVs
C:0 T:4 142 XUs and 222 XVs -> 11 XUVs
C:0 T:5 899 XUs and 942 XVs -> 49 XUVs
C:0 T:6 1078 XUs and 1637 XVs -> 73 XUVs
C:0 T:7 930 XUs and 1540 XVs -> 77 XUVs
C:0 T:8 6791 XUs and 9345 XVs -> 2573 XUVs
C:0 T:9 3756 XUs and 5441 XVs -> 852 XUVs
C:0 T:10 2938 XUs and 4731 XVs -> 855 XUVs
C:0 T:11 13136 XUs and 26705 XVs -> 4948 XUVs
C:0 T:12 11519 XUs and 25279 XVs -> 1864 XUVs
C:0 T:13 2231 XUs and 3666 XVs -> 672 XUVs
C:0 T:14 3391 XUs and 5562 XVs -> 1443 XUVs
C:0 T:15 2886 XUs and 2599 XVs -> 200 XUVs
13715 XUVs total
1981 collection wire objects
13715 potential space points
Neighbour search...
2192011 tests to find 888610 neighbours
Iterating with no regularization...
Begin: 3.27357e+09
0 3.11482e+09
1 3.10842e+09
2 3.10796e+09
Now with regularization...
Begin: 3.09523e+09
0 3.09496e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
09-Sep-2025 12:57:11 BST  Closed output file "np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157_reco_stage1_20250909T115711_keepup.root"

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        121.166       208.242       329.543       213.019       48.6373        27     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      4.3418e-05    7.83796e-05   0.000506471   5.3537e-05    8.80623e-05      27     
produce:tpcrawdecoder:PDVDTPCReader               35.1075       66.4131       149.092       49.5243       30.3628        27     
produce:triggerrawdecoder:PDVDTriggerReader4     0.0348765     0.0406338     0.0716783     0.0358392    0.00890211       27     
produce:pdvddaphne:DAPHNEReaderPDVD               5.58161       9.65828       19.2651       8.68817       3.44537        27     
produce:ophit:OpHitFinder                        0.0302742     0.0397572     0.0463976     0.0398897     0.0040214       27     
produce:opflash:OpFlashFinderVerticalDrift      0.00695279     0.0136312     0.0298045     0.0120016    0.00521604       27     
produce:wclsdatavd:WireCellToolkit                45.1371       64.9125       101.666       63.794        11.1401        27     
produce:gaushit:GausHitFinder                    0.799029       1.26972       1.90214       1.2245       0.288421        27     
produce:nhitsfilter:NumberOfHitsFilter          0.00012783    0.000236625   0.000370612   0.000230074   7.14227e-05      27     
produce:reco3d:SpacePointSolver                   4.71183       11.1453       18.8785       10.782        3.37293        27     
produce:hitpdune:DisambigFromSpacePoints         0.0723616     0.182943      0.351147      0.171791      0.0634894       27     
produce:pandora:StandardPandora                    18.23        48.5923        101.1        41.4082       23.4244        27     
produce:pandoraTrack:LArPandoraTrackCreation     0.340879      0.790026       1.22786      0.773103      0.249472        27     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0145722     0.0247422     0.0346277     0.0246337    0.00489756       27     
[art]:TriggerResults:TriggerResultInserter      1.5047e-05    2.10628e-05   5.2639e-05    1.7489e-05    8.39025e-06      27     
end_path:out1:RootOutput                         2.997e-06    6.2683e-06    2.0754e-05     6.67e-06     3.58076e-06      27     
end_path:out1:RootOutput(write)                   4.23485       5.13527       7.52307       5.01422      0.756031        27     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 4749.84 MB
  Peak resident set size usage (VmHWM): 2834.28 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157_reco_stage1_20250909T115711_keepup.root
\tHists: np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157_reco_stage1_20250909T115712_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157_reco_stage1_20250909T115711_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157_reco_stage1_20250909T115711_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": 1757419032.0,
    "core.end_time": 1757419032.0,
    "core.events": [
      94460,
      94480,
      94500,
      94520,
      94540,
      94560,
      94580,
      94600,
      94620,
      94640,
      94660,
      94680,
      94700,
      94720,
      94740,
      94760,
      94780,
      94800,
      94820,
      94840,
      94860,
      94880,
      94900,
      94920,
      94940,
      94960,
      94980
    ],
    "core.event_count": 27,
    "core.first_event_number": 94460,
    "core.last_event_number": 94980,
    "core.data_stream": "physics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39344
    ],
    "core.runs_subruns": [
      3934400001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157_reco_stage1_20250909T115712_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": 1757419032.0,
    "core.end_time": 1757419032.0,
    "core.data_stream": "physics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39344
    ],
    "core.runs_subruns": [
      3934400001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039344_0177_df-s01-d2_dw_0_20250908T154157.hdf5"
    }
  ]
}