Merge pull request #59 from autometrics-dev/improved-caller-detection

Improve caller detection

.github/workflows/build.yml → .github/workflows/main.yml

@@ -1,5 +1,5 @@
 ---
-name: Lint
+name: Lint and test
 
 on:
   pull_request:
@@ -8,15 +8,18 @@ on:
     branches: ["main"]
 
 jobs:
-  build:
+  lint:
     runs-on: ubuntu-latest
+    strategy:
+      matrix:
+        python-version: ["3.7", "3.11", "pypy3.10"]
     steps:
       - uses: actions/checkout@v3
       - name: Install poetry
         run: pipx install poetry
       - uses: actions/setup-python@v4
         with:
-          python-version: "3.11"
+          python-version: ${{ matrix.python-version }}
           cache: "poetry"
       - name: Install dependencies
         run: poetry install --no-interaction --no-root --with dev

CHANGELOG.md

@@ -16,7 +16,8 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/).
 
 ### Changed
 
--
+- Caller tracking only tracks autometricised functions, as per spec #59
+- Function name labels now use qualified name, and module labels use module's `__name__` when available #59
 
 ### Deprecated
 

README.md

@@ -1,5 +1,6 @@
 ![GitHub_headerImage](https://user-images.githubusercontent.com/3262610/221191767-73b8a8d9-9f8b-440e-8ab6-75cb3c82f2bc.png)
 
+[![Tests](https://github.com/autometrics-dev/autometrics-py/actions/workflows/main.yml/badge.svg)](https://github.com/autometrics-dev/autometrics-py/actions/workflows/main.yml)
 [![Discord Shield](https://discordapp.com/api/guilds/950489382626951178/widget.png?style=shield)](https://discord.gg/kHtwcH8As9)
 
 > A Python port of the Rust
@@ -24,7 +25,7 @@ See [Why Autometrics?](https://github.com/autometrics-dev#why-autometrics) for m
 - [🔍 Identify commits](#identifying-commits-that-introduced-problems) that introduced errors or increased latency
 - [🚨 Define alerts](#alerts--slos) using SLO best practices directly in your source code
 - [📊 Grafana dashboards](#dashboards) work out of the box to visualize the performance of instrumented functions & SLOs
-- [⚙️ Configurable](#metrics-libraries) metric collection library (`opentelemetry`, `prometheus`, or `metrics`)
+- [⚙️ Configurable](#metrics-libraries) metric collection library (`opentelemetry` or `prometheus`)
 - [📍 Attach exemplars](#exemplars) to connect metrics with traces
 - ⚡ Minimal runtime overhead
 
@@ -86,39 +87,7 @@ def api_handler():
   # ...
 ```
 
-Autometrics by default will try to store information on which function calls a decorated function. As such you may want to place the autometrics in the top/first decorator, as otherwise you may get `inner` or `wrapper` as the caller function.
-
-So instead of writing:
-
-```py
-from functools import wraps
-from typing import Any, TypeVar, Callable
-
-R = TypeVar("R")
-
-def noop(func: Callable[..., R]) -> Callable[..., R]:
-    """A noop decorator that does nothing."""
-
-    @wraps(func)
-    def inner(*args: Any, **kwargs: Any) -> Any:
-        return func(*args, **kwargs)
-
-    return inner
-
-@noop
-@autometrics
-def api_handler():
-  # ...
-```
-
-You may want to switch the order of the decorator
-
-```py
-@autometrics
-@noop
-def api_handler():
-  # ...
-```
+Autometrics keeps track of instrumented functions calling each other. If you have a function that calls another function, metrics for later will include `caller` label set to the name of the autometricised function that called it.
 
 #### Metrics Libraries
 

src/autometrics/decorator.py

@@ -1,19 +1,28 @@
 """Autometrics module."""
+from contextvars import ContextVar
 import time
 import inspect
 
 from functools import wraps
 from typing import overload, TypeVar, Callable, Optional, Awaitable
 from typing_extensions import ParamSpec
+
 from .objectives import Objective
 from .tracker import get_tracker, Result
-from .utils import get_module_name, get_caller_function, append_docs_to_docstring
+from .utils import (
+    get_function_name,
+    get_module_name,
+    append_docs_to_docstring,
+)
 
 
 P = ParamSpec("P")
 T = TypeVar("T")
 
 
+caller_var: ContextVar[str] = ContextVar("caller", default="")
+
+
 # Bare decorator usage
 @overload
 def autometrics(func: Callable[P, T]) -> Callable[P, T]:
@@ -85,15 +94,17 @@ def sync_decorator(func: Callable[P, T]) -> Callable[P, T]:
         """Helper for decorating synchronous functions, to track calls and duration."""
 
         module_name = get_module_name(func)
-        func_name = func.__name__
+        func_name = get_function_name(func)
         register_function_info(func_name, module_name)
 
         @wraps(func)
         def sync_wrapper(*args: P.args, **kwds: P.kwargs) -> T:
             start_time = time.time()
-            caller = get_caller_function()
+            caller = caller_var.get()
+            context_token = None
 
             try:
+                context_token = caller_var.set(func_name)
                 if track_concurrency:
                     track_start(module=module_name, function=func_name)
                 result = func(*args, **kwds)
@@ -111,6 +122,11 @@ def sync_wrapper(*args: P.args, **kwds: P.kwargs) -> T:
                 )
                 # Reraise exception
                 raise exception
+
+            finally:
+                if context_token is not None:
+                    caller_var.reset(context_token)
+
             return result
 
         sync_wrapper.__doc__ = append_docs_to_docstring(func, func_name, module_name)
@@ -120,15 +136,17 @@ def async_decorator(func: Callable[P, Awaitable[T]]) -> Callable[P, Awaitable[T]
         """Helper for decorating async functions, to track calls and duration."""
 
         module_name = get_module_name(func)
-        func_name = func.__name__
+        func_name = get_function_name(func)
         register_function_info(func_name, module_name)
 
         @wraps(func)
         async def async_wrapper(*args: P.args, **kwds: P.kwargs) -> T:
             start_time = time.time()
-            caller = get_caller_function()
+            caller = caller_var.get()
+            context_token = None
 
             try:
+                context_token = caller_var.set(func_name)
                 if track_concurrency:
                     track_start(module=module_name, function=func_name)
                 result = await func(*args, **kwds)
@@ -146,6 +164,11 @@ async def async_wrapper(*args: P.args, **kwds: P.kwargs) -> T:
                 )
                 # Reraise exception
                 raise exception
+
+            finally:
+                if context_token is not None:
+                    caller_var.reset(context_token)
+
             return result
 
         async_wrapper.__doc__ = append_docs_to_docstring(func, func_name, module_name)

src/autometrics/test_caller.py

@@ -0,0 +1,43 @@
+"""Tests for caller tracking."""
+from functools import wraps
+from prometheus_client.exposition import generate_latest
+
+from .decorator import autometrics
+
+
+def test_caller_detection():
+    """This is a test to see if the caller is properly detected."""
+
+    def dummy_decorator(func):
+        @wraps(func)
+        def dummy_wrapper(*args, **kwargs):
+            return func(*args, **kwargs)
+
+        return dummy_wrapper
+
+    def another_decorator(func):
+        @wraps(func)
+        def another_wrapper(*args, **kwargs):
+            return func(*args, **kwargs)
+
+        return another_wrapper
+
+    @dummy_decorator
+    @autometrics
+    @another_decorator
+    def foo():
+        pass
+
+    @autometrics
+    def bar():
+        foo()
+
+    bar()
+
+    blob = generate_latest()
+    assert blob is not None
+    data = blob.decode("utf-8")
+
+    expected = """function_calls_count_total{caller="test_caller_detection.<locals>.bar",function="test_caller_detection.<locals>.foo",module="autometrics.test_caller",objective_name="",objective_percentile="",result="ok"} 1.0"""
+    assert "wrapper" not in data
+    assert expected in data