sapling/eden/scm/edenscm/tracing.py
Jun Wu c33df0dc4c tracing: add edenscm.tracing Python module mirroring Rust APIs
Summary:
Add a `edenscm.tracing` Python module that mirrors some of the APIs in the Rust
tracing eco-system:
- span, {info,debug,trace,warn,error}_span (for tracing)
- event, {info,debug,trace,warn,error} (for logging)
- instrument (decorator for function tracing)

One thing that needs to be careful is that callsites are meant to be static:
multiple calls to a same code location should reuse a single callsite. That
is achieved using (id(code), line) from the Python stack as the key.

Reviewed By: sfilipco

Differential Revision: D26013750

fbshipit-source-id: 63b89a73186d876af9fc1b311fbd7948d0a6e27a
2021-01-28 13:17:59 -08:00

163 lines
4.4 KiB
Python

# Copyright (c) Facebook, Inc. and its affiliates.
#
# This software may be used and distributed according to the terms of the
# GNU General Public License version 2.
from __future__ import absolute_import
"""
Tracing APIs similar to the Rust equivalent defined by the tracing crate.
"""
import os
import sys
from functools import partial
import bindings
# The Rust bindings (pytracing crate)
_tracing = bindings.tracing
LEVEL_TRACE = _tracing.LEVEL_TRACE
LEVEL_DEBUG = _tracing.LEVEL_DEBUG
LEVEL_INFO = _tracing.LEVEL_INFO
LEVEL_WARN = _tracing.LEVEL_WARN
LEVEL_ERROR = _tracing.LEVEL_ERROR
# ---- instrument ----
"""Decorate a function for tracing
Example::
@instrument
def f(x, y):
# x and y will be logged if they are str or int
@instrument(level=LEVEL_WARN, target="bar", skip=["y"])
def f(x, y):
# skip: do not log specified args
"""
instrument = _tracing.instrument
if os.getenv("EDENSCM_NO_PYTHON_INSTRUMENT"):
def instrument(func=None, **kwargs):
return func or instrument
# ---- event ----
def event(message, name=None, target=None, level=LEVEL_INFO, depth=0, **meta):
"""Log an event to the Rust tracing eco-system
name, target, and meta keys are stored in the callsite metadata, meaning
that a callsite, once defined, won't be able to change them.
depth can be used to adjust callsite definition. For a utility function
that wraps 'event', it might want to set depth to 1 so callsite is not
that utility function but the one calling it. In Rust, such utility
functions would need to be implemented in macros.
Example::
info(f"{n} files downloaded in {t} seconds", request_id=reqid)
"""
frame = sys._getframe(1 + depth)
ident = (id(frame.f_code), frame.f_lineno)
callsite = _callsites.get(ident)
if callsite is None:
# Create the callsite.
# The field name "message" matches Rust tracing macros behavior.
fieldnames = ["message"]
if meta:
fieldnames += sorted(meta)
callsite = _insertcallsite(
ident,
_tracing.EventCallsite(
obj=frame,
name=name,
target=target,
level=level,
fieldnames=fieldnames,
),
)
frame = None # break cycles
values = [message]
if meta:
values += [v for _k, v in sorted(meta.items())]
callsite.event(values)
trace = partial(event, level=LEVEL_TRACE)
debug = partial(event, level=LEVEL_DEBUG)
info = partial(event, level=LEVEL_INFO)
warn = partial(event, level=LEVEL_WARN)
error = partial(event, level=LEVEL_ERROR)
# ---- span ----
def span(name, target=None, level=LEVEL_INFO, depth=0, **meta):
"""Open a span in the Rust tracing eco-system.
The returned span works as a context manager, and meta can be dynamically
updated via 'span.record(name=value)'. Note: all meta field names must
be predefined statically.
name, target, and meta keys are stored in the callsite metadata, meaning
that a callsite, once defined, won't be able to change them.
depth can be used to adjust callsite definition. For a utility function
that wraps 'span', it might want to set depth to 1 so callsite is not
that utility function but the one calling it. In Rust, such utility
functions would need to be implemented in macros.
Example::
with info_span("Downloading Files", n=100, tx=None) as span:
...
span.record("tx", txbytes)
"""
frame = sys._getframe(1 + depth)
ident = (id(frame.f_code), frame.f_lineno)
callsite = _callsites.get(ident)
if callsite is None:
fieldnames = meta and sorted(meta)
callsite = _insertcallsite(
ident,
_tracing.SpanCallsite(
obj=frame,
name=name,
target=target,
level=level,
fieldnames=fieldnames,
),
)
frame = None # break cycles
values = meta and [v for _k, v in sorted(meta.items())]
return callsite.span(values)
trace_span = partial(span, level=LEVEL_TRACE)
debug_span = partial(span, level=LEVEL_DEBUG)
info_span = partial(span, level=LEVEL_INFO)
warn_span = partial(span, level=LEVEL_WARN)
error_span = partial(span, level=LEVEL_ERROR)
# ---- local cache of callsites ----
_callsites = {}
def _insertcallsite(key, callsite):
_callsites[key] = callsite
return callsite