Skip to content

fix: correct host CPU and disk utilization metrics #1036

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
waninggibbon wants to merge 4 commits into
base: mainline
Choose a base branch
from
Open

fix: correct host CPU and disk utilization metrics #1036

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
9ecc35b
fix: correct host CPU and disk utilization metrics
waninggibbon Jul 31, 2026
58fcf78
fix: widen exception handling, fix total disk used percent metric.
waninggibbon Jul 31, 2026
07192af
fix: make host metrics collection non-fatal and bound nvidia-smi
waninggibbon Aug 3, 2026
8baec7b
Merge branch 'mainline' into fix-host-metrics-sampling
waninggibbon Aug 4, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
106 changes: 84 additions & 22 deletions src/deadline_worker_agent/metrics.py
View file
Open in desktop

@leongdl leongdl Aug 1, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggestion 2 of 3: this is the unbounded blocker that the new 5s join is compensating for.

This check_output has no timeout=, so it can block indefinitely. A wedged nvidia-smi is a real failure mode on unhealthy GPU drivers, where the process can sit in uninterruptible sleep — and it's exactly the "unresponsive nvidia-smi" case cited in the new __exit__ comment.

This line is outside the diff, so it's pre-existing rather than something this PR introduced. But it's worth fixing here, because it's the root cause: it's the only thing inside log_metrics() that can keep the metrics thread from noticing _stop_event promptly, and therefore the only reason the bounded join can ever run out its clock. Bounding the collection makes the join's timeout nearly unreachable in practice.

output = subprocess.check_output(
    ["nvidia-smi", f"--query-gpu={query_str}", "--format=csv,noheader,nounits"],
    stderr=subprocess.PIPE,
    universal_newlines=True,
    timeout=...,  # a few seconds, comfortably under interval_s
)

One thing to check if you take this: subprocess.TimeoutExpired is not a subclass of CalledProcessError, so it would fall through to the existing except Exception catch-all below. That does the right thing (debug log, then _host_has_no_gpu = True), but note the _host_has_no_gpu latch means a single transient timeout permanently disables GPU metrics for the process lifetime. A dedicated except subprocess.TimeoutExpired that logs and returns without setting the latch is probably what you want, so a one-off hang doesn't cost you GPU metrics forever.

@waninggibbon waninggibbon Aug 3, 2026

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I went ahead with a 5 second time out, skipped the _host_has_no_gpu latch, and added a dedicated timeout expired handler.

Agree that a transient hang causing us to drop a sample is preferable here. Thanks for the suggestion!

Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
from __future__ import annotations

from logging import Logger, getLogger
from threading import Timer
from threading import Event, Thread
from typing import Any, Dict

import os
Expand All @@ -18,29 +18,92 @@
class HostMetricsLogger:
"""Context manager that regularly logs host metrics"""

# How long to wait for the metrics thread to exit during shutdown before
# abandoning it. Kept short: the thread is a daemon and setting the stop event wakes
# it immediately, so this is only ever paid if a collection is hung.
JOIN_TIMEOUT_S = 1.0

# How long to wait for nvidia-smi to report GPU metrics. An unhealthy GPU driver can
# leave nvidia-smi unresponsive, which would otherwise block the metrics thread
# indefinitely and keep it from noticing the stop event.
GPU_QUERY_TIMEOUT_S = 5.0

logger: Logger
interval_s: float
_timer: Timer | None
_thread: Thread | None
_stop_event: Event
_prev_network: Any | None
_prev_disk_counters: Any | None
_host_has_no_gpu: bool | None = None

def __init__(self, logger: Logger, interval_s: float) -> None:
assert interval_s > 0, "interval_s must be a positive number"
self._timer = None
self._thread = None
self._stop_event = Event()
self._prev_network = None
self._prev_disk_counters = None
self.logger = logger
self.interval_s = interval_s

def __enter__(self) -> HostMetricsLogger:
self.log_metrics()
self._stop_event.clear()
thread = Thread(target=self._run, name="HostMetricsLogger", daemon=True)
try:
thread.start()
except RuntimeError as e:
# Host metrics are best-effort observability, so degrade to logging no metrics
# rather than failing the Worker when the host cannot spare a thread.
module_logger.warning(
f"Failed to start the host metrics thread. Host metrics will not be logged. "
f"Error: {e}"
)
else:
self._thread = thread
return self

def __exit__(self, type, value, traceback) -> None:
if self._timer:
self._timer.cancel()
self._timer = None
self._stop_event.set()
if self._thread:
# Bounded join so that an unresponsive metrics collection (e.g. a hung
# nvidia-smi) cannot block Worker shutdown. The thread is a daemon, so it
# will not keep the process alive if it outlives this join.
self._thread.join(timeout=self.JOIN_TIMEOUT_S)

@leongdl leongdl Jul 31, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would be careful here, 5s is a long time to join, since this is a context enter / exit, does it cost the call stack higher using this context any issues?

if self._thread.is_alive():
module_logger.warning(
"Host metrics thread did not exit within "
f"{self.JOIN_TIMEOUT_S} seconds. Abandoning it."
)
self._thread = None

def _run(self) -> None:
self._prime_metrics()
while not self._stop_event.wait(self.interval_s):

@github-actions github-actions Bot Aug 3, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Startup no longer logs an immediate metrics line. Previously __enter__ called log_metrics() synchronously, so a first sample was emitted at t=0 and then every interval_s. Now _run primes baselines and then blocks on self._stop_event.wait(self.interval_s) before the first log_metrics(), so the first line appears only after a full interval (default 60s).

Two consequences worth confirming are intended:

  • A Worker that lives less than one interval will now log no host metrics at all, whereas before it logged at least one line on startup.
  • Observability of a freshly started Worker is delayed by up to interval_s.

If the goal was only to get accurate (non-zeroed) rates on the first sample, that is already achieved by _prime_metrics(); you could still emit an immediate priming sample or shorten the first wait to preserve the previous startup-visibility behavior.

try:
self.log_metrics()
except Exception as e:
# Never let an unexpected error end the metrics thread; a single bad
# collection should not silently stop host metrics for the lifetime of
# the Worker.
module_logger.warning(f"Failed to log host metrics. Error: {e}")

def _prime_metrics(self) -> None:
"""
Establishes the baselines that the first logged sample is measured against.

psutil tracks non-blocking CPU samples per thread, so the CPU baseline must be
primed on this long-lived thread for every logged value to cover one complete
metrics interval. The network and disk counters are primed here for the same
reason: the gap between priming and the first collection is exactly one interval.
"""
try:
psutil.cpu_percent()
self._prev_network = psutil.net_io_counters(nowrap=True)
self._prev_disk_counters = psutil.disk_io_counters(nowrap=True)
except Exception as e:
module_logger.warning(
f"Failed to prime host metrics baselines. The first host metrics log message "
f"may report zeroed rates. Error: {e}"
)

def _get_gpu_metrics(self) -> Dict[str, str]:
"""
Expand Down Expand Up @@ -70,6 +133,7 @@ def _get_gpu_metrics(self) -> Dict[str, str]:
["nvidia-smi", f"--query-gpu={query_str}", "--format=csv,noheader,nounits"],
stderr=subprocess.PIPE,
universal_newlines=True,
timeout=self.GPU_QUERY_TIMEOUT_S,
)

# Variables to sum metrics across GPUs
Expand Down Expand Up @@ -105,6 +169,14 @@ def _get_gpu_metrics(self) -> Dict[str, str]:

avg_mem_util = round(mem_util_sum / valid_gpu_count, 1)
gpu_metrics["gpu-memory-utilization-percent"] = str(avg_mem_util)
except subprocess.TimeoutExpired:
# Returned without latching _host_has_no_gpu so that a single unresponsive
# nvidia-smi does not disable GPU metrics for the lifetime of the process.
module_logger.debug(
f"nvidia-smi did not respond within {self.GPU_QUERY_TIMEOUT_S} seconds, "
"skipping GPU metrics collection"
)
return {}
except FileNotFoundError:
module_logger.debug("nvidia-smi not found, skipping GPU metrics collection")
except subprocess.CalledProcessError:
Expand All @@ -116,7 +188,7 @@ def _get_gpu_metrics(self) -> Dict[str, str]:

return gpu_metrics

def log_metrics(self):
def log_metrics(self) -> None:
"""
Queries information about the host machine and logs the information as a space-delimited
line of the form: <label> <value> ...
Expand Down Expand Up @@ -183,7 +255,10 @@ def log_metrics(self):
"swap-used-bytes": str(swap.used),
"total-disk-bytes": str(disk.total),
"total-disk-used-bytes": str(disk.used),
"total-disk-used-percent": str(round(disk.used / disk.total, ndigits=1)),
# Computed from the root-based total/used values reported above rather than
# using psutil's disk.percent, which is measured against user-available
# space and so would not agree with the other total-disk-* metrics.
"total-disk-used-percent": str(round(disk.used / disk.total * 100, ndigits=1)),

@github-actions github-actions Bot Aug 4, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

total-disk-used-percent changes scale/units for existing consumers. The old code emitted round(disk.used / disk.total, 1) — a 0.0–1.0 fraction (e.g. 0.2 for a 25%-full disk), while the new code emits round(disk.used / disk.total * 100, 1) — a 0–100 percentage (e.g. 25.0).

This is the correct value (the old one was never a real percent), but it is a ~100× change to a metric a public product emits. Any existing CloudWatch alarm, dashboard, or log-based metric keyed on total-disk-used-percent will silently misbehave after this ships: a threshold like > 0.8 will now fire almost always, and a > 80 threshold that never fired before will start working. Worth calling out in the changelog / release notes so operators can re-tune anything built on the previous (fractional) values.

"user-disk-available-bytes": str(disk.free),
"network-sent-bytes-per-second": network_sent,
"network-recv-bytes-per-second": network_recv,
Expand All @@ -195,16 +270,3 @@ def log_metrics(self):
stats.update(gpu_metrics)

self.logger.info(MetricsLogEvent(subtype=MetricsLogEventSubtype.SYSTEM, metrics=stats))
finally:
self._set_timer()

def _set_timer(self) -> None:
"""
Sets the timer to log the host metrics at a regular interval.

Args:
interval_s (float): The interval in seconds to print the host metrics at.
"""
self._timer = Timer(self.interval_s, self.log_metrics)
self._timer.name = "HostMetricsLogger"
self._timer.start()
Loading
Loading