Jobsub ID 41150.35@dunegpschedd02.fnal.gov

Jobsub ID	41150.35@dunegpschedd02.fnal.gov
Workflow ID	2815
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-17 18:11:32
Site	UK_QMUL
Entry	DUNE_UK_London_QMUL_arcce03
Last heartbeat	2025-09-17 21:27:51
From worker node	Hostname	cn119.htc.esc.qmul
	cpuinfo	Intel(R) Xeon(R) Gold 6248R CPU @ 3.00GHz
	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-17 19:05:46
Input files	vd-protodune:np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154.hdf5
Jobscript	Exit code	0
	Real time	2h (8125s)
	CPU time	1h (5967s = 73%)
	Max RSS bytes	3357184000 (3201 MiB)
Outputting started	2025-09-17 21:21:13
Output files	vd-protodune-det-reco:np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154_reco_stage1_20250917T212051_keepup.root
Finished	2025-09-17 21:27:51
Saved logs	justin-logs:41150.35-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

gProc::OmnibusSigProc : 19.15 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 18.33 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 16.86 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.97 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.96 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.77 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.49 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.48 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.46 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.46 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.45 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.07 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.02 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:13:23.518] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:13:23.518] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[22:13:23.518] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[22:13:23.518] I [ timer  ] Timer: Total node execution : 135.78000128641725 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 60285 traces tagged "gauss"
FrameSaver: q=1.21728e+07 n=1473008 tag=gauss
wclsFrameSaver: saving 74148 traces tagged "wiener"
FrameSaver: q=1.31816e+07 n=1421876 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 298 XUs and 477 XVs -> 4 XUVs
C:0 T:1 494 XUs and 689 XVs -> 21 XUVs
C:0 T:2 891 XUs and 1530 XVs -> 55 XUVs
C:0 T:3 219 XUs and 399 XVs -> 21 XUVs
C:0 T:4 161 XUs and 155 XVs -> 2 XUVs
C:0 T:5 177 XUs and 260 XVs -> 15 XUVs
C:0 T:6 272 XUs and 269 XVs -> 9 XUVs
C:0 T:7 2418 XUs and 2606 XVs -> 83 XUVs
C:0 T:8 18514 XUs and 47232 XVs -> 7485 XUVs
C:0 T:9 9531 XUs and 15235 XVs -> 2683 XUVs
C:0 T:10 9934 XUs and 19194 XVs -> 4131 XUVs
C:0 T:11 12618 XUs and 21975 XVs -> 4520 XUVs
C:0 T:12 11476 XUs and 22068 XVs -> 2056 XUVs
C:0 T:13 17808 XUs and 33023 XVs -> 4432 XUVs
C:0 T:14 18282 XUs and 41915 XVs -> 6518 XUVs
C:0 T:15 8456 XUs and 7946 XVs -> 444 XUVs
32479 XUVs total
2888 collection wire objects
32479 potential space points
Neighbour search...
4944919 tests to find 2067290 neighbours
Iterating with no regularization...
Begin: 7.73673e+08
0 6.67899e+08
1 6.62013e+08
2 6.60789e+08
3 6.60345e+08
Now with regularization...
Begin: 6.44577e+08
0 6.44061e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 22:20:51 BST  Closed output file "np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154_reco_stage1_20250917T212051_keepup.root"

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        267.951       413.016       622.656       394.698       116.911        19     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.5738e-05    0.000109766   0.000252099    9.797e-05    4.13802e-05      19     
produce:tpcrawdecoder:PDVDTPCReader               68.9195       105.814       155.972       96.7544       24.5666        19     
produce:triggerrawdecoder:PDVDTriggerReader4     0.281508      0.319225      0.426445      0.302139      0.0392501       19     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000424722   0.000507091    0.0010081    0.000454901   0.000150364      19     
produce:ophit:OpHitFinder                       0.000151363   0.000252286   0.00117473    0.000203146   0.000219624      19     
produce:opflash:OpFlashFinderVerticalDrift      6.7785e-05    0.000102973   0.000491449   7.9872e-05    9.24654e-05      19     
produce:wclsdatavd:WireCellToolkit                80.8901       122.972       152.45        120.807       19.5099        19     
produce:gaushit:GausHitFinder                     1.05162       2.44184       4.04381       2.25832      0.866223        19     
produce:nhitsfilter:NumberOfHitsFilter          0.000366719   0.000772897   0.00113704    0.000788551   0.000211102      19     
produce:reco3d:SpacePointSolver                   6.92377       22.3062       44.789        18.4458       9.93699        19     
produce:hitpdune:DisambigFromSpacePoints         0.127113      0.571719       1.38076       0.51366      0.337654        19     
produce:pandora:StandardPandora                   31.6555       147.118       314.554       103.628       94.0296        19     
produce:pandoraTrack:LArPandoraTrackCreation     0.751744       4.62021       10.9152       3.81159       2.75801        19     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0201649     0.0568852     0.100772      0.0537159     0.0234376       19     
[art]:TriggerResults:TriggerResultInserter      3.4099e-05    5.44651e-05   0.000141275   4.9916e-05    2.25423e-05      19     
end_path:out1:RootOutput                         6.482e-06    1.26273e-05   4.7963e-05    1.0791e-05    8.65241e-06      19     
end_path:out1:RootOutput(write)                   4.54882       6.72686       8.51189       7.2066        1.31748        19     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5245.54 MB
  Peak resident set size usage (VmHWM): 3357.18 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154_reco_stage1_20250917T212051_keepup.root
\tHists: np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154_reco_stage1_20250917T212102_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154_reco_stage1_20250917T212051_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154_reco_stage1_20250917T212051_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": 1758144062.0,
    "core.end_time": 1758144062.0,
    "core.events": [
      26224,
      26228,
      26232,
      26236,
      26240,
      26244,
      26248,
      26252,
      26256,
      26260,
      26264,
      26268,
      26272,
      26276,
      26280,
      26284,
      26288,
      26292,
      26296
    ],
    "core.event_count": 19,
    "core.first_event_number": 26224,
    "core.last_event_number": 26296,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39388
    ],
    "core.runs_subruns": [
      3938800001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154_reco_stage1_20250917T212102_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": 1758144062.0,
    "core.end_time": 1758144062.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39388
    ],
    "core.runs_subruns": [
      3938800001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039388_0341_df-s05-d0_dw_0_20250916T202154.hdf5"
    }
  ]
}