Skip to content

Commit 9056b6f

Browse files
Weiwei Yangchanglan
authored andcommitted
Add prometheus style metrics for Bastion
GitOrigin-RevId: ce71732
1 parent d851e6e commit 9056b6f

3 files changed

Lines changed: 199 additions & 9 deletions

File tree

axlearn/cloud/common/bastion.py

Lines changed: 14 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -110,6 +110,7 @@
110110
except ModuleNotFoundError:
111111
logging.warning("tensorflow_io is not installed -- tf_io may not work with s3://")
112112

113+
from axlearn.cloud.common import metrics
113114
from axlearn.cloud.common.cleaner import Cleaner
114115
from axlearn.cloud.common.event_queue import BaseQueueClient, Event
115116
from axlearn.cloud.common.quota import QuotaFn
@@ -904,10 +905,13 @@ def check_leaves(x, y):
904905

905906
def _wait_and_close_proc(self, proc: _PipedProcess, kill: bool = False):
906907
"""Cleans up the process/fds and upload logs to gs."""
908+
pid = proc.popen.pid
907909
if kill:
908910
send_signal(proc.popen, sig=signal.SIGKILL)
909911
# Note: proc should already be polled and completed, so wait is nonblocking.
910912
proc.popen.wait()
913+
# Cleanup the local prometheus DB files when the process is terminated
914+
_catch_with_error_log(metrics.cleanup, pid)
911915
proc.fd.close()
912916
# Upload outputs to log dir.
913917
_catch_with_error_log(
@@ -958,15 +962,16 @@ def _sync_jobs(self):
958962
959963
We use these jobspecs to update the local self._active_jobs.
960964
"""
961-
active_jobs, jobs_with_user_states, jobs_with_failed_validation = download_job_batch(
962-
spec_dir=self._active_dir,
963-
state_dir=self._state_dir,
964-
user_state_dir=self._user_state_dir,
965-
verbose=True,
966-
remove_invalid_user_states=True,
967-
quota=self._quota,
968-
validator=self._validator,
969-
)
965+
with metrics.BASTION_DOWNLOAD_JOB_ALL_SECONDS.time():
966+
active_jobs, jobs_with_user_states, jobs_with_failed_validation = download_job_batch(
967+
spec_dir=self._active_dir,
968+
state_dir=self._state_dir,
969+
user_state_dir=self._user_state_dir,
970+
verbose=True,
971+
remove_invalid_user_states=True,
972+
quota=self._quota,
973+
validator=self._validator,
974+
)
970975
self._jobs_with_user_states = jobs_with_user_states
971976
# Iterate over unique job names.
972977
# pylint: disable-next=use-sequence-for-iteration

axlearn/cloud/common/metrics.py

Lines changed: 158 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,158 @@
1+
"""Prometheus metrics for Bastion runners."""
2+
3+
import logging
4+
import threading
5+
from http.server import BaseHTTPRequestHandler, HTTPServer
6+
7+
from prometheus_client import CollectorRegistry, Gauge, Histogram, generate_latest, multiprocess
8+
9+
BASTION_DOWNLOAD_JOB_ALL_SECONDS = Histogram(
10+
"bastion_download_job_all_seconds",
11+
"Time in seconds consumed in each scheduling loop to download all the job specs",
12+
[],
13+
buckets=(1, 5, 10, 30, 60, 120, 300, 600, 1800, 3600), # 1s to 1hr
14+
)
15+
16+
JOB_TIME_TO_RUNNING_SECONDS = Histogram(
17+
"bastion_job_time_to_running_seconds",
18+
"Time in seconds from runner starts a job until until it reaches Running state",
19+
["job_name"],
20+
buckets=(1, 5, 10, 30, 60, 120, 300, 600, 1800, 3600), # 1s to 1hr
21+
)
22+
23+
JOB_RUN_LATENCY_GAUGE = Gauge(
24+
"bastion_job_run_latency_seconds",
25+
"Time in seconds from runner starts a job until until it reaches Running state",
26+
["job_name"],
27+
)
28+
29+
JOB_WAIT_FOR_BUILD_SECONDS = Gauge(
30+
"bastion_job_wait_for_build_seconds",
31+
"time in seconds until the job is built successfully",
32+
["job_name"],
33+
)
34+
35+
JOB_SUSPENDED_DURATION_SECONDS = Histogram(
36+
"bastion_job_suspended_duration_seconds",
37+
"Time in seconds the jobset stayed in SUSPENDED state",
38+
["job_name"],
39+
buckets=(1, 5, 10, 30, 60, 120, 300, 600, 1800, 3600), # 1s to 1hr
40+
)
41+
42+
43+
class _MetricsHandler(BaseHTTPRequestHandler):
44+
"""HTTP handler that serves aggregated metrics from multiprocess mode."""
45+
46+
def do_GET(self): # pylint: disable=invalid-name
47+
if self.path == "/metrics":
48+
registry = CollectorRegistry()
49+
multiprocess.MultiProcessCollector(registry)
50+
metrics = generate_latest(registry)
51+
52+
self.send_response(200)
53+
self.send_header("Content-Type", "text/plain; charset=utf-8")
54+
self.end_headers()
55+
self.wfile.write(metrics)
56+
else:
57+
self.send_error(404)
58+
59+
def log_message(self, format, *args): # pylint: disable=redefined-builtin
60+
# Suppress default logging
61+
pass
62+
63+
64+
class MetricsServer:
65+
"""Singleton class to manage Prometheus metrics server.
66+
67+
Supports multiprocess mode where metrics from parent and child processes
68+
are aggregated and exposed via a single endpoint.
69+
"""
70+
71+
_instance = None
72+
_lock = threading.Lock()
73+
_server_started = False
74+
_multiprocess_dir = None
75+
76+
def __new__(cls):
77+
if cls._instance is None:
78+
with cls._lock:
79+
if cls._instance is None:
80+
cls._instance = super().__new__(cls)
81+
return cls._instance
82+
83+
@classmethod
84+
def start(cls, port: int = 8000):
85+
"""Start Prometheus metrics HTTP server on the specified port.
86+
87+
Args:
88+
port: Port number to start the metrics server on. Defaults to 8000.
89+
use_multiprocess: If True, use multiprocess mode which aggregates metrics
90+
from child processes. Defaults to False for backward compatibility.
91+
"""
92+
with cls._lock:
93+
if not cls._server_started:
94+
try:
95+
# Use custom handler for multiprocess aggregation
96+
server = HTTPServer(("", port), _MetricsHandler)
97+
thread = threading.Thread(target=server.serve_forever, daemon=True)
98+
thread.start()
99+
logging.info(
100+
"Prometheus metrics server (multiprocess mode) started on port %s", port
101+
)
102+
cls._server_started = True
103+
except OSError as e:
104+
# Port might already be in use
105+
logging.warning("Failed to start metrics server on port %s: %s", port, e)
106+
107+
@classmethod
108+
def is_started(cls) -> bool:
109+
"""Check if the metrics server has been started."""
110+
return cls._server_started
111+
112+
@classmethod
113+
def get_multiprocess_dir(cls) -> str:
114+
"""Get the multiprocess directory path if configured."""
115+
return cls._multiprocess_dir
116+
117+
118+
def record_job_time_to_running(job_name: str, time_seconds: float):
119+
"""Record the time it took for a job to reach RUNNING state.
120+
121+
Args:
122+
job_name: Name of the job
123+
time_seconds: Time in seconds from first seen until RUNNING state
124+
"""
125+
JOB_TIME_TO_RUNNING_SECONDS.labels(job_name=job_name).observe(time_seconds)
126+
logging.info("Metrics: job %s took %.2f seconds to reach RUNNING state", job_name, time_seconds)
127+
128+
129+
def record_job_run_latency(job_name: str, time_seconds: float):
130+
JOB_RUN_LATENCY_GAUGE.labels(job_name).set(time_seconds)
131+
132+
133+
def record_job_wait_for_build(job_name: str, time_seconds: float):
134+
"""Record the time it took to wait for the cloud build to finish
135+
136+
This does not necessarily mean the whole cloud build time for a job,
137+
as the build starts when the client submits the job. This only measures
138+
how long the runner waits for the build to complete before launching
139+
the job.
140+
"""
141+
JOB_WAIT_FOR_BUILD_SECONDS.labels(job_name).set(time_seconds)
142+
143+
144+
def record_job_suspended_duration(job_name: str, time_seconds: float):
145+
"""Record the time a job spent in SUSPENDED state.
146+
147+
Args:
148+
job_name: Name of the job
149+
time_seconds: Time in seconds the job was in SUSPENDED state
150+
"""
151+
JOB_SUSPENDED_DURATION_SECONDS.labels(job_name=job_name).observe(time_seconds)
152+
logging.info("Metrics: job %s was in SUSPENDED state for %.2f seconds", job_name, time_seconds)
153+
154+
155+
def cleanup(pid=None):
156+
if pid:
157+
logging.info("Cleaning up prometheus metrics DB file for %s", pid)
158+
multiprocess.mark_process_dead(pid)

axlearn/cloud/gcp/runners/gke.py

Lines changed: 27 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -71,6 +71,7 @@
7171
import requests
7272
from absl import flags, logging
7373

74+
from axlearn.cloud.common import metrics
7475
from axlearn.cloud.common.bastion import (
7576
BASTION_JOB_VERSION_ENV_VAR,
7677
JobLifecycleEvent,
@@ -537,9 +538,15 @@ def _reschedule(self):
537538
def _execute(self):
538539
cfg: GKERunnerJob.Config = self.config
539540

541+
# Record start time for JOB_TIME_TO_RUNNING_SECONDS metric.
542+
start_time = time.perf_counter()
543+
540544
# Keep track of last status to prevent duplicate events.
541545
last_job_status = None
542546

547+
# Track when the job enters SUSPENDED state.
548+
suspended_since = None
549+
543550
while True:
544551
status = self._get_status()
545552

@@ -571,7 +578,11 @@ def _execute(self):
571578
try:
572579
# Note: while the wait is blocking, the bastion will kill the runner process
573580
# when it needs to reschedule.
581+
wait_build_start = time.perf_counter()
574582
self._bundler.wait_until_finished(image_id or cfg.name)
583+
metrics.record_job_wait_for_build(
584+
cfg.name, time.perf_counter() - wait_build_start
585+
)
575586
except RuntimeError as e:
576587
logging.error("Bundling failed: %s. Aborting the job.", e)
577588
return
@@ -581,13 +592,29 @@ def _execute(self):
581592
self._pre_provisioner.create_for(self._inner)
582593

583594
self._inner.execute()
595+
elif status == GKERunnerJob.Status.SUSPENDED:
596+
# Job is in SUSPENDED state.
597+
if suspended_since is None:
598+
suspended_since = time.perf_counter()
599+
logging.info("Job %s entered SUSPENDED state", cfg.name)
584600
else:
601+
# For all other statuses, check if we were tracking a suspend period.
602+
if suspended_since is not None:
603+
# Job exited SUSPENDED state, record the duration.
604+
suspended_duration = time.perf_counter() - suspended_since
605+
metrics.record_job_suspended_duration(cfg.name, suspended_duration)
606+
suspended_since = None
607+
585608
# Ensure VertexAI Tensorboard Uploader is running.
586609
if self._tb_uploader:
587610
self._tb_uploader.upload()
588611
logging.info("Task %s has status: %s", cfg.name, status)
589612
# Only emit events when status changes.
590613
if status == GKERunnerJob.Status.READY and status != last_job_status:
614+
# Record the time to reach RUNNING state.
615+
elapsed_time = time.perf_counter() - start_time
616+
metrics.record_job_time_to_running(cfg.name, elapsed_time)
617+
metrics.record_job_run_latency(cfg.name, elapsed_time)
591618
self._maybe_publish(
592619
cfg.name, msg="Job is running", state=JobLifecycleState.RUNNING
593620
)

0 commit comments

Comments
 (0)