Skip to main content

monarch_hyperactor/
telemetry.rs

1/*
2 * Copyright (c) Meta Platforms, Inc. and affiliates.
3 * All rights reserved.
4 *
5 * This source code is licensed under the BSD-style license found in the
6 * LICENSE file in the root directory of this source tree.
7 */
8
9#![allow(unsafe_op_in_unsafe_fn)]
10
11use hyperactor_telemetry::end_user_span;
12use hyperactor_telemetry::sinks::perfetto::USER_TELEMETRY_PREFIX;
13use hyperactor_telemetry::sqlite::SqliteTracing;
14use hyperactor_telemetry::start_user_span;
15use hyperactor_telemetry::trace_dispatcher::FieldValue;
16use opentelemetry::global;
17use opentelemetry::metrics;
18use pyo3::prelude::*;
19use pyo3::types::PyTraceback;
20
21use crate::proc::PyActorAddr;
22
23/// Get the current span ID from the active span
24#[pyfunction]
25pub fn get_current_span_id() -> PyResult<u64> {
26    Ok(tracing::Span::current().id().map_or(0, |id| id.into_u64()))
27}
28
29/// Log a message with the given metaata
30#[pyfunction]
31pub fn forward_to_tracing(py: Python, record: Py<PyAny>) -> PyResult<()> {
32    let message = record.call_method0(py, "getMessage")?;
33    let message: &str = message.extract(py)?;
34    let lineno: i64 = record.getattr(py, "lineno")?.extract(py)?;
35    let file = record.getattr(py, "filename")?;
36    let file: &str = file.extract(py)?;
37    let level: i32 = record.getattr(py, "levelno")?.extract(py)?;
38
39    // Extract actor_id from the Python record object if available
40    let actor_id = record
41        .getattr(py, "actor_id")
42        .ok()
43        .and_then(|attr| attr.extract::<String>(py).ok());
44
45    // Enter the actor's recording span (if present) so RecorderLayer
46    // captures this event in the per-actor flight recorder. The span
47    // is entered synchronously for the duration of the tracing emit
48    // only — no cross-contamination in shared-asyncio mode.
49    //
50    // Gracefully falls back to plain tracing when _context is absent,
51    // None, or contains an unexpected type.
52    let _recording_guard = extract_recording_span(py);
53
54    // Map level number to level name
55    match level {
56        40 | 50 => {
57            let exc = record.getattr(py, "exc_info").ok();
58            let traceback = exc
59                .and_then(|exc| {
60                    if exc.is_none(py) {
61                        return None;
62                    }
63                    exc.extract::<(Py<PyAny>, Py<PyAny>, Bound<'_, PyTraceback>)>(py)
64                        .ok()
65                })
66                .map(|(_, _, tb)| tb.format().unwrap_or_default());
67            match traceback {
68                Some(traceback) => {
69                    tracing::error!(
70                        target:"log_events",
71                        file = file,
72                        lineno = lineno,
73                        stacktrace = traceback,
74                        actor_id = actor_id.as_deref(),
75                        message
76                    );
77                }
78                None => {
79                    tracing::error!(
80                        file = file,
81                        lineno = lineno,
82                        actor_id = actor_id.as_deref(),
83                        message
84                    );
85                }
86            }
87        }
88        30 => {
89            tracing::warn!(target:"log_events", file = file, lineno = lineno, actor_id = actor_id.as_deref(), message)
90        }
91        20 => {
92            tracing::info!(target:"log_events", file = file, lineno = lineno, actor_id = actor_id.as_deref(), message)
93        }
94        10 => {
95            tracing::debug!(target:"log_events", file = file, lineno = lineno, actor_id = actor_id.as_deref(), message)
96        }
97        _ => {
98            tracing::info!(target:"log_events", file = file, lineno = lineno, actor_id = actor_id.as_deref(), message)
99        }
100    }
101    Ok(())
102}
103
104/// Extract the recording span from the current Python actor context.
105///
106/// Looks up the `_context` ContextVar in
107/// `monarch._src.actor.actor_mesh`, downcasts to `PyContext`, and
108/// clones the recording span. Returns an entered span guard that
109/// routes tracing events to the actor's flight recorder.
110///
111/// Returns `None` on any failure — missing module, absent context,
112/// unexpected type, or no recording span. This function is called
113/// from arbitrary Python logging contexts (import-time, client-side,
114/// non-actor threads) and must never fail.
115fn extract_recording_span(py: Python) -> Option<tracing::span::EnteredSpan> {
116    let actor_mesh = py.import("monarch._src.actor.actor_mesh").ok()?;
117    let ctx_var = actor_mesh.getattr("_context").ok()?;
118    let ctx_obj = ctx_var.call_method1("get", (py.None(),)).ok()?;
119    if ctx_obj.is_none() {
120        return None;
121    }
122    let py_ctx = ctx_obj
123        .extract::<PyRef<'_, crate::context::PyContext>>()
124        .ok()?;
125    let span = py_ctx.recording_span()?.clone();
126    Some(span.entered())
127}
128
129/// Get the current execution ID
130#[pyfunction]
131pub fn get_execution_id() -> PyResult<String> {
132    Ok(hyperactor_telemetry::env::execution_id())
133}
134
135#[pyfunction]
136pub fn instant_event(message: &str) -> PyResult<()> {
137    tracing::info!(message);
138    Ok(())
139}
140
141// opentelemetry requires that the names of counters etc are static for the lifetime of the program.
142// Since we are binding these classes from python to rust, we have to leak these strings in order to
143// ensure they live forever. This is fine, as these classes aren't dynamically created.
144fn as_static_str(to_leak: &str) -> &'static str {
145    String::from(to_leak).leak()
146}
147
148#[pyclass(
149    subclass,
150    module = "monarch._rust_bindings.monarch_hyperactor.telemetry"
151)]
152struct PyCounter {
153    inner: metrics::Counter<u64>,
154}
155
156#[pymethods]
157impl PyCounter {
158    #[new]
159    fn new(name: &str) -> Self {
160        Self {
161            inner: global::meter("monarch")
162                .u64_counter(as_static_str(name))
163                .build(),
164        }
165    }
166
167    fn add(&mut self, value: u64, attributes: Option<std::collections::HashMap<String, String>>) {
168        let kv_attributes: Vec<opentelemetry::KeyValue> = match attributes {
169            Some(attrs) => attrs
170                .into_iter()
171                .map(|(k, v)| opentelemetry::KeyValue::new(k, v))
172                .collect(),
173            None => vec![],
174        };
175        self.inner.add(value, &kv_attributes);
176    }
177}
178
179#[pyclass(
180    subclass,
181    module = "monarch._rust_bindings.monarch_hyperactor.telemetry"
182)]
183struct PyHistogram {
184    inner: metrics::Histogram<f64>,
185}
186
187#[pymethods]
188impl PyHistogram {
189    #[new]
190    fn new(name: &str) -> Self {
191        Self {
192            inner: global::meter("monarch")
193                .f64_histogram(as_static_str(name))
194                .build(),
195        }
196    }
197
198    fn record(
199        &mut self,
200        value: f64,
201        attributes: Option<std::collections::HashMap<String, String>>,
202    ) {
203        let kv_attributes: Vec<opentelemetry::KeyValue> = match attributes {
204            Some(attrs) => attrs
205                .into_iter()
206                .map(|(k, v)| opentelemetry::KeyValue::new(k, v))
207                .collect(),
208            None => vec![],
209        };
210        self.inner.record(value, &kv_attributes);
211    }
212}
213
214#[pyclass(
215    subclass,
216    module = "monarch._rust_bindings.monarch_hyperactor.telemetry"
217)]
218struct PyUpDownCounter {
219    inner: metrics::UpDownCounter<i64>,
220}
221
222#[pymethods]
223impl PyUpDownCounter {
224    #[new]
225    fn new(name: &str) -> Self {
226        Self {
227            inner: global::meter("monarch")
228                .i64_up_down_counter(as_static_str(name))
229                .build(),
230        }
231    }
232
233    fn add(&mut self, value: i64, attributes: Option<std::collections::HashMap<String, String>>) {
234        let kv_attributes: Vec<opentelemetry::KeyValue> = match attributes {
235            Some(attrs) => attrs
236                .into_iter()
237                .map(|(k, v)| opentelemetry::KeyValue::new(k, v))
238                .collect(),
239            None => vec![],
240        };
241        self.inner.add(value, &kv_attributes);
242    }
243}
244
245#[pyclass(
246    subclass,
247    module = "monarch._rust_bindings.monarch_hyperactor.telemetry"
248)]
249struct PySpan {
250    id: Option<u64>,
251}
252
253#[pymethods]
254impl PySpan {
255    #[new]
256    #[pyo3(signature = (name, actor_id = None, correlation_id = None))]
257    fn new(name: &str, actor_id: Option<&PyActorAddr>, correlation_id: Option<u64>) -> Self {
258        let mut fields = vec![("name", FieldValue::Str(name.to_string()))];
259        if let Some(actor_id) = actor_id {
260            fields.push(("actor_id", FieldValue::Str(actor_id.inner.to_string())));
261        }
262        if let Some(cid) = correlation_id {
263            fields.push(("correlation_id", FieldValue::U64(cid)));
264        }
265        let id = start_user_span("python_user_span", USER_TELEMETRY_PREFIX, fields);
266
267        Self {
268            id: (id != 0).then_some(id),
269        }
270    }
271
272    fn __enter__(slf: PyRef<'_, Self>) -> PyRef<'_, Self> {
273        slf
274    }
275
276    fn __exit__(
277        &mut self,
278        _exc_type: Option<Py<PyAny>>,
279        _exc_value: Option<Py<PyAny>>,
280        _traceback: Option<Py<PyAny>>,
281    ) -> PyResult<bool> {
282        if let Some(id) = self.id.take() {
283            end_user_span(id);
284        }
285        Ok(false)
286    }
287}
288
289impl Drop for PySpan {
290    fn drop(&mut self) {
291        if let Some(id) = self.id.take() {
292            end_user_span(id);
293        }
294    }
295}
296
297#[pyclass(
298    subclass,
299    module = "monarch._rust_bindings.monarch_hyperactor.telemetry"
300)]
301struct PySqliteTracing {
302    guard: Option<SqliteTracing>,
303}
304
305#[pymethods]
306impl PySqliteTracing {
307    #[new]
308    #[pyo3(signature = (in_memory = false))]
309    fn new(in_memory: bool) -> PyResult<Self> {
310        let guard = if in_memory {
311            SqliteTracing::new_in_memory()
312        } else {
313            SqliteTracing::new()
314        };
315
316        match guard {
317            Ok(guard) => Ok(Self { guard: Some(guard) }),
318            Err(e) => Err(PyErr::new::<pyo3::exceptions::PyRuntimeError, _>(format!(
319                "Failed to create SQLite tracing guard: {}",
320                e
321            ))),
322        }
323    }
324
325    fn db_path(&self) -> PyResult<Option<String>> {
326        match &self.guard {
327            Some(guard) => Ok(guard.db_path().map(|p| p.to_string_lossy().to_string())),
328            None => Err(PyErr::new::<pyo3::exceptions::PyRuntimeError, _>(
329                "Guard has been closed",
330            )),
331        }
332    }
333
334    fn __enter__(slf: PyRefMut<'_, Self>) -> PyResult<PyRefMut<'_, Self>> {
335        Ok(slf)
336    }
337
338    fn __exit__(
339        &mut self,
340        _exc_type: Option<Py<PyAny>>,
341        _exc_value: Option<Py<PyAny>>,
342        _traceback: Option<Py<PyAny>>,
343    ) -> PyResult<bool> {
344        self.guard = None;
345        Ok(false) // Don't suppress exceptions
346    }
347
348    fn close(&mut self) {
349        self.guard = None;
350    }
351}
352
353pub fn register_python_bindings(module: &Bound<'_, PyModule>) -> PyResult<()> {
354    // Register the forward_to_tracing function
355    let f = wrap_pyfunction!(forward_to_tracing, module)?;
356    f.setattr(
357        "__module__",
358        "monarch._rust_bindings.monarch_hyperactor.telemetry",
359    )?;
360    module.add_function(f)?;
361
362    // Register the span-related functions
363    let get_current_span_id_fn = wrap_pyfunction!(get_current_span_id, module)?;
364    get_current_span_id_fn.setattr(
365        "__module__",
366        "monarch._rust_bindings.monarch_hyperactor.telemetry",
367    )?;
368    module.add_function(get_current_span_id_fn)?;
369
370    let get_execution_id_fn = wrap_pyfunction!(get_execution_id, module)?;
371    get_execution_id_fn.setattr(
372        "__module__",
373        "monarch._rust_bindings.monarch_hyperactor.telemetry",
374    )?;
375    module.add_function(get_execution_id_fn)?;
376
377    let instant_event_fn = wrap_pyfunction!(instant_event, module)?;
378    instant_event_fn.setattr(
379        "__module__",
380        "monarch._rust_bindings.monarch_hyperactor.telemetry",
381    )?;
382    module.add_function(instant_event_fn)?;
383
384    module.add_class::<PySpan>()?;
385    module.add_class::<PyCounter>()?;
386    module.add_class::<PyHistogram>()?;
387    module.add_class::<PyUpDownCounter>()?;
388    module.add_class::<PySqliteTracing>()?;
389    Ok(())
390}
391
392#[cfg(test)]
393mod tests {
394    use pyo3::ffi::c_str;
395    use pyo3::prelude::*;
396
397    use super::*;
398    use crate::runtime::GilSite;
399    use crate::runtime::monarch_with_gil_blocking;
400
401    fn init_python() {
402        pyo3::Python::initialize();
403    }
404
405    /// Helper: create a Python logging.LogRecord with the given message.
406    fn make_log_record(py: Python, message: &str) -> Py<PyAny> {
407        let locals = pyo3::types::PyDict::new(py);
408        locals.set_item("msg", message).unwrap();
409        py.run(
410            c_str!(
411                "import logging\n\
412                 record = logging.LogRecord('test', logging.INFO, 'test.py', 1, msg, (), None)"
413            ),
414            None,
415            Some(&locals),
416        )
417        .unwrap();
418        locals.get_item("record").unwrap().unwrap().into()
419    }
420
421    /// forward_to_tracing returns Ok when _context is absent.
422    /// Must never crash in non-actor logging contexts.
423    #[test]
424    fn forward_to_tracing_without_context_does_not_crash() {
425        init_python();
426        monarch_with_gil_blocking(GilSite::Test, |py| {
427            let record = make_log_record(py, "no context marker");
428            let result = forward_to_tracing(py, record);
429            assert!(result.is_ok());
430        });
431    }
432
433    /// When a recording span is entered on the current thread,
434    /// events emitted by forward_to_tracing are captured in the
435    /// recording's ring buffer.
436    #[test]
437    fn forward_to_tracing_captures_when_recording_span_entered() {
438        init_python();
439        hyperactor_telemetry::initialize_logging_for_test();
440
441        let recording = hyperactor_telemetry::recorder().record(64);
442        let span = recording.span("test");
443
444        monarch_with_gil_blocking(GilSite::Test, |py| {
445            let record = make_log_record(py, "recorder marker");
446            let _guard = span.enter();
447            let result = forward_to_tracing(py, record);
448            assert!(result.is_ok());
449        });
450
451        let events = recording.tail();
452        assert!(
453            !events.is_empty(),
454            "expected at least one event in recording"
455        );
456        let last = events.last().unwrap();
457        let fields = format!("{:?}", last);
458        assert!(
459            fields.contains("recorder marker"),
460            "expected 'recorder marker' in event fields, got: {fields}"
461        );
462    }
463
464    /// extract_recording_span returns None when _context is absent.
465    #[test]
466    fn extract_recording_span_returns_none_without_context() {
467        init_python();
468        monarch_with_gil_blocking(GilSite::Test, |py| {
469            let result = extract_recording_span(py);
470            assert!(result.is_none());
471        });
472    }
473}