Jobsub ID 40551.130@dunegpschedd02.fnal.gov

Jobsub ID	40551.130@dunegpschedd02.fnal.gov
Workflow ID	2657
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-16 17:44:13
Site	UK_Durham
Entry	DUNE_UK_SGridDurham_ce4
Last heartbeat	2025-09-16 19:35:32
From worker node	Hostname	n117.dur.scotgrid.ac.uk
	cpuinfo	Intel(R) Xeon(R) CPU E5-2630 v4 @ 2.20GHz
	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-16 17:45:55
Input files	vd-protodune:np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745.hdf5
Jobscript	Exit code	0
	Real time	1h (6224s)
	CPU time	1h (4485s = 72%)
	Max RSS bytes	3170050048 (3023 MiB)
Outputting started	2025-09-16 19:29:40
Output files	vd-protodune-det-reco:np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745_reco_stage1_20250916T192925_keepup.root
Finished	2025-09-16 19:35:32
Saved logs	justin-logs:40551.130-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

cution complete 
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 18.6 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 16.1 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.75 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.14 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.4 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.65 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.2 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.12 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.29 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.25 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.25 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Aux::Resampler : 1.23 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.06 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.03 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.03 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:25:16.965] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:25:16.965] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:25:16.965] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:25:16.965] I [ timer  ] Timer: Total node execution : 120.14000001549721 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 71227 traces tagged "gauss"
FrameSaver: q=1.34432e+07 n=1538831 tag=gauss
wclsFrameSaver: saving 87657 traces tagged "wiener"
FrameSaver: q=1.42982e+07 n=1480428 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1302 XUs and 1380 XVs -> 69 XUVs
C:0 T:1 776 XUs and 841 XVs -> 29 XUVs
C:0 T:2 1434 XUs and 1319 XVs -> 38 XUVs
C:0 T:3 852 XUs and 898 XVs -> 57 XUVs
C:0 T:4 1659 XUs and 2230 XVs -> 74 XUVs
C:0 T:5 12675 XUs and 16261 XVs -> 958 XUVs
C:0 T:6 4376 XUs and 5182 XVs -> 162 XUVs
C:0 T:7 1345 XUs and 1942 XVs -> 57 XUVs
C:0 T:8 11486 XUs and 26244 XVs -> 4643 XUVs
C:0 T:9 13493 XUs and 22704 XVs -> 1761 XUVs
C:0 T:10 3569 XUs and 4273 XVs -> 960 XUVs
C:0 T:11 2371 XUs and 2541 XVs -> 101 XUVs
C:0 T:12 846 XUs and 944 XVs -> 53 XUVs
C:0 T:13 677 XUs and 868 XVs -> 74 XUVs
C:0 T:14 5012 XUs and 6139 XVs -> 162 XUVs
C:0 T:15 13997 XUs and 25294 XVs -> 2690 XUVs
11888 XUVs total
2649 collection wire objects
11888 potential space points
Neighbour search...
1536308 tests to find 605564 neighbours
Iterating with no regularization...
Begin: 1.87973e+09
0 1.53895e+09
1 1.50563e+09
2 1.50358e+09
3 1.50291e+09
Now with regularization...
Begin: 1.48028e+09
0 1.47989e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
16-Sep-2025 20:29:25 BST  Closed output file "np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745_reco_stage1_20250916T192925_keepup.root"

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        120.174       307.277       461.783       311.084       65.0276        20     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.6799e-05    9.47084e-05   0.000213717   8.0398e-05    3.43555e-05      20     
produce:tpcrawdecoder:PDVDTPCReader               33.2394       90.3281       110.576       92.6471       13.8765        20     
produce:triggerrawdecoder:PDVDTriggerReader4     0.515603      0.548921      0.662774      0.535239      0.0381172       20     
produce:pdvddaphne:DAPHNEReaderPDVD             0.00041219    0.000476687   0.000829509   0.000450635   9.0617e-05       20     
produce:ophit:OpHitFinder                       0.000140127   0.000219075   0.000871523   0.00015925    0.00015982       20     
produce:opflash:OpFlashFinderVerticalDrift      5.8763e-05    8.46042e-05   0.000349708   6.2447e-05    6.64182e-05      20     
produce:wclsdatavd:WireCellToolkit                55.7852       100.273       121.491       100.638       13.2215        20     
produce:gaushit:GausHitFinder                     1.0527        1.97784       2.93861       2.03191      0.434875        20     
produce:nhitsfilter:NumberOfHitsFilter          0.00024069    0.000491383   0.000787747   0.000488465   0.000121587      20     
produce:reco3d:SpacePointSolver                   7.48177       18.0424       33.4595       18.1762       5.67107        20     
produce:hitpdune:DisambigFromSpacePoints         0.137508       0.29915      0.630205      0.295624      0.113475        20     
produce:pandora:StandardPandora                   18.5124       86.6829        195.9        87.8577       38.5843        20     
produce:pandoraTrack:LArPandoraTrackCreation     0.847577       3.03553       5.88689       2.73784       1.4288         20     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0187798     0.045282      0.0671764     0.0454635     0.0115201       20     
[art]:TriggerResults:TriggerResultInserter      3.2222e-05    5.20713e-05   0.000108342   4.98185e-05   1.47301e-05      20     
end_path:out1:RootOutput                         8.006e-06    1.15764e-05   3.1497e-05    1.0098e-05    4.95181e-06      20     
end_path:out1:RootOutput(write)                   1.80592       5.99236       6.74078       6.19785      0.988113        20     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5050.2 MB
  Peak resident set size usage (VmHWM): 3163.82 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745_reco_stage1_20250916T192925_keepup.root
\tHists: np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745_reco_stage1_20250916T192928_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745_reco_stage1_20250916T192925_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745_reco_stage1_20250916T192925_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": 1758050968.0,
    "core.end_time": 1758050968.0,
    "core.events": [
      15069,
      15073,
      15077,
      15081,
      15085,
      15089,
      15093,
      15097,
      15101,
      15105,
      15109,
      15113,
      15117,
      15121,
      15125,
      15129,
      15133,
      15137,
      15141,
      15145
    ],
    "core.event_count": 20,
    "core.first_event_number": 15069,
    "core.last_event_number": 15145,
    "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_0195_df-s05-d1_dw_0_20250916T171745.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run039388_0195_df-s05-d1_dw_0_20250916T171745_reco_stage1_20250916T192928_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": 1758050968.0,
    "core.end_time": 1758050968.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_0195_df-s05-d1_dw_0_20250916T171745.hdf5"
    }
  ]
}