Jobsub ID 236682.5@dunegpschedd02.fnal.gov

Jobsub ID	236682.5@dunegpschedd02.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 12:56:56
Site	UK_Bristol
Entry	CMSHTPC_T2_UK_SGrid_Bristol_lcgce02
Last heartbeat	2025-11-03 14:58:49
From worker node	Hostname	hd70.dice.priv
	cpuinfo	AMD EPYC 7551P 32-Core Processor
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	2
	RSS bytes	4194304000 (4000 MiB)
	Wall seconds limit	259200 (72 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-11-03 13:13:11
Input files	vd-protodune:np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120.hdf5
Jobscript	Exit code	0
	Real time	1h (6184s)
	CPU time	1h (4136s = 66%)
	Max RSS bytes	3829051392 (3651 MiB)
Outputting started	2025-11-03 14:56:16
Output files	vd-protodune-det-reco:np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120_reco_stage1_20251103T145604_keepup.root
Finished	2025-11-03 14:58:49
Saved logs	justin-logs:236682.5-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

complete 
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.01 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.92 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.14 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.51 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.49 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.08 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.94 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.64 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.33 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.33 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.32 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.31 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:55:08.123] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[14:55:08.123] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[14:55:08.123] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[14:55:08.123] I [ timer  ] Timer: Total node execution : 79.0900005158037 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 42062 traces tagged "gauss"
FrameSaver: q=1.07638e+07 n=900376 tag=gauss
wclsFrameSaver: saving 52995 traces tagged "wiener"
FrameSaver: q=1.15424e+07 n=858526 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 13780 XUs and 10615 XVs -> 675 XUVs
C:0 T:1 566 XUs and 587 XVs -> 18 XUVs
C:0 T:2 9413 XUs and 3944 XVs -> 371 XUVs
C:0 T:3 635 XUs and 665 XVs -> 34 XUVs
C:0 T:4 503 XUs and 494 XVs -> 26 XUVs
C:0 T:5 685 XUs and 963 XVs -> 18 XUVs
C:0 T:6 522 XUs and 433 XVs -> 10 XUVs
C:0 T:7 761 XUs and 1096 XVs -> 41 XUVs
C:0 T:8 1298 XUs and 1200 XVs -> 61 XUVs
C:0 T:9 752 XUs and 649 XVs -> 27 XUVs
C:0 T:10 466 XUs and 550 XVs -> 23 XUVs
C:0 T:11 469 XUs and 378 XVs -> 23 XUVs
C:0 T:12 439 XUs and 604 XVs -> 29 XUVs
C:0 T:13 782 XUs and 1043 XVs -> 43 XUVs
C:0 T:14 801 XUs and 1114 XVs -> 69 XUVs
C:0 T:15 1199 XUs and 1745 XVs -> 97 XUVs
1565 XUVs total
1105 collection wire objects
1565 potential space points
Neighbour search...
32089 tests to find 11140 neighbours
Iterating with no regularization...
Begin: 5.02277e+09
0 4.68766e+09
1 4.67548e+09
2 4.67541e+09
Now with regularization...
Begin: 4.64871e+09
0 4.64868e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
03-Nov-2025 14:56:04 UTC  Closed output file "np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120_reco_stage1_20251103T145604_keepup.root"

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        198.357       265.796       600.851        245.5        88.7394        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      7.7406e-05    0.000132586   0.000402508   0.000102352   7.99497e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               50.6188       90.2965       142.444       92.1953       24.1421        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.597514       0.73503       1.05607      0.702668      0.119096        23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000401637   0.000512799   0.00092385    0.000480906   0.000112796      23     
produce:ophit:OpHitFinder                       7.3829e-05    0.000151789   0.000728221   0.000110067   0.000131678      23     
produce:opflash:OpFlashFinderVerticalDrift      5.7288e-05    0.000102482   0.000409771   8.5952e-05    7.11895e-05      23     
produce:wclsdatavd:WireCellToolkit                75.0197       98.9683       144.645       91.6391       20.8151        23     
produce:gaushit:GausHitFinder                     1.00906       1.67805       2.59361       1.55452      0.440661        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000249419   0.000344921   0.000618856   0.000325894   7.3802e-05       23     
produce:reco3d:SpacePointSolver                   7.1828        13.1705       25.8055       12.0779       4.50303        23     
produce:hitpdune:DisambigFromSpacePoints          0.10058      0.222721      0.525257      0.179594      0.102372        23     
produce:pandora:StandardPandora                   14.5798       53.0684       341.316       32.7093       66.1617        23     
produce:pandoraTrack:LArPandoraTrackCreation     0.488518       1.4919        4.05001       1.24187      0.800519        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0267717     0.0441227     0.0631859     0.0437688     0.0100803       23     
[art]:TriggerResults:TriggerResultInserter      2.4947e-05    4.11179e-05   8.3478e-05    3.8383e-05    1.35833e-05      23     
end_path:out1:RootOutput                         4.439e-06     8.99e-06     3.2642e-05     6.673e-06    7.1137e-06       23     
end_path:out1:RootOutput(write)                   5.16484       6.0578        7.42491       5.80222      0.644998        23     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5943.14 MB
  Peak resident set size usage (VmHWM): 3829.05 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120_reco_stage1_20251103T145604_keepup.root
\tHists: np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120_reco_stage1_20251103T145604_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120_reco_stage1_20251103T145604_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120_reco_stage1_20251103T145604_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": 1762181765.0,
    "core.end_time": 1762181765.0,
    "core.events": [
      318891,
      318895,
      318899,
      318903,
      318907,
      318911,
      318915,
      318919,
      318923,
      318927,
      318931,
      318935,
      318939,
      318943,
      318947,
      318951,
      318955,
      318959,
      318963,
      318967,
      318971,
      318975,
      318979
    ],
    "core.event_count": 23,
    "core.first_event_number": 318891,
    "core.last_event_number": 318979,
    "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_3456_df-s04-d3_dw_0_20251103T123120.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3456_df-s04-d3_dw_0_20251103T123120_reco_stage1_20251103T145604_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": 1762181765.0,
    "core.end_time": 1762181765.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_3456_df-s04-d3_dw_0_20251103T123120.hdf5"
    }
  ]
}