Files
2026-07-13 13:22:34 +08:00

3232 lines
109 KiB
Python

import asyncio
import json
import os
import subprocess
import sys
import threading
import time
import uuid
import warnings
from concurrent.futures import ThreadPoolExecutor, as_completed
from dataclasses import asdict
from datetime import datetime
from unittest import mock
import pytest
from opentelemetry.sdk.trace.export import SpanExporter
import mlflow
from mlflow.entities import (
SpanEvent,
SpanLogLevel,
SpanStatusCode,
SpanType,
Trace,
TraceData,
TraceInfo,
)
from mlflow.entities.trace_location import (
MlflowExperimentLocation,
TraceLocation,
UCSchemaLocation,
)
from mlflow.entities.trace_state import TraceState
from mlflow.environment_variables import MLFLOW_TRACE_SAMPLING_RATIO, MLFLOW_TRACKING_USERNAME
from mlflow.exceptions import MlflowException
from mlflow.store.entities.paged_list import PagedList
from mlflow.store.tracking import SEARCH_TRACES_DEFAULT_MAX_RESULTS
from mlflow.tracing.client import TracingClient
from mlflow.tracing.constant import (
TRACE_SCHEMA_VERSION_KEY,
SpanAttributeKey,
TokenUsageKey,
TraceMetadataKey,
TraceTagKey,
)
from mlflow.tracing.destination import MlflowExperiment
from mlflow.tracing.export.inference_table import pop_trace
from mlflow.tracing.fluent import start_span_no_context
from mlflow.tracing.provider import (
_MLFLOW_TRACE_USER_DESTINATION,
_get_tracer,
safe_set_span_in_context,
set_destination,
)
from mlflow.tracking.fluent import _get_experiment_id
from mlflow.version import IS_TRACING_SDK_ONLY
from tests.tracing.helper import (
create_test_trace_info,
get_traces,
purge_traces,
skip_when_testing_trace_sdk,
)
class DefaultTestModel:
@mlflow.trace()
def predict(self, x, y):
z = x + y
z = self.add_one(z)
z = mlflow.trace(self.square)(z)
return z # noqa: RET504
@mlflow.trace(span_type=SpanType.LLM, name="add_one_with_custom_name", attributes={"delta": 1})
def add_one(self, z):
return z + 1
def square(self, t):
res = t**2
time.sleep(0.1)
return res
class DefaultAsyncTestModel:
@mlflow.trace()
async def predict(self, x, y):
z = x + y
z = await self.add_one(z)
z = await mlflow.trace(self.square)(z)
return z # noqa: RET504
@mlflow.trace(span_type=SpanType.LLM, name="add_one_with_custom_name", attributes={"delta": 1})
async def add_one(self, z):
return z + 1
async def square(self, t):
res = t**2
time.sleep(0.1)
return res
class StreamTestModel:
@mlflow.trace(output_reducer=lambda x: sum(x))
def predict_stream(self, x, y):
z = x + y
for i in range(z):
yield i
# Generator with a normal func
for i in range(z):
yield self.square(i)
# Nested generator
yield from self.generate_numbers(z)
@mlflow.trace
def square(self, t):
time.sleep(0.1)
return t**2
# No output_reducer -> record the list of outputs
@mlflow.trace
def generate_numbers(self, z):
for i in range(z):
yield i
class AsyncStreamTestModel:
@mlflow.trace(output_reducer=lambda x: sum(x))
async def predict_stream(self, x, y):
z = x + y
for i in range(z):
yield i
# Generator with a normal func
for i in range(z):
yield await self.square(i)
# Nested generator
async for number in self.generate_numbers(z):
yield number
@mlflow.trace
async def square(self, t):
await asyncio.sleep(0.1)
return t**2
@mlflow.trace
async def generate_numbers(self, z):
for i in range(z):
yield i
class ErroringTestModel:
@mlflow.trace()
def predict(self, x, y):
return self.some_operation_raise_error(x, y)
@mlflow.trace()
def some_operation_raise_error(self, x, y):
raise ValueError("Some error")
class ErroringAsyncTestModel:
@mlflow.trace()
async def predict(self, x, y):
return await self.some_operation_raise_error(x, y)
@mlflow.trace()
async def some_operation_raise_error(self, x, y):
raise ValueError("Some error")
class ErroringStreamTestModel:
@mlflow.trace
def predict_stream(self, x):
for i in range(x):
if i > 0:
# Ensure distinct start_time_ns on Windows for deterministic span ordering
time.sleep(0.001)
yield self.some_operation_raise_error(i)
@mlflow.trace
def some_operation_raise_error(self, i):
if i >= 1:
raise ValueError("Some error")
return i
@pytest.fixture
def mock_client():
client = mock.MagicMock()
with mock.patch("mlflow.tracing.fluent.TracingClient", return_value=client):
yield client
@pytest.fixture
def mock_otel_trace_start_time():
# mock the start time of a trace, ensuring the root span has
# a smaller start time than child spans.
with mock.patch("opentelemetry.sdk.trace.time_ns", return_value=0):
yield
@pytest.mark.parametrize("with_active_run", [True, False])
@pytest.mark.parametrize("wrap_sync_func", [True, False])
def test_trace(wrap_sync_func, with_active_run, async_logging_enabled):
model = DefaultTestModel() if wrap_sync_func else DefaultAsyncTestModel()
if with_active_run:
if IS_TRACING_SDK_ONLY:
pytest.skip("Skipping test because mlflow or mlflow-skinny is not installed.")
with mlflow.start_run() as run:
model.predict(2, 5) if wrap_sync_func else asyncio.run(model.predict(2, 5))
run_id = run.info.run_id
else:
model.predict(2, 5) if wrap_sync_func else asyncio.run(model.predict(2, 5))
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
traces = get_traces()
assert len(traces) == 1
trace = traces[0]
assert trace.info.trace_id is not None
assert trace.info.experiment_id == _get_experiment_id()
assert trace.info.execution_time_ms >= 0.1 * 1e3 # at least 0.1 sec
assert trace.info.state == TraceState.OK
assert trace.info.request_metadata[TraceMetadataKey.INPUTS] == '{"x": 2, "y": 5}'
assert trace.info.request_metadata[TraceMetadataKey.OUTPUTS] == "64"
if with_active_run:
assert trace.info.request_metadata[TraceMetadataKey.SOURCE_RUN] == run_id
assert trace.data.request == '{"x": 2, "y": 5}'
assert trace.data.response == "64"
assert len(trace.data.spans) == 3
span_name_to_span = {span.name: span for span in trace.data.spans}
root_span = span_name_to_span["predict"]
# TODO: Trace info timestamp is not accurate because it is not adjusted to exclude the latency
# assert root_span.start_time_ns // 1e6 == trace.info.timestamp_ms
assert root_span.parent_id is None
assert root_span.attributes == {
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanFunctionName": "predict",
"mlflow.spanType": "UNKNOWN",
"mlflow.spanLogLevel": SpanLogLevel.DEBUG,
"mlflow.spanInputs": {"x": 2, "y": 5},
"mlflow.spanOutputs": 64,
}
child_span_1 = span_name_to_span["add_one_with_custom_name"]
assert child_span_1.parent_id == root_span.span_id
assert child_span_1.attributes == {
"delta": 1,
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanFunctionName": "add_one",
"mlflow.spanType": "LLM",
"mlflow.spanLogLevel": SpanLogLevel.INFO,
"mlflow.spanInputs": {"z": 7},
"mlflow.spanOutputs": 8,
}
child_span_2 = span_name_to_span["square"]
assert child_span_2.parent_id == root_span.span_id
assert child_span_2.start_time_ns <= child_span_2.end_time_ns - 0.1 * 1e6
assert child_span_2.attributes == {
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanFunctionName": "square",
"mlflow.spanType": "UNKNOWN",
"mlflow.spanLogLevel": SpanLogLevel.DEBUG,
"mlflow.spanInputs": {"t": 8},
"mlflow.spanOutputs": 64,
}
def test_deep_trace_is_not_corrupted_by_aggregation(async_logging_enabled):
# Regression test for #24344: a trace nested deeper than the recursion limit used to
# raise RecursionError while aggregating token usage during root-span finalization,
# aborting export and leaving the trace permanently stuck IN_PROGRESS with corrupted
# span data. The trace must (a) finalize to a terminal state and be loadable, and
# (b) still aggregate token usage correctly across multiple LLM spans.
depth = 1100 # > sys.getrecursionlimit() default of 1000
# A deep backbone (no usage) that exceeds the recursion limit...
spans = [start_span_no_context("root", span_type=SpanType.AGENT)]
for i in range(depth):
spans.append(start_span_no_context(f"level_{i}", parent_span=spans[-1]))
# ...ending in a fan of sibling LLM leaves that each carry usage. None is an ancestor
# of another, so aggregation must SUM all of them (3 * {10, 5, 15}).
backbone_leaf = spans[-1]
for j in range(3):
leaf = start_span_no_context(f"llm_{j}", span_type=SpanType.LLM, parent_span=backbone_leaf)
leaf.set_attribute(
SpanAttributeKey.CHAT_USAGE,
{
TokenUsageKey.INPUT_TOKENS: 10,
TokenUsageKey.OUTPUT_TOKENS: 5,
TokenUsageKey.TOTAL_TOKENS: 15,
},
)
leaf.end()
for s in reversed(spans):
s.end()
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
trace_id = spans[0].trace_id
trace = mlflow.get_trace(trace_id)
assert trace is not None
assert trace.info.state == TraceState.OK
assert trace.info.token_usage == {
TokenUsageKey.INPUT_TOKENS: 30,
TokenUsageKey.OUTPUT_TOKENS: 15,
TokenUsageKey.TOTAL_TOKENS: 45,
}
@pytest.mark.parametrize("wrap_sync_func", [True, False])
def test_trace_stream(wrap_sync_func):
model = StreamTestModel() if wrap_sync_func else AsyncStreamTestModel()
stream = model.predict_stream(1, 2)
# Trace should not be logged until the generator is consumed
assert get_traces() == []
# The span should not be set to active
# because the generator is not yet consumed
assert mlflow.get_current_active_span() is None
chunks = []
if wrap_sync_func:
for chunk in stream:
chunks.append(chunk)
# The `predict` span should not be active here.
assert mlflow.get_current_active_span() is None
else:
async def consume_stream():
async for chunk in stream:
chunks.append(chunk)
assert mlflow.get_current_active_span() is None
asyncio.run(consume_stream())
traces = get_traces()
assert len(traces) == 1
trace = traces[0]
assert trace.info.trace_id is not None
assert trace.info.experiment_id == _get_experiment_id()
assert trace.info.execution_time_ms >= 0.1 * 1e3 # at least 0.1 sec
assert trace.info.status == SpanStatusCode.OK
metadata = trace.info.request_metadata
assert metadata[TraceMetadataKey.INPUTS] == '{"x": 1, "y": 2}'
assert metadata[TraceMetadataKey.OUTPUTS] == "11" # sum of the outputs
assert len(trace.data.spans) == 5 # 1 root span + 3 square + 1 generate_numbers
root_span = trace.data.spans[0]
assert root_span.name == "predict_stream"
assert root_span.inputs == {"x": 1, "y": 2}
assert root_span.outputs == 11
assert len(root_span.events) == 9
assert root_span.events[0].name == "mlflow.chunk.item.0"
assert root_span.events[0].attributes == {"mlflow.chunk.value": "0"}
assert root_span.events[8].name == "mlflow.chunk.item.8"
# Spans for the chid 'square' function
for i in range(3):
assert trace.data.spans[i + 1].name == "square"
assert trace.data.spans[i + 1].inputs == {"t": i}
assert trace.data.spans[i + 1].outputs == i**2
assert trace.data.spans[i + 1].parent_id == root_span.span_id
# Span for the 'generate_numbers' function
assert trace.data.spans[4].name == "generate_numbers"
assert trace.data.spans[4].inputs == {"z": 3}
assert trace.data.spans[4].outputs == [0, 1, 2] # list of outputs
assert len(trace.data.spans[4].events) == 3
def test_trace_with_databricks_tracking_uri(databricks_tracking_uri, monkeypatch):
monkeypatch.setenv("MLFLOW_EXPERIMENT_NAME", "test")
monkeypatch.setenv(MLFLOW_TRACKING_USERNAME.name, "bob")
monkeypatch.setattr(mlflow.tracking.context.default_context, "_get_source_name", lambda: "test")
model = DefaultTestModel()
mock_trace_info = mock.MagicMock()
mock_trace_info.trace_id = "123"
mock_trace_info.trace_location = mock.MagicMock()
mock_trace_info.trace_location.uc_schema = None
with (
mock.patch(
"mlflow.tracing.client.TracingClient._upload_trace_data"
) as mock_upload_trace_data,
mock.patch("mlflow.tracing.client._get_store") as mock_get_store,
):
mock_get_store().start_trace.return_value = mock_trace_info
model.predict(2, 5)
mlflow.flush_trace_async_logging(terminate=True)
mock_get_store().start_trace.assert_called_once()
mock_upload_trace_data.assert_called_once()
# NB: async logging should be no-op for model serving,
# but we test it here to make sure it doesn't break
@skip_when_testing_trace_sdk
def test_trace_in_databricks_model_serving(
mock_databricks_serving_with_tracing_env, async_logging_enabled
):
# Dummy flask app for prediction
import flask
from mlflow.pyfunc.context import Context, set_prediction_context
app = flask.Flask(__name__)
@app.route("/invocations", methods=["POST"])
def predict():
data = json.loads(flask.request.data.decode("utf-8"))
request_id = flask.request.headers.get("X-Request-ID")
with set_prediction_context(Context(request_id=request_id)):
prediction = TestModel().predict(**data)
trace = pop_trace(request_id=request_id)
result = json.dumps(
{
"prediction": prediction,
"trace": trace,
},
default=str,
)
return flask.Response(response=result, status=200, mimetype="application/json")
class TestModel:
@mlflow.trace()
def predict(self, x, y):
z = x + y
z = self.add_one(z)
with mlflow.start_span(name="square") as span:
z = self.square(z)
span.add_event(SpanEvent("event", 0, attributes={"foo": "bar"}))
return z
@mlflow.trace(span_type=SpanType.LLM, name="custom", attributes={"delta": 1})
def add_one(self, z):
return z + 1
def square(self, t):
return t**2
# Mimic scoring request
databricks_request_id = "request-12345"
response = app.test_client().post(
"/invocations",
headers={"X-Request-ID": databricks_request_id},
data=json.dumps({"x": 2, "y": 5}),
)
assert response.status_code == 200
assert response.json["prediction"] == 64
trace_dict = response.json["trace"]
trace = Trace.from_dict(trace_dict)
assert trace.info.trace_id.startswith("tr-")
assert trace.info.client_request_id == databricks_request_id
assert trace.info.request_metadata[TRACE_SCHEMA_VERSION_KEY] == "3"
assert len(trace.data.spans) == 3
span_name_to_span = {span.name: span for span in trace.data.spans}
root_span = span_name_to_span["predict"]
assert isinstance(root_span._trace_id, str)
assert isinstance(root_span.span_id, str)
assert isinstance(root_span.start_time_ns, int)
assert isinstance(root_span.end_time_ns, int)
assert root_span.status.status_code.value == "OK"
assert root_span.status.description == ""
assert root_span.attributes == {
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": SpanType.UNKNOWN,
"mlflow.spanLogLevel": SpanLogLevel.DEBUG,
"mlflow.spanFunctionName": "predict",
"mlflow.spanInputs": {"x": 2, "y": 5},
"mlflow.spanOutputs": 64,
}
assert root_span.events == []
child_span_1 = span_name_to_span["custom"]
assert child_span_1.parent_id == root_span.span_id
assert child_span_1.attributes == {
"delta": 1,
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": SpanType.LLM,
"mlflow.spanLogLevel": SpanLogLevel.INFO,
"mlflow.spanFunctionName": "add_one",
"mlflow.spanInputs": {"z": 7},
"mlflow.spanOutputs": 8,
}
assert child_span_1.events == []
child_span_2 = span_name_to_span["square"]
assert child_span_2.parent_id == root_span.span_id
assert child_span_2.attributes == {
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": SpanType.UNKNOWN,
"mlflow.spanLogLevel": SpanLogLevel.DEBUG,
}
assert asdict(child_span_2.events[0]) == {
"name": "event",
"timestamp": 0,
"attributes": {"foo": "bar"},
}
# The trace should be removed from the buffer after being retrieved
assert pop_trace(request_id=databricks_request_id) is None
# In model serving, the traces should not be stored in the fluent API buffer
traces = get_traces()
assert len(traces) == 0
@skip_when_testing_trace_sdk
def test_trace_in_model_evaluation(monkeypatch, async_logging_enabled):
from mlflow.pyfunc.context import Context, set_prediction_context
monkeypatch.setenv(MLFLOW_TRACKING_USERNAME.name, "bob")
monkeypatch.setattr(mlflow.tracking.context.default_context, "_get_source_name", lambda: "test")
class TestModel:
@mlflow.trace()
def predict(self, x, y):
return x + y
model = TestModel()
# mock _upload_trace_data to avoid generating trace data file
with mlflow.start_run() as run:
run_id = run.info.run_id
request_id_1 = "tr-eval-123"
with set_prediction_context(Context(request_id=request_id_1, is_evaluate=True)):
model.predict(1, 2)
request_id_2 = "tr-eval-456"
with set_prediction_context(Context(request_id=request_id_2, is_evaluate=True)):
model.predict(3, 4)
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
trace = mlflow.get_trace(request_id_1)
assert trace.info.request_metadata[TraceMetadataKey.SOURCE_RUN] == run_id
assert trace.info.tags[TraceTagKey.EVAL_REQUEST_ID] == request_id_1
trace = mlflow.get_trace(request_id_2)
assert trace.info.request_metadata[TraceMetadataKey.SOURCE_RUN] == run_id
assert trace.info.tags[TraceTagKey.EVAL_REQUEST_ID] == request_id_2
@pytest.mark.parametrize("sync", [True, False])
def test_trace_handle_exception_during_prediction(sync):
# This test is to make sure that the exception raised by the main prediction
# logic is raised properly and the trace is still logged.
model = ErroringTestModel() if sync else ErroringAsyncTestModel()
with pytest.raises(ValueError, match=r"Some error"):
model.predict(2, 5) if sync else asyncio.run(model.predict(2, 5))
# Trace should be logged even if the function fails, with status code ERROR
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert trace.info.trace_id is not None
assert trace.info.state == TraceState.ERROR
assert trace.info.request_metadata[TraceMetadataKey.INPUTS] == '{"x": 2, "y": 5}'
assert trace.info.request_metadata[TraceMetadataKey.OUTPUTS] == ""
assert trace.data.request == '{"x": 2, "y": 5}'
assert trace.data.response is None
assert len(trace.data.spans) == 2
def test_trace_handle_exception_during_streaming():
model = ErroringStreamTestModel()
stream = model.predict_stream(2)
chunks = []
with pytest.raises(ValueError, match=r"Some error"): # noqa: PT012
for chunk in stream:
chunks.append(chunk)
# The test model raises an error after the first chunk
assert len(chunks) == 1
traces = get_traces()
assert len(traces) == 1
trace = traces[0]
assert trace.info.state == TraceState.ERROR
assert trace.info.request_metadata[TraceMetadataKey.INPUTS] == '{"x": 2}'
# The test model is expected to produce three spans
# 1. Root span (error - inherited from the child)
# 2. First chunk span (OK)
# 3. Second chunk span (error)
spans = trace.data.spans
assert len(spans) == 3
assert spans[0].name == "predict_stream"
assert spans[0].status.status_code == SpanStatusCode.ERROR
assert spans[1].name == "some_operation_raise_error"
assert spans[1].status.status_code == SpanStatusCode.OK
assert spans[2].name == "some_operation_raise_error"
assert spans[2].status.status_code == SpanStatusCode.ERROR
# One chunk event + one exception event
assert len(spans[0].events) == 2
assert spans[0].events[0].name == "mlflow.chunk.item.0"
assert spans[0].events[1].name == "exception"
@pytest.mark.parametrize(
"model",
[
DefaultTestModel(),
DefaultAsyncTestModel(),
StreamTestModel(),
AsyncStreamTestModel(),
],
)
def test_trace_ignore_exception(monkeypatch, model):
# This test is to make sure that the main prediction logic is not affected
# by the exception raised by the tracing logic.
def _call_model_and_assert_output(model):
if isinstance(model, DefaultTestModel):
output = model.predict(2, 5)
assert output == 64
elif isinstance(model, DefaultAsyncTestModel):
output = asyncio.run(model.predict(2, 5))
assert output == 64
elif isinstance(model, StreamTestModel):
stream = model.predict_stream(2, 5)
assert len(list(stream)) == 21
elif isinstance(model, AsyncStreamTestModel):
astream = model.predict_stream(2, 5)
async def _consume_stream():
return [chunk async for chunk in astream]
stream = asyncio.run(_consume_stream())
assert len(list(stream)) == 21
else:
raise ValueError("Unknown model type")
# Exception during starting span: trace should not be logged.
with mock.patch("mlflow.tracing.provider._get_tracer", side_effect=ValueError("Some error")):
_call_model_and_assert_output(model)
assert get_traces() == []
# Exception during ending span: trace should not be logged.
tracer = _get_tracer(__name__)
def _always_fail(*args, **kwargs):
raise ValueError("Some error")
monkeypatch.setattr(tracer.span_processor, "on_end", _always_fail)
_call_model_and_assert_output(model)
assert len(get_traces()) == 0
def test_trace_skip_resolving_unrelated_tags_to_traces():
with mock.patch("mlflow.tracking.context.registry.DatabricksRepoRunContext") as mock_context:
mock_context.in_context.return_value = ["unrelated tags"]
model = DefaultTestModel()
model.predict(2, 5)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert "unrelated tags" not in trace.info.tags
# Tracing SDK doesn't have `create_experiment` support
@skip_when_testing_trace_sdk
def test_trace_with_experiment_id():
exp_1 = mlflow.create_experiment("exp_1")
exp_2 = mlflow.set_experiment("exp_2").experiment_id # active experiment
@mlflow.trace(trace_destination=MlflowExperiment(exp_1))
def predict_1():
with mlflow.start_span(name="child_span"):
return
@mlflow.trace()
def predict_2():
pass
predict_1()
traces = get_traces(experiment_id=exp_1)
assert len(traces) == 1
assert traces[0].info.experiment_id == exp_1
assert len(traces[0].data.spans) == 2
assert get_traces(experiment_id=exp_2) == []
predict_2()
traces = get_traces(experiment_id=exp_2)
assert len(traces) == 1
assert traces[0].info.experiment_id == exp_2
# Tracing SDK doesn't have `create_experiment` support
@skip_when_testing_trace_sdk
def test_trace_with_experiment_id_issue_warning_when_not_root_span():
exp_1 = mlflow.create_experiment("exp_1")
@mlflow.trace(trace_destination=MlflowExperiment(exp_1))
def predict_1():
return predict_2()
@mlflow.trace(trace_destination=MlflowExperiment(exp_1))
def predict_2():
return
with mock.patch("mlflow.tracing.provider._logger") as mock_logger:
predict_1()
assert mock_logger.warning.call_count == 1
assert mock_logger.warning.call_args[0][0] == (
"The `experiment_id` parameter can only be used for root spans, but the span "
"`predict_2` is not a root span. The specified value `1` will be ignored."
)
def test_start_span_context_manager(async_logging_enabled):
datetime_now = datetime.now()
class TestModel:
def predict(self, x, y):
with mlflow.start_span(name="root_span") as root_span:
root_span.set_inputs({"x": x, "y": y})
z = x + y
with mlflow.start_span(name="child_span", span_type=SpanType.LLM) as child_span:
child_span.set_inputs(z)
z = z + 2
child_span.set_outputs(z)
child_span.set_attributes({"delta": 2, "time": datetime_now})
# Ensure deterministic span order on Windows by forcing different start_time_ns
time.sleep(0.001)
res = self.square(z)
root_span.set_outputs(res)
return res
def square(self, t):
with mlflow.start_span(name="child_span") as span:
span.set_inputs({"t": t})
res = t**2
time.sleep(0.1)
span.set_outputs(res)
return res
model = TestModel()
model.predict(1, 2)
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
traces = get_traces()
assert len(traces) == 1
trace = traces[0]
assert trace.info.trace_id is not None
assert trace.info.experiment_id == _get_experiment_id()
assert trace.info.execution_time_ms >= 0.1 * 1e3 # at least 0.1 sec
assert trace.info.state == TraceState.OK
assert trace.info.request_metadata[TraceMetadataKey.INPUTS] == '{"x": 1, "y": 2}'
assert trace.info.request_metadata[TraceMetadataKey.OUTPUTS] == "25"
assert trace.data.request == '{"x": 1, "y": 2}'
assert trace.data.response == "25"
assert len(trace.data.spans) == 3
root_span = trace.data.spans[0]
assert root_span.name == "root_span"
assert root_span.parent_id is None
assert root_span.attributes == {
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": "UNKNOWN",
"mlflow.spanLogLevel": SpanLogLevel.DEBUG,
"mlflow.spanInputs": {"x": 1, "y": 2},
"mlflow.spanOutputs": 25,
}
child_span_1 = trace.data.spans[1]
assert child_span_1.name == "child_span"
assert child_span_1.parent_id == root_span.span_id
assert child_span_1.attributes == {
"delta": 2,
"time": str(datetime_now),
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": "LLM",
"mlflow.spanLogLevel": SpanLogLevel.INFO,
"mlflow.spanInputs": 3,
"mlflow.spanOutputs": 5,
}
child_span_2 = trace.data.spans[2]
assert child_span_2.name == "child_span"
assert child_span_2.parent_id == root_span.span_id
assert child_span_2.attributes == {
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": "UNKNOWN",
"mlflow.spanLogLevel": SpanLogLevel.DEBUG,
"mlflow.spanInputs": {"t": 5},
"mlflow.spanOutputs": 25,
}
assert child_span_2.start_time_ns <= child_span_2.end_time_ns - 0.1 * 1e6
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_start_span_with_run_id(async_logging_enabled):
from mlflow.tracking import MlflowClient
client = MlflowClient()
experiment_id = client.create_experiment(f"test_experiment_{uuid.uuid4().hex}")
run = client.create_run(experiment_id=experiment_id)
with mlflow.start_span(
name="root_span",
trace_destination=MlflowExperimentLocation(experiment_id=experiment_id),
run_id=run.info.run_id,
):
pass
traces = mlflow.search_traces(
locations=[experiment_id],
return_type="list",
include_spans=False,
flush=True,
)
assert len(traces) == 1
trace_info = traces[0].info
assert trace_info.experiment_id == experiment_id
assert trace_info.request_metadata[TraceMetadataKey.SOURCE_RUN] == run.info.run_id
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_start_span_with_run_id_takes_precedence_over_active_run(async_logging_enabled):
from mlflow.tracking import MlflowClient
client = MlflowClient()
active_experiment_id = client.create_experiment(f"test_experiment_{uuid.uuid4().hex}")
explicit_experiment_id = client.create_experiment(f"test_experiment_{uuid.uuid4().hex}")
active_run = client.create_run(experiment_id=active_experiment_id)
explicit_run = client.create_run(experiment_id=explicit_experiment_id)
with mlflow.start_run(run_id=active_run.info.run_id):
with mlflow.start_span(
name="root_span",
trace_destination=MlflowExperimentLocation(experiment_id=active_experiment_id),
run_id=explicit_run.info.run_id,
):
pass
traces = mlflow.search_traces(
locations=[active_experiment_id],
return_type="list",
include_spans=False,
flush=True,
)
assert len(traces) == 1
trace_info = traces[0].info
assert trace_info.experiment_id == active_experiment_id
assert trace_info.request_metadata[TraceMetadataKey.SOURCE_RUN] == explicit_run.info.run_id
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_start_span_with_run_id_warns_for_child_span(async_logging_enabled):
from mlflow.tracking import MlflowClient
client = MlflowClient()
experiment_id = client.create_experiment(f"test_experiment_{uuid.uuid4().hex}")
run_1 = client.create_run(experiment_id=experiment_id)
run_2 = client.create_run(experiment_id=experiment_id)
with mock.patch("mlflow.tracing.fluent._logger") as mock_logger:
with mlflow.start_span(
name="root_span",
trace_destination=MlflowExperimentLocation(experiment_id=experiment_id),
run_id=run_1.info.run_id,
):
with mlflow.start_span(name="child_span", run_id=run_2.info.run_id):
pass
traces = mlflow.search_traces(
locations=[experiment_id],
return_type="list",
include_spans=False,
flush=True,
)
assert len(traces) == 1
trace_info = traces[0].info
assert trace_info.experiment_id == experiment_id
assert trace_info.request_metadata[TraceMetadataKey.SOURCE_RUN] == run_1.info.run_id
mock_logger.warning.assert_called_once_with(
"The `run_id` parameter can only be used for root spans, but the span "
f"`child_span` is not a root span. The specified value `{run_2.info.run_id}` "
"will be ignored."
)
def test_start_span_context_manager_with_imperative_apis(async_logging_enabled):
# This test is to make sure that the spans created with fluent APIs and imperative APIs
# (via MLflow client) are correctly linked together. This usage is not recommended but
# should be supported for the advanced use cases like using LangChain callbacks as a
# part of broader tracing.
class TestModel:
def predict(self, x, y):
with mlflow.start_span(name="root_span") as root_span:
root_span.set_inputs({"x": x, "y": y})
z = x + y
child_span = start_span_no_context(
name="child_span_1",
span_type=SpanType.LLM,
parent_span=root_span,
)
child_span.set_inputs(z)
z = z + 2
time.sleep(0.1)
child_span.set_outputs(z)
child_span.set_attributes({"delta": 2})
child_span.end()
root_span.set_outputs(z)
return z
model = TestModel()
model.predict(1, 2)
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
traces = get_traces()
assert len(traces) == 1
trace = traces[0]
assert trace.info.trace_id is not None
assert trace.info.experiment_id == _get_experiment_id()
assert trace.info.execution_time_ms >= 0.1 * 1e3 # at least 0.1 sec
assert trace.info.state == TraceState.OK
assert trace.info.request_metadata[TraceMetadataKey.INPUTS] == '{"x": 1, "y": 2}'
assert trace.info.request_metadata[TraceMetadataKey.OUTPUTS] == "5"
assert trace.data.request == '{"x": 1, "y": 2}'
assert trace.data.response == "5"
assert len(trace.data.spans) == 2
span_name_to_span = {span.name: span for span in trace.data.spans}
root_span = span_name_to_span["root_span"]
assert root_span.parent_id is None
assert root_span.attributes == {
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": "UNKNOWN",
"mlflow.spanLogLevel": SpanLogLevel.DEBUG,
"mlflow.spanInputs": {"x": 1, "y": 2},
"mlflow.spanOutputs": 5,
}
child_span_1 = span_name_to_span["child_span_1"]
assert child_span_1.parent_id == root_span.span_id
assert child_span_1.attributes == {
"delta": 2,
"mlflow.traceRequestId": trace.info.trace_id,
"mlflow.spanType": "LLM",
"mlflow.spanLogLevel": SpanLogLevel.INFO,
"mlflow.spanInputs": 3,
"mlflow.spanOutputs": 5,
}
def test_mlflow_trace_isolated_from_other_otel_processors():
# Set up non-MLFlow tracer
import opentelemetry.sdk.trace as trace_sdk
from opentelemetry import trace
class MockOtelExporter(trace_sdk.export.SpanExporter):
def __init__(self):
self.exported_spans = []
def export(self, spans):
self.exported_spans.extend(spans)
other_exporter = MockOtelExporter()
provider = trace_sdk.TracerProvider()
processor = trace_sdk.export.SimpleSpanProcessor(other_exporter)
provider.add_span_processor(processor)
trace.set_tracer_provider(provider)
# Create MLflow trace
with mlflow.start_span(name="mlflow_span"):
pass
# Create non-MLflow trace
tracer = trace.get_tracer(__name__)
with tracer.start_as_current_span("non_mlflow_span"):
pass
# MLflow only processes spans created with MLflow APIs
assert len(get_traces()) == 1
assert (
mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True).data.spans[0].name
== "mlflow_span"
)
# Other spans are processed by the other processor
assert len(other_exporter.exported_spans) == 1
assert other_exporter.exported_spans[0].name == "non_mlflow_span"
def test_get_trace():
with mock.patch("mlflow.tracing.display.get_display_handler") as mock_get_display_handler:
model = DefaultTestModel()
model.predict(2, 5)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
trace_id = trace.info.trace_id
mock_get_display_handler.reset_mock()
# Fetch trace from in-memory buffer
trace_in_memory = mlflow.get_trace(trace_id)
assert trace.info.trace_id == trace_in_memory.info.trace_id
mock_get_display_handler.assert_not_called()
# Fetch trace from backend
trace_from_backend = mlflow.get_trace(trace.info.trace_id)
assert trace.info.trace_id == trace_from_backend.info.trace_id
mock_get_display_handler.assert_not_called()
# If not found, return None with warning
with mock.patch("mlflow.tracing.fluent._logger") as mock_logger:
assert mlflow.get_trace("not_found") is None
mock_logger.warning.assert_called_once()
def test_test_search_traces_empty(mock_client):
mock_client.search_traces.return_value = PagedList([], token=None)
traces = mlflow.search_traces()
assert len(traces) == 0
if not IS_TRACING_SDK_ONLY:
default_columns = Trace.pandas_dataframe_columns()
assert traces.columns.tolist() == default_columns
traces = mlflow.search_traces(extract_fields=["foo.inputs.bar"])
assert traces.columns.tolist() == [*default_columns, "foo.inputs.bar"]
mock_client.search_traces.assert_called()
@pytest.mark.parametrize("return_type", ["pandas", "list"])
def test_search_traces(return_type, mock_client):
if return_type == "pandas" and IS_TRACING_SDK_ONLY:
pytest.skip("Skipping test because mlflow or mlflow-skinny is not installed.")
mock_client.search_traces.return_value = PagedList(
[
Trace(
info=create_test_trace_info(f"tr-{i}"),
data=TraceData([]),
)
for i in range(10)
],
token=None,
)
traces = mlflow.search_traces(
locations=["1"],
filter_string="name = 'foo'",
max_results=10,
order_by=["timestamp DESC"],
return_type=return_type,
)
if return_type == "pandas":
import pandas as pd
assert isinstance(traces, pd.DataFrame)
else:
assert isinstance(traces, list)
assert all(isinstance(trace, Trace) for trace in traces)
assert len(traces) == 10
mock_client.search_traces.assert_called_once_with(
experiment_ids=None,
run_id=None,
filter_string="name = 'foo'",
max_results=10,
order_by=["timestamp DESC"],
page_token=None,
model_id=None,
include_spans=True,
locations=["1"],
)
def test_search_traces_invalid_return_types(mock_client):
with pytest.raises(MlflowException, match=r"Invalid return type"):
mlflow.search_traces(return_type="invalid")
with pytest.raises(MlflowException, match=r"The `extract_fields`"):
mlflow.search_traces(extract_fields=["foo.inputs.bar"], return_type="list")
def test_search_traces_validates_experiment_ids_type():
with pytest.raises(MlflowException, match=r"locations must be a list"):
mlflow.search_traces(locations=4)
with pytest.raises(MlflowException, match=r"locations must be a list"):
mlflow.search_traces(locations="4")
def test_search_traces_with_pagination(mock_client):
traces = [
Trace(
info=create_test_trace_info(f"tr-{i}"),
data=TraceData([]),
)
for i in range(30)
]
mock_client.search_traces.side_effect = [
PagedList(traces[:10], token="token-1"),
PagedList(traces[10:20], token="token-2"),
PagedList(traces[20:], token=None),
]
traces = mlflow.search_traces(locations=["1"])
assert len(traces) == 30
common_args = {
"experiment_ids": None,
"run_id": None,
"max_results": SEARCH_TRACES_DEFAULT_MAX_RESULTS,
"filter_string": None,
"order_by": None,
"include_spans": True,
"model_id": None,
"locations": ["1"],
}
mock_client.search_traces.assert_has_calls([
mock.call(**common_args, page_token=None),
mock.call(**common_args, page_token="token-1"),
mock.call(**common_args, page_token="token-2"),
])
def test_search_traces_with_default_experiment_id(mock_client):
mock_client.search_traces.return_value = PagedList([], token=None)
with mock.patch("mlflow.tracking.fluent._get_experiment_id", return_value="123"):
mlflow.search_traces()
mock_client.search_traces.assert_called_once_with(
experiment_ids=None,
run_id=None,
filter_string=None,
max_results=SEARCH_TRACES_DEFAULT_MAX_RESULTS,
order_by=None,
page_token=None,
model_id=None,
include_spans=True,
locations=["123"],
)
@pytest.mark.parametrize(
("locations", "filter_string", "expect_warning"),
[
(["catalog.schema.prefix"], None, True),
(["catalog.schema.prefix"], "trace.timestamp_ms > '2024-01-01'", False),
(["123"], None, False),
],
)
def test_search_traces_warns_on_uc_location_without_time_range(
locations, filter_string, expect_warning, mock_client
):
mock_client.search_traces.return_value = PagedList([], token=None)
with warnings.catch_warnings(record=True) as caught:
warnings.simplefilter("always")
mlflow.search_traces(locations=locations, filter_string=filter_string)
uc_warnings = [
w
for w in caught
if issubclass(w.category, UserWarning) and "trace.timestamp_ms" in str(w.message)
]
assert bool(uc_warnings) == expect_warning
@skip_when_testing_trace_sdk
@pytest.mark.skipif(os.name == "nt", reason="Flaky on Windows")
def test_search_traces_yields_expected_dataframe_contents(monkeypatch):
model = DefaultTestModel()
expected_traces = []
for _ in range(10):
model.predict(2, 5)
time.sleep(0.1)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
expected_traces.append(trace)
df = mlflow.search_traces(max_results=10, order_by=["timestamp ASC"], flush=True)
assert df.columns.tolist() == [
"trace_id",
"trace",
"client_request_id",
"state",
"request_time",
"execution_duration",
"request",
"response",
"trace_metadata",
"tags",
"spans",
"assessments",
]
for idx, trace in enumerate(expected_traces):
assert df.iloc[idx].trace_id == trace.info.trace_id
assert Trace.from_json(df.iloc[idx].trace).info.trace_id == trace.info.trace_id
assert df.iloc[idx].client_request_id == trace.info.client_request_id
assert df.iloc[idx].state == trace.info.state
assert df.iloc[idx].request_time == trace.info.request_time
assert df.iloc[idx].execution_duration == pytest.approx(
trace.info.execution_duration, abs=1
)
assert df.iloc[idx].request == json.loads(trace.data.request)
assert df.iloc[idx].response == json.loads(trace.data.response)
assert df.iloc[idx].trace_metadata == trace.info.trace_metadata
assert df.iloc[idx].spans == [s.to_dict() for s in trace.data.spans]
assert df.iloc[idx].tags == trace.info.tags
assert df.iloc[idx].assessments == trace.info.assessments
@skip_when_testing_trace_sdk
def test_search_traces_handles_missing_response_tags_and_metadata(mock_client):
mock_client.search_traces.return_value = PagedList(
[
Trace(
info=TraceInfo(
trace_id="5",
trace_location=TraceLocation.from_experiment_id("test"),
request_time=1,
execution_duration=2,
state=TraceState.OK,
),
data=TraceData(spans=[]),
)
],
token=None,
)
df = mlflow.search_traces()
assert df["response"].isnull().all()
assert df["tags"].tolist() == [{}]
assert df["trace_metadata"].tolist() == [{}]
@skip_when_testing_trace_sdk
def test_search_traces_extracts_fields_as_expected():
model = DefaultTestModel()
model.predict(2, 5)
df = mlflow.search_traces(
extract_fields=["predict.inputs.x", "predict.outputs", "add_one_with_custom_name.inputs.z"],
flush=True,
)
assert df["predict.inputs.x"].tolist() == [2]
assert df["predict.outputs"].tolist() == [64]
assert df["add_one_with_custom_name.inputs.z"].tolist() == [7]
# no spans have the input or output with name,
# some span has an input but we're looking for output,
@skip_when_testing_trace_sdk
def test_search_traces_with_input_and_no_output():
with mlflow.start_span(name="with_input_and_no_output") as span:
span.set_inputs({"a": 1})
df = mlflow.search_traces(
extract_fields=["with_input_and_no_output.inputs.a", "with_input_and_no_output.outputs"],
flush=True,
)
assert df["with_input_and_no_output.inputs.a"].tolist() == [1]
assert df["with_input_and_no_output.outputs"].isnull().all()
@skip_when_testing_trace_sdk
def test_search_traces_with_non_dict_span_inputs_outputs():
with mlflow.start_span(name="non_dict_span") as span:
span.set_inputs(["a", "b"])
span.set_outputs([1, 2, 3])
df = mlflow.search_traces(
extract_fields=["non_dict_span.inputs", "non_dict_span.outputs", "non_dict_span.inputs.x"],
flush=True,
)
assert df["non_dict_span.inputs"].tolist() == [["a", "b"]]
assert df["non_dict_span.outputs"].tolist() == [[1, 2, 3]]
assert df["non_dict_span.inputs.x"].isnull().all()
@skip_when_testing_trace_sdk
def test_search_traces_extract_fields_preserves_standard_columns():
with mlflow.start_span(name="test_span") as span:
span.set_inputs({"x": 1})
span.set_outputs({"y": 2})
df = mlflow.search_traces(extract_fields=["test_span.inputs.x"], flush=True)
# Verify standard columns still exist
assert "trace_id" in df.columns
assert "spans" in df.columns
assert "tags" in df.columns
assert "request" in df.columns
assert "response" in df.columns
# Verify extract field was added
assert "test_span.inputs.x" in df.columns
assert df["test_span.inputs.x"].tolist() == [1]
@skip_when_testing_trace_sdk
def test_search_traces_with_multiple_spans_with_same_name():
class TestModel:
@mlflow.trace(name="duplicate_name")
def predict(self, x, y):
z = x + y
z = self.add_one(z)
z = mlflow.trace(self.square)(z)
return z # noqa: RET504
@mlflow.trace(span_type=SpanType.LLM, name="duplicate_name", attributes={"delta": 1})
def add_one(self, z):
return z + 1
def square(self, t):
res = t**2
time.sleep(0.1)
return res
model = TestModel()
model.predict(2, 5)
df = mlflow.search_traces(
extract_fields=[
"duplicate_name.inputs.x",
"duplicate_name.inputs.y",
"duplicate_name.inputs.z",
],
flush=True,
)
# Duplicate spans would all be null
assert df["duplicate_name.inputs.x"].isnull().all()
assert df["duplicate_name.inputs.y"].isnull().all()
assert df["duplicate_name.inputs.z"].tolist() == [7]
# Test a field that doesn't exist for extraction - we shouldn't throw, just return empty column
@skip_when_testing_trace_sdk
def test_search_traces_with_non_existent_field():
model = DefaultTestModel()
model.predict(2, 5)
df = mlflow.search_traces(
extract_fields=[
"predict.inputs.k",
"predict.inputs.x",
"predict.outputs",
"add_one_with_custom_name.inputs.z",
],
flush=True,
)
assert df["predict.inputs.k"].isnull().all()
assert df["predict.inputs.x"].tolist() == [2]
assert df["predict.outputs"].tolist() == [64]
assert df["add_one_with_custom_name.inputs.z"].tolist() == [7]
@skip_when_testing_trace_sdk
def test_search_traces_span_and_field_name_with_dot():
with mlflow.start_span(name="span.name") as span:
span.set_inputs({"a.b": 0})
span.set_outputs({"x.y": 1})
df = mlflow.search_traces(
extract_fields=[
"`span.name`.inputs",
"`span.name`.inputs.`a.b`",
"`span.name`.outputs",
"`span.name`.outputs.`x.y`",
],
flush=True,
)
assert df["span.name.inputs"].tolist() == [{"a.b": 0}]
assert df["span.name.inputs.a.b"].tolist() == [0]
assert df["span.name.outputs"].tolist() == [{"x.y": 1}]
assert df["span.name.outputs.x.y"].tolist() == [1]
@skip_when_testing_trace_sdk
def test_search_traces_with_run_id():
def _create_trace(name, tags=None):
with mlflow.start_span(name=name) as span:
for k, v in (tags or {}).items():
mlflow.set_trace_tag(trace_id=span.request_id, key=k, value=v)
return span.request_id
def _get_names(traces):
tags = traces["tags"].tolist()
return [tags[i].get(TraceTagKey.TRACE_NAME) for i in range(len(tags))]
with mlflow.start_run() as run1:
_create_trace(name="tr-1")
_create_trace(name="tr-2", tags={"fruit": "apple"})
with mlflow.start_run() as run2:
_create_trace(name="tr-3")
_create_trace(name="tr-4", tags={"fruit": "banana"})
_create_trace(name="tr-5", tags={"fruit": "apple"})
traces = mlflow.search_traces(flush=True)
assert set(_get_names(traces)) == {"tr-5", "tr-4", "tr-3", "tr-2", "tr-1"}
traces = mlflow.search_traces(run_id=run1.info.run_id, flush=True)
assert set(_get_names(traces)) == {"tr-2", "tr-1"}
traces = mlflow.search_traces(
run_id=run2.info.run_id,
filter_string="tag.fruit = 'apple'",
flush=True,
)
assert _get_names(traces) == ["tr-5"]
with pytest.raises(MlflowException, match="You cannot filter by run_id when it is already"):
mlflow.search_traces(
run_id=run2.info.run_id,
filter_string="metadata.mlflow.sourceRun = '123'",
)
with pytest.raises(MlflowException, match=f"Run {run1.info.run_id} belongs to"):
mlflow.search_traces(run_id=run1.info.run_id, locations=["1"])
@pytest.mark.parametrize(
"extract_fields",
[
["span.llm.inputs"],
["span.llm.inputs.x"],
["span.llm.outputs"],
],
)
@skip_when_testing_trace_sdk
def test_search_traces_invalid_extract_fields(extract_fields):
with pytest.raises(MlflowException, match="Invalid field type"):
mlflow.search_traces(extract_fields=extract_fields)
def test_get_last_active_trace_id():
assert mlflow.get_last_active_trace_id() is None
@mlflow.trace()
def predict(x, y):
return x + y
predict(1, 2)
predict(2, 5)
predict(3, 6)
trace_id = mlflow.get_last_active_trace_id()
trace = mlflow.get_trace(trace_id, flush=True)
assert trace.info.trace_id is not None
assert trace.data.request == '{"x": 3, "y": 6}'
# Mutation of the copy should not affect the original trace logged in the backend
trace.info.state = TraceState.ERROR
original_trace = mlflow.get_trace(trace.info.trace_id)
assert original_trace.info.state == TraceState.OK
def test_get_last_active_trace_thread_local():
assert mlflow.get_last_active_trace_id() is None
def run(id):
@mlflow.trace(name=f"predict_{id}")
def predict(x, y):
return x + y
predict(1, 2)
return mlflow.get_last_active_trace_id(thread_local=True)
with ThreadPoolExecutor(
max_workers=4, thread_name_prefix="test-tracing-fluent-last-active"
) as executor:
futures = [executor.submit(run, i) for i in range(10)]
trace_ids = [future.result() for future in futures]
assert len(trace_ids) == 10
for i, trace_id in enumerate(trace_ids):
trace = mlflow.get_trace(trace_id, flush=True)
assert trace.info.state == TraceState.OK
assert trace.data.spans[0].name == f"predict_{i}"
def test_trace_with_classmethod():
class TestModel:
@mlflow.trace
@classmethod
def predict(cls, x, y):
return x + y
# Call the classmethod
result = TestModel.predict(1, 2)
assert result == 3
# Get the last trace and verify inputs and outputs
trace_id = mlflow.get_last_active_trace_id()
assert trace_id is not None
trace = mlflow.get_trace(trace_id, flush=True)
assert trace is not None
assert len(trace.data.spans) > 0
# The first span should be our traced function
span = trace.data.spans[0]
assert span.name == "predict"
assert span.inputs == {"x": 1, "y": 2}
assert span.outputs == 3
def test_trace_with_classmethod_order_reversed():
class TestModel:
@classmethod
@mlflow.trace
def predict(cls, x, y):
return x + y
# Call the classmethod
result = TestModel.predict(1, 2)
assert result == 3
# Get the last trace and verify inputs and outputs
trace_id = mlflow.get_last_active_trace_id()
assert trace_id is not None
trace = mlflow.get_trace(trace_id, flush=True)
assert trace is not None
assert len(trace.data.spans) > 0
# The first span should be our traced function
span = trace.data.spans[0]
assert span.name == "predict"
assert span.inputs == {"x": 1, "y": 2}
assert span.outputs == 3
def test_trace_with_staticmethod():
class TestModel:
@mlflow.trace
@staticmethod
def predict(x, y):
return x + y
# Call the staticmethod
result = TestModel.predict(1, 2)
assert result == 3
# Get the last trace and verify inputs and outputs
trace_id = mlflow.get_last_active_trace_id()
assert trace_id is not None
trace = mlflow.get_trace(trace_id, flush=True)
assert trace is not None
assert len(trace.data.spans) > 0
# The first span should be our traced function
span = trace.data.spans[0]
assert span.name == "predict"
assert span.inputs == {"x": 1, "y": 2}
assert span.outputs == 3
def test_trace_with_staticmethod_order_reversed():
class TestModel:
@staticmethod
@mlflow.trace
def predict(x, y):
return x + y
# Call the staticmethod
result = TestModel.predict(1, 2)
assert result == 3
# Get the last trace and verify inputs and outputs
trace_id = mlflow.get_last_active_trace_id()
assert trace_id is not None
trace = mlflow.get_trace(trace_id, flush=True)
assert trace is not None
assert len(trace.data.spans) > 0
# The first span should be our traced function
span = trace.data.spans[0]
assert span.name == "predict"
assert span.inputs == {"x": 1, "y": 2}
assert span.outputs == 3
def test_update_current_trace():
@mlflow.trace(name="root_function")
def f(x):
mlflow.update_current_trace(tags={"fruit": "apple", "animal": "dog"})
return g(x) + 1
@mlflow.trace(name="level_1_function")
def g(y):
with mlflow.start_span(name="level_2_span"):
mlflow.update_current_trace(tags={"fruit": "orange", "vegetable": "carrot"})
return h(y) * 2
@mlflow.trace(name="level_3_function")
def h(z):
with mlflow.start_span(name="level_4_span"):
with mlflow.start_span(name="level_5_span"):
mlflow.update_current_trace(tags={"depth": "deep", "level": "5"})
return z + 10
f(1)
expected_tags = {
"animal": "dog",
"fruit": "orange",
"vegetable": "carrot",
"depth": "deep",
"level": "5",
}
# Validate in-memory trace
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert trace.info.state == TraceState.OK
tags = {k: v for k, v in trace.info.tags.items() if not k.startswith("mlflow.")}
assert tags == expected_tags
# Validate backend trace
traces = get_traces()
assert len(traces) == 1
assert traces[0].info.state == TraceState.OK
tags = {k: v for k, v in traces[0].info.tags.items() if not k.startswith("mlflow.")}
assert tags == expected_tags
# Verify trace can be searched by span names (only when database backend is available)
if not IS_TRACING_SDK_ONLY:
trace_by_root_span = mlflow.search_traces(
filter_string='span.name = "root_function"', return_type="list", flush=True
)
assert len(trace_by_root_span) == 1
trace_by_level_2_span = mlflow.search_traces(
filter_string='span.name = "level_2_span"', return_type="list", flush=True
)
assert len(trace_by_level_2_span) == 1
trace_by_level_5_span = mlflow.search_traces(
filter_string='span.name = "level_5_span"', return_type="list", flush=True
)
assert len(trace_by_level_5_span) == 1
# All searches should return the same trace
assert trace_by_root_span[0].info.request_id == trace.info.request_id
assert trace_by_level_2_span[0].info.request_id == trace.info.request_id
assert trace_by_level_5_span[0].info.request_id == trace.info.request_id
def test_update_current_trace_with_client_request_id():
from mlflow.tracing.trace_manager import InMemoryTraceManager
# Test updating during span execution
with mlflow.start_span("test_span") as span:
# Update with both tags and client_request_id
mlflow.update_current_trace(tags={"operation": "test"}, client_request_id="req-12345")
# Check in-memory trace during execution
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.client_request_id == "req-12345"
tags = {k: v for k, v in trace.info.tags.items() if not k.startswith("mlflow.")}
assert tags["operation"] == "test"
# Test with tags only
with mlflow.start_span("test_span_2") as span:
mlflow.update_current_trace(tags={"operation": "tags_only"})
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.client_request_id is None
tags = {k: v for k, v in trace.info.tags.items() if not k.startswith("mlflow.")}
assert tags["operation"] == "tags_only"
# Test with client_request_id only
with mlflow.start_span("test_span_3") as span:
mlflow.update_current_trace(client_request_id="req-67890")
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.client_request_id == "req-67890"
def test_update_current_trace_client_request_id_overwrites():
from mlflow.tracing.trace_manager import InMemoryTraceManager
with mlflow.start_span("overwrite_test") as span:
# First set
mlflow.update_current_trace(client_request_id="req-initial")
# Overwrite with new value
mlflow.update_current_trace(client_request_id="req-updated")
# Check during execution
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
# Should have the updated value, not the initial one
assert trace.info.client_request_id == "req-updated"
def test_update_current_trace_client_request_id_stringification():
from mlflow.tracing.trace_manager import InMemoryTraceManager
test_cases = [
(123, "123"),
(45.67, "45.67"),
(True, "True"),
(False, "False"),
(None, None), # None should remain None
(["list", "value"], "['list', 'value']"),
({"dict": "value"}, "{'dict': 'value'}"),
]
for input_value, expected_output in test_cases:
with mlflow.start_span(f"stringification_test_{input_value}") as span:
if input_value is None:
# None should not update the client_request_id
mlflow.update_current_trace(client_request_id=input_value)
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.client_request_id is None
else:
mlflow.update_current_trace(client_request_id=input_value)
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.client_request_id == expected_output
assert isinstance(trace.info.client_request_id, str)
def test_update_current_trace_with_metadata():
@mlflow.trace
def f():
mlflow.update_current_trace(
metadata={
"mlflow.source.name": "inference.py",
"mlflow.source.git.commit": "1234567890",
"mlflow.source.git.repoURL": "https://github.com/mlflow/mlflow",
"non-string-metadata": 123,
},
)
f()
expected_metadata = {
"mlflow.source.name": "inference.py",
"mlflow.source.git.commit": "1234567890",
"mlflow.source.git.repoURL": "https://github.com/mlflow/mlflow",
"non-string-metadata": "123", # Should be stringified
}
# Validate in-memory trace
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
for k, v in expected_metadata.items():
assert trace.info.trace_metadata[k] == v
# Validate backend trace
traces = get_traces()
assert len(traces) == 1
assert traces[0].info.status == "OK"
for k, v in expected_metadata.items():
assert traces[0].info.trace_metadata[k] == v
@skip_when_testing_trace_sdk
def test_update_current_trace_with_model_id():
with mlflow.start_span("test_span"):
mlflow.update_current_trace(model_id="model-123")
trace = get_traces()[0]
assert trace.info.trace_metadata[TraceMetadataKey.MODEL_ID] == "model-123"
@skip_when_testing_trace_sdk
def test_update_current_trace_should_not_raise_during_model_logging():
"""
Tracing is disabled while model logging. When the model includes
`update_current_trace` call, it should be no-op.
"""
class MyModel(mlflow.pyfunc.PythonModel):
@mlflow.trace
def predict(self, model_inputs):
mlflow.update_current_trace(tags={"fruit": "apple"})
return [model_inputs[0] + 1]
model = MyModel()
model.predict([1])
trace = get_traces()[0]
assert trace.info.state == "OK"
assert trace.info.tags["fruit"] == "apple"
purge_traces()
model_info = mlflow.pyfunc.log_model(
python_model=model,
name="model",
input_example=[0],
)
# Trace should not be generated while logging the model
assert get_traces() == []
# Signature should be inferred properly without raising any exception
assert model_info.signature is not None
assert model_info.signature.inputs is not None
assert model_info.signature.outputs is not None
# Loading back the model
loaded_model = mlflow.pyfunc.load_model(model_info.model_uri)
loaded_model.predict([1])
trace = get_traces()[0]
assert trace.info.status == "OK"
assert trace.info.tags["fruit"] == "apple"
def test_update_current_trace_with_state():
from mlflow.tracing.trace_manager import InMemoryTraceManager
# Test with TraceState enum
with mlflow.start_span("test_span") as span:
mlflow.update_current_trace(state=TraceState.ERROR)
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.state == TraceState.ERROR
# Test with string state
with mlflow.start_span("test_span_2") as span:
mlflow.update_current_trace(state="OK")
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.state == TraceState.OK
# Test with combined parameters
with mlflow.start_span("test_span_3") as span:
mlflow.update_current_trace(
state="ERROR", tags={"error_type": "validation"}, client_request_id="req-123"
)
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.state == TraceState.ERROR
assert trace.info.tags["error_type"] == "validation"
assert trace.info.client_request_id == "req-123"
def test_update_current_trace_state_none():
from mlflow.tracing.trace_manager import InMemoryTraceManager
with mlflow.start_span("test_span") as span:
# First set state to OK
mlflow.update_current_trace(state="OK")
# Then call with state=None - should not change state
mlflow.update_current_trace(state=None, tags={"test": "value"})
trace_manager = InMemoryTraceManager.get_instance()
with trace_manager.get_trace(span.trace_id) as trace:
assert trace.info.state == TraceState.OK
assert trace.info.tags["test"] == "value"
def test_update_current_trace_state_validation():
with mlflow.start_span("test_span"):
# Valid states should work
mlflow.update_current_trace(state="OK")
mlflow.update_current_trace(state="ERROR")
mlflow.update_current_trace(state=TraceState.OK)
mlflow.update_current_trace(state=TraceState.ERROR)
# Invalid string state should raise an exception
with pytest.raises(
MlflowException, match=r"State must be either 'OK' or 'ERROR', but got 'IN_PROGRESS'"
):
mlflow.update_current_trace(state="IN_PROGRESS")
# Invalid enum state should raise an exception
with pytest.raises(
MlflowException,
match=r"State must be either 'OK' or 'ERROR', but got 'STATE_UNSPECIFIED'",
):
mlflow.update_current_trace(state=TraceState.STATE_UNSPECIFIED)
# Custom invalid string should raise an exception
with pytest.raises(
MlflowException, match=r"State must be either 'OK' or 'ERROR', but got 'CUSTOM_STATE'"
):
mlflow.update_current_trace(state="CUSTOM_STATE")
# Invalid types should raise an exception with a proper error message
with pytest.raises(
MlflowException, match=r"State must be either 'OK' or 'ERROR', but got '123'"
):
mlflow.update_current_trace(state=123)
def test_span_record_exception_with_string():
with mlflow.start_span("test_span") as span:
span.record_exception("Something went wrong")
# Check persisted trace
trace = get_traces()[0]
spans = trace.data.spans
test_span = spans[0]
# Verify span status is ERROR
assert test_span.status.status_code == SpanStatusCode.ERROR
# Verify exception event was added
exception_events = [event for event in test_span.events if "exception" in event.name.lower()]
assert len(exception_events) == 1
# Verify exception message is in the event
exception_event = exception_events[0]
assert "Something went wrong" in str(exception_event.attributes)
def test_span_record_exception_with_exception():
test_exception = ValueError("Custom error message")
with mlflow.start_span("test_span") as span:
span.record_exception(test_exception)
# Check persisted trace
trace = get_traces()[0]
spans = trace.data.spans
test_span = spans[0]
# Verify span status is ERROR
assert test_span.status.status_code == SpanStatusCode.ERROR
# Verify exception event was added with proper exception details
exception_events = [event for event in test_span.events if "exception" in event.name.lower()]
assert len(exception_events) == 1
exception_event = exception_events[0]
event_attrs = str(exception_event.attributes)
assert "ValueError" in event_attrs
assert "Custom error message" in event_attrs
def test_span_record_exception_invalid_type():
with mlflow.start_span("test_span") as span:
with pytest.raises(
MlflowException,
match="The `exception` parameter must be an Exception instance or a string",
):
span.record_exception(123)
def test_combined_state_and_record_exception():
@mlflow.trace
def test_function():
# Get current span and record exception
span = mlflow.get_current_active_span()
span.record_exception("Processing failed")
# Update trace state independently
mlflow.update_current_trace(state="ERROR", tags={"error_source": "processing"})
return "result"
test_function()
# Check the trace
trace = get_traces()[0]
# Verify trace state was set to ERROR
assert trace.info.state == TraceState.ERROR
assert trace.info.tags["error_source"] == "processing"
# Verify span has exception event and ERROR state
spans = trace.data.spans
root_span = spans[0]
assert root_span.status.status_code == SpanStatusCode.ERROR
exception_events = [event for event in root_span.events if "exception" in event.name.lower()]
assert len(exception_events) == 1
assert "Processing failed" in str(exception_events[0].attributes)
def test_span_record_exception_no_op_span():
# This should not raise an exception
from mlflow.entities.span import NoOpSpan
no_op_span = NoOpSpan()
no_op_span.record_exception("This should be ignored")
# Should not create any traces
assert get_traces() == []
def test_update_current_trace_state_isolation():
with mlflow.start_span("test_span") as span:
# Set span status to OK explicitly
span.set_status("OK")
# Update trace state to ERROR
mlflow.update_current_trace(state="ERROR")
# Span status should still be OK
assert span.status.status_code == SpanStatusCode.OK
# Check the final persisted trace
trace = get_traces()[0]
assert trace.info.state == TraceState.ERROR
# Verify span status remained OK despite trace state being ERROR
spans = trace.data.spans
test_span = spans[0]
assert test_span.status.status_code == SpanStatusCode.OK
@skip_when_testing_trace_sdk
def test_non_ascii_characters_not_encoded_as_unicode():
with mlflow.start_span() as span:
span.set_inputs({"japanese": "あ", "emoji": "👍"})
trace = mlflow.get_trace(span.trace_id, flush=True)
span = trace.data.spans[0]
assert span.inputs == {"japanese": "あ", "emoji": "👍"}
_SAMPLE_REMOTE_TRACE = {
"info": {
"request_id": "2e72d64369624e6888324462b62dc120",
"experiment_id": "0",
"timestamp_ms": 1726145090860,
"execution_time_ms": 162,
"status": "OK",
"request_metadata": {
"mlflow.trace_schema.version": "2",
"mlflow.traceInputs": '{"x": 1}',
"mlflow.traceOutputs": '{"prediction": 1}',
},
"tags": {
"fruit": "apple",
"food": "pizza",
},
},
"data": {
"spans": [
{
"name": "remote",
"context": {
"span_id": "0x337af925d6629c01",
"trace_id": "0x05e82d1fc4486f3986fae6dd7b5352b1",
},
"parent_id": None,
"start_time": 1726145091022155863,
"end_time": 1726145091022572053,
"status_code": "OK",
"status_message": "",
"attributes": {
"mlflow.traceRequestId": '"2e72d64369624e6888324462b62dc120"',
"mlflow.spanType": '"UNKNOWN"',
"mlflow.spanInputs": '{"x": 1}',
"mlflow.spanOutputs": '{"prediction": 1}',
},
"events": [
{"name": "event", "timestamp": 1726145091022287, "attributes": {"foo": "bar"}}
],
},
{
"name": "remote-child",
"context": {
"span_id": "0xa3dde9f2ebac1936",
"trace_id": "0x05e82d1fc4486f3986fae6dd7b5352b1",
},
"parent_id": "0x337af925d6629c01",
"start_time": 1726145091022419340,
"end_time": 1726145091022497944,
"status_code": "OK",
"status_message": "",
"attributes": {
"mlflow.traceRequestId": '"2e72d64369624e6888324462b62dc120"',
"mlflow.spanType": '"UNKNOWN"',
},
"events": [],
},
],
"request": '{"x": 1}',
"response": '{"prediction": 1}',
},
}
def test_add_trace(mock_otel_trace_start_time):
# Mimic a remote service call that returns a trace as a part of the response
def dummy_remote_call():
return {"prediction": 1, "trace": _SAMPLE_REMOTE_TRACE}
@mlflow.trace
def predict(add_trace: bool):
resp = dummy_remote_call()
if add_trace:
mlflow.add_trace(resp["trace"])
return resp["prediction"]
# If we don't call add_trace, the trace from the remote service should be discarded
predict(add_trace=False)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert len(trace.data.spans) == 1
# If we call add_trace, the trace from the remote service should be merged
predict(add_trace=True)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
trace_id = trace.info.trace_id
assert trace_id is not None
assert trace.data.request == '{"add_trace": true}'
assert trace.data.response == "1"
# Remote spans should be merged
assert len(trace.data.spans) == 3
assert all(span.trace_id == trace_id for span in trace.data.spans)
parent_span, child_span, grandchild_span = trace.data.spans
assert child_span.parent_id == parent_span.span_id
assert child_span._trace_id == parent_span._trace_id
assert grandchild_span.parent_id == child_span.span_id
assert grandchild_span._trace_id == parent_span._trace_id
# Check if span information is correctly copied
rs = Trace.from_dict(_SAMPLE_REMOTE_TRACE).data.spans[0]
assert child_span.name == rs.name
assert child_span.start_time_ns == rs.start_time_ns
assert child_span.end_time_ns == rs.end_time_ns
assert child_span.status == rs.status
assert child_span.span_type == rs.span_type
assert child_span.events == rs.events
# exclude request ID attribute from comparison
for k in rs.attributes.keys() - {SpanAttributeKey.REQUEST_ID}:
assert child_span.attributes[k] == rs.attributes[k]
def test_add_trace_no_current_active_trace():
# Use the remote trace without any active trace
remote_trace = Trace.from_dict(_SAMPLE_REMOTE_TRACE)
mlflow.add_trace(remote_trace)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert len(trace.data.spans) == 3
parent_span, child_span, grandchild_span = trace.data.spans
assert parent_span.name == "Remote Trace <remote>"
rs = remote_trace.data.spans[0]
assert parent_span.start_time_ns == rs.start_time_ns - 1
assert parent_span.end_time_ns == rs.end_time_ns
assert child_span.name == rs.name
assert child_span.parent_id is parent_span.span_id
assert child_span.start_time_ns == rs.start_time_ns
assert child_span.end_time_ns == rs.end_time_ns
assert child_span.status == rs.status
assert child_span.span_type == rs.span_type
assert child_span.events == rs.events
assert grandchild_span.parent_id == child_span.span_id
# exclude request ID attribute from comparison
for k in rs.attributes.keys() - {SpanAttributeKey.REQUEST_ID}:
assert child_span.attributes[k] == rs.attributes[k]
def test_add_trace_specific_target_span(mock_otel_trace_start_time):
span = start_span_no_context(name="parent")
mlflow.add_trace(_SAMPLE_REMOTE_TRACE, target=span)
span.end()
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert len(trace.data.spans) == 3
parent_span, child_span, grandchild_span = trace.data.spans
assert parent_span.span_id == span.span_id
rs = Trace.from_dict(_SAMPLE_REMOTE_TRACE).data.spans[0]
assert child_span.name == rs.name
assert child_span.parent_id is parent_span.span_id
assert grandchild_span.parent_id == child_span.span_id
def test_add_trace_merge_tags():
client = TracingClient()
# Start the parent trace and merge the above trace as a child
with mlflow.start_span(name="parent") as span:
client.set_trace_tag(span.trace_id, "vegetable", "carrot")
client.set_trace_tag(span.trace_id, "food", "sushi")
mlflow.add_trace(Trace.from_dict(_SAMPLE_REMOTE_TRACE))
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
custom_tags = {k: v for k, v in trace.info.tags.items() if not k.startswith("mlflow.")}
assert custom_tags == {
"fruit": "apple",
"vegetable": "carrot",
# Tag value from the parent trace should prevail
"food": "sushi",
}
def test_add_trace_raise_for_invalid_trace():
with pytest.raises(MlflowException, match="Invalid trace object"):
mlflow.add_trace(None)
with pytest.raises(MlflowException, match="Failed to load a trace object"):
mlflow.add_trace({"info": {}, "data": {}})
in_progress_trace = Trace(
info=TraceInfo(
trace_id="123",
trace_location=TraceLocation.from_experiment_id("0"),
request_time=0,
execution_duration=0,
state=TraceState.IN_PROGRESS,
),
data=TraceData(),
)
with pytest.raises(MlflowException, match="The trace must be ended"):
mlflow.add_trace(in_progress_trace)
trace = Trace.from_dict(_SAMPLE_REMOTE_TRACE)
spans = trace.data.spans
unordered_trace = Trace(info=trace.info, data=TraceData(spans=[spans[1], spans[0]]))
with pytest.raises(MlflowException, match="Span with ID "):
mlflow.add_trace(unordered_trace)
@skip_when_testing_trace_sdk
def test_add_trace_in_databricks_model_serving(mock_databricks_serving_with_tracing_env):
from mlflow.pyfunc.context import Context, set_prediction_context
# Mimic a remote service call that returns a trace as a part of the response
def dummy_remote_call():
return {"prediction": 1, "trace": _SAMPLE_REMOTE_TRACE}
# The parent function that invokes the dummy remote service
@mlflow.trace
def predict():
resp = dummy_remote_call()
remote_trace = Trace.from_dict(resp["trace"])
mlflow.add_trace(remote_trace)
return resp["prediction"]
db_request_id = "databricks-request-id"
with set_prediction_context(Context(request_id=db_request_id)):
predict()
# Pop the trace to be written to the inference table
trace = Trace.from_dict(pop_trace(request_id=db_request_id))
assert trace.info.trace_id.startswith("tr-")
assert trace.info.client_request_id == db_request_id
assert len(trace.data.spans) == 3
assert all(span.trace_id == trace.info.trace_id for span in trace.data.spans)
parent_span, child_span, grandchild_span = trace.data.spans
assert child_span.parent_id == parent_span.span_id
assert child_span._trace_id == parent_span._trace_id
assert grandchild_span.parent_id == child_span.span_id
assert grandchild_span._trace_id == parent_span._trace_id
# Check if span information is correctly copied
rs = Trace.from_dict(_SAMPLE_REMOTE_TRACE).data.spans[0]
assert child_span.name == rs.name
assert child_span.start_time_ns == rs.start_time_ns
assert child_span.end_time_ns == rs.end_time_ns
@skip_when_testing_trace_sdk
def test_add_trace_logging_model_from_code():
with mlflow.start_run():
model_info = mlflow.pyfunc.log_model(
name="model",
python_model="tests/tracing/sample_code/model_with_add_trace.py",
input_example=[1, 2],
)
loaded_model = mlflow.pyfunc.load_model(model_info.model_uri)
# Trace should not be logged while logging / loading
assert mlflow.get_trace(mlflow.get_last_active_trace_id()) is None
loaded_model.predict(1)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert trace is not None
assert len(trace.data.spans) == 2
@pytest.mark.parametrize(
"inputs", [{"question": "Does mlflow support tracing?"}, "Does mlflow support tracing?", None]
)
@pytest.mark.parametrize("outputs", [{"answer": "Yes"}, "Yes", None])
@pytest.mark.parametrize(
"intermediate_outputs",
[
{
"retrieved_documents": ["mlflow documentation"],
"system_prompt": ["answer the question with yes or no"],
},
None,
],
)
def test_log_trace_success(inputs, outputs, intermediate_outputs):
start_time_ms = 1736144700
execution_time_ms = 5129
mlflow.log_trace(
name="test",
request=inputs,
response=outputs,
intermediate_outputs=intermediate_outputs,
start_time_ms=start_time_ms,
execution_time_ms=execution_time_ms,
)
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
if inputs is not None:
assert trace.data.request == json.dumps(inputs)
else:
assert trace.data.request is None
if outputs is not None:
assert trace.data.response == json.dumps(outputs)
else:
assert trace.data.response is None
if intermediate_outputs is not None:
assert trace.data.intermediate_outputs == intermediate_outputs
spans = trace.data.spans
assert len(spans) == 1
root_span = spans[0]
assert root_span.name == "test"
assert root_span.start_time_ns == start_time_ms * 1000000
assert root_span.end_time_ns == (start_time_ms + execution_time_ms) * 1000000
def test_set_delete_trace_tag():
with mlflow.start_span("span1") as span:
trace_id = span.trace_id
mlflow.set_trace_tag(trace_id=trace_id, key="key1", value="value1")
trace = mlflow.get_trace(trace_id=trace_id, flush=True)
assert trace.info.tags["key1"] == "value1"
mlflow.delete_trace_tag(trace_id=trace_id, key="key1")
trace = mlflow.get_trace(trace_id=trace_id, flush=True)
assert "key1" not in trace.info.tags
# Test with request_id kwarg (backward compatibility)
mlflow.set_trace_tag(request_id=trace_id, key="key3", value="value3")
trace = mlflow.get_trace(request_id=trace_id, flush=True)
assert trace.info.tags["key3"] == "value3"
mlflow.delete_trace_tag(request_id=trace_id, key="key3")
trace = mlflow.get_trace(request_id=trace_id, flush=True)
assert "key3" not in trace.info.tags
@pytest.mark.parametrize("is_databricks", [True, False])
def test_search_traces_with_run_id_validates_store_filter_string(is_databricks):
mock_store = mock.MagicMock()
mock_store.search_traces.return_value = ([], None)
mock_store.get_run.return_value = mock.MagicMock()
mock_store.get_run.return_value.info.experiment_id = "test_exp_id"
test_run_id = "test_run_123"
with (
mock.patch("mlflow.tracing.client._get_store", return_value=mock_store),
mock.patch("mlflow.tracking.fluent._get_experiment_id", return_value="test_exp_id"),
):
mlflow.search_traces(run_id=test_run_id)
expected_filter_string = f"attribute.run_id = '{test_run_id}'"
mock_store.search_traces.assert_called()
call_args = mock_store.search_traces.call_args
actual_filter_string = call_args[1]["filter_string"]
assert actual_filter_string == expected_filter_string
def test_search_traces_with_locations(mock_client):
mock_client.search_traces.return_value = PagedList([], token=None)
# Test with locations
mlflow.search_traces(locations=["catalog1.schema1", "catalog2.schema2"])
# Verify that search_traces was called with locations
mock_client.search_traces.assert_called_once()
call_kwargs = mock_client.search_traces.call_args.kwargs
assert call_kwargs["locations"] == ["catalog1.schema1", "catalog2.schema2"]
assert call_kwargs.get("experiment_ids") is None
@pytest.mark.filterwarnings("ignore::FutureWarning")
def test_search_traces_experiment_ids_deprecation_warning(mock_client):
mock_client.search_traces.return_value = PagedList([], token=None)
# Test that using experiment_ids shows a deprecation warning
with pytest.warns(FutureWarning, match="experiment_ids.*deprecated.*use.*locations"):
mlflow.search_traces(experiment_ids=["123"])
# Verify that search_traces was called and experiment_ids was converted to locations
mock_client.search_traces.assert_called_once()
call_kwargs = mock_client.search_traces.call_args.kwargs
assert call_kwargs["locations"] == ["123"]
assert call_kwargs["experiment_ids"] is None
def test_search_traces_with_sql_warehouse_id(mock_client):
mock_client.search_traces.return_value = PagedList([], token=None)
# Test with sql_warehouse_id
mlflow.search_traces(locations=["123"], sql_warehouse_id="warehouse456")
# Verify that search_traces was called with sql_warehouse_id
mock_client.search_traces.assert_called_once()
call_kwargs = mock_client.search_traces.call_args.kwargs
assert call_kwargs["locations"] == ["123"]
assert "sql_warehouse_id" not in call_kwargs
assert os.environ["MLFLOW_TRACING_SQL_WAREHOUSE_ID"] == "warehouse456"
@skip_when_testing_trace_sdk
@pytest.mark.flaky(attempts=3, condition=sys.platform == "win32")
@pytest.mark.parametrize("use_batch_processor", [False, True])
def test_set_destination_in_threads(async_logging_enabled, use_batch_processor, monkeypatch):
monkeypatch.setenv("MLFLOW_USE_BATCH_SPAN_PROCESSOR", str(use_batch_processor))
# This test makes sure `set_destination` obeys thread-local behavior.
class TestModel:
def predict(self, x):
with mlflow.start_span(name="root_span") as root_span:
def child_span_thread(z):
child_span = start_span_no_context(
name="child_span_1",
parent_span=root_span,
)
child_span.set_inputs(z)
time.sleep(0.5)
child_span.end()
thread = threading.Thread(
name="test-fluent-child-span", target=child_span_thread, args=(x + 1,)
)
thread.start()
thread.join()
return x
model = TestModel()
def func(experiment_id: str | None, x: int):
if experiment_id is not None:
set_destination(MlflowExperiment(experiment_id), context_local=True)
time.sleep(0.5)
model.predict(x)
# Main thread: global config
experiment_id1 = mlflow.create_experiment(uuid.uuid4().hex)
set_destination(MlflowExperiment(experiment_id1))
func(None, 3)
# Thread 1: context-local config
experiment_id2 = mlflow.create_experiment(uuid.uuid4().hex)
thread1 = threading.Thread(
name="test-fluent-destination-thread1", target=func, args=(experiment_id2, 3)
)
# Thread 2: context-local config
experiment_id3 = mlflow.create_experiment(uuid.uuid4().hex)
thread2 = threading.Thread(
name="test-fluent-destination-thread2", target=func, args=(experiment_id3, 40)
)
# Thread 3: no config -> fallback to global config
thread3 = threading.Thread(name="test-fluent-destination-thread3", target=func, args=(None, 40))
thread1.start()
thread2.start()
thread3.start()
thread1.join()
thread2.join()
thread3.join()
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
traces = get_traces(experiment_id1)
assert len(traces) == 2 # main thread + thread 3
assert traces[0].info.experiment_id == experiment_id1
assert len(traces[0].data.spans) == 2
assert traces[1].info.experiment_id == experiment_id1
assert len(traces[1].data.spans) == 2
for exp_id in [experiment_id2, experiment_id3]:
traces = get_traces(exp_id)
assert len(traces) == 1
assert traces[0].info.experiment_id == exp_id
assert len(traces[0].data.spans) == 2
@pytest.mark.asyncio
@skip_when_testing_trace_sdk
async def test_set_destination_in_async_contexts(async_logging_enabled):
class TestModel:
async def predict(self, x):
with mlflow.start_span(name="root_span") as root_span:
async def child_span_task(z):
child_span = start_span_no_context(
name="child_span_1",
parent_span=root_span,
)
child_span.set_inputs(z)
await asyncio.sleep(0.5)
child_span.end()
await child_span_task(x + 1)
return x
model = TestModel()
async def async_func(experiment_id: str, x: int):
set_destination(MlflowExperiment(experiment_id), context_local=True)
await asyncio.sleep(0.5)
await model.predict(x)
experiment_id1 = mlflow.create_experiment(uuid.uuid4().hex)
task1 = asyncio.create_task(async_func(experiment_id1, 3))
experiment_id2 = mlflow.create_experiment(uuid.uuid4().hex)
task2 = asyncio.create_task(async_func(experiment_id2, 40))
await asyncio.gather(task1, task2)
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
for exp_id in [experiment_id1, experiment_id2]:
traces = get_traces(exp_id)
assert len(traces) == 1
assert traces[0].info.experiment_id == exp_id
assert len(traces[0].data.spans) == 2
def test_set_destination_from_env_var_databricks_uc(monkeypatch):
monkeypatch.setenv("MLFLOW_TRACING_DESTINATION", "catalog.schema")
destination = _MLFLOW_TRACE_USER_DESTINATION.get()
assert isinstance(destination, UCSchemaLocation)
assert destination.catalog_name == "catalog"
assert destination.schema_name == "schema"
assert mlflow.get_tracking_uri() == "databricks"
@skip_when_testing_trace_sdk
def test_traces_can_be_searched_by_span_properties(async_logging_enabled):
@mlflow.trace(name="test_span")
def test_function():
return "result"
test_function()
if async_logging_enabled:
mlflow.flush_trace_async_logging(terminate=True)
traces = mlflow.search_traces(filter_string='span.name = "test_span"', return_type="list")
assert len(traces) == 1, "Should find exactly one trace with span name 'test_span'"
found_span_names = [span.name for span in traces[0].data.spans]
assert "test_span" in found_span_names
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_traces_with_full_text():
with mlflow.start_span(name="test_span") as span:
span.set_attribute("llm.inputs", "How's the result?")
span.set_attribute("llm.outputs", "the number increased 90%")
trace_id_1 = span.trace_id
with mlflow.start_span(name="test_span") as span:
span.set_outputs({"outputs": 1234567})
span.set_attribute("test", "the number increased")
trace_id_2 = span.trace_id
with mlflow.start_span(name="test_span") as span:
span.set_attribute("test", "result including 'single quotes'")
trace_id_3 = span.trace_id
traces = mlflow.search_traces(
filter_string='trace.text LIKE "%How\'s the result?%"', return_type="list", flush=True
)
assert len(traces) == 1
assert traces[0].info.trace_id == trace_id_1
traces = mlflow.search_traces(
filter_string='trace.text LIKE "%1234567%"', return_type="list", flush=True
)
assert len(traces) == 1
assert traces[0].info.trace_id == trace_id_2
traces = mlflow.search_traces(
filter_string="trace.text LIKE \"%result including 'single quotes'%\"",
return_type="list",
flush=True,
)
assert len(traces) == 1
assert traces[0].info.trace_id == trace_id_3
traces = mlflow.search_traces(
filter_string='trace.text LIKE "%increased 90%%"', return_type="list", flush=True
)
assert len(traces) == 1
assert traces[0].info.trace_id == trace_id_1
def _create_trace_with_session(session_id: str, name: str = "test_span") -> str:
with mlflow.start_span(name=name) as span:
mlflow.update_current_trace(metadata={TraceMetadataKey.TRACE_SESSION: session_id})
span.set_inputs({"input": "test"})
span.set_outputs({"output": "test"})
mlflow.flush_trace_async_logging()
return span.trace_id
def _create_trace_without_session(name: str = "test_span") -> str:
with mlflow.start_span(name=name) as span:
span.set_inputs({"input": "test"})
span.set_outputs({"output": "test"})
mlflow.flush_trace_async_logging()
return span.trace_id
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_sessions_empty():
# Create a trace without a session ID - should result in no sessions
_create_trace_without_session()
sessions = mlflow.search_sessions()
assert sessions == []
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_sessions_returns_grouped_traces():
session_id_1 = f"session-1-{uuid.uuid4().hex[:8]}"
session_id_2 = f"session-2-{uuid.uuid4().hex[:8]}"
# Create traces for session 1
trace_id_1 = _create_trace_with_session(session_id_1, "session1_trace1")
trace_id_2 = _create_trace_with_session(session_id_1, "session1_trace2")
# Create trace for session 2
trace_id_3 = _create_trace_with_session(session_id_2, "session2_trace1")
sessions = mlflow.search_sessions()
assert len(sessions) == 2
# Convert to dict keyed by session.id for easier assertions
sessions_by_id = {s.id: s for s in sessions}
assert len(sessions_by_id[session_id_1]) == 2
assert len(sessions_by_id[session_id_2]) == 1
# Verify trace IDs
session_1_trace_ids = {t.info.trace_id for t in sessions_by_id[session_id_1]}
assert trace_id_1 in session_1_trace_ids
assert trace_id_2 in session_1_trace_ids
assert sessions_by_id[session_id_2][0].info.trace_id == trace_id_3
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_sessions_respects_max_results():
session_ids = [f"session-{i}-{uuid.uuid4().hex[:8]}" for i in range(3)]
# Create one trace per session
for session_id in session_ids:
_create_trace_with_session(session_id)
sessions = mlflow.search_sessions(max_results=2)
assert len(sessions) == 2
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_sessions_skips_traces_without_session_id():
session_id = f"session-{uuid.uuid4().hex[:8]}"
# Create trace without session
_create_trace_without_session("no_session_trace")
# Create trace with session
trace_id = _create_trace_with_session(session_id, "with_session_trace")
sessions = mlflow.search_sessions()
assert len(sessions) == 1
assert len(sessions[0]) == 1
assert sessions[0][0].info.trace_id == trace_id
def test_search_sessions_validates_locations_type():
with pytest.raises(MlflowException, match=r"locations must be a list"):
mlflow.search_sessions(locations=4)
with pytest.raises(MlflowException, match=r"locations must be a list"):
mlflow.search_sessions(locations="4")
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_sessions_with_default_experiment_id():
session_id = f"session-{uuid.uuid4().hex[:8]}"
_create_trace_with_session(session_id)
# search_sessions should use the default experiment
sessions = mlflow.search_sessions()
assert len(sessions) == 1
def test_search_sessions_raises_without_experiment():
with mock.patch("mlflow.tracking.fluent._get_experiment_id", return_value=None):
with pytest.raises(MlflowException, match=r"No active experiment found"):
mlflow.search_sessions()
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_sessions_include_spans_true():
session_id = f"session-{uuid.uuid4().hex[:8]}"
_create_trace_with_session(session_id)
sessions = mlflow.search_sessions(include_spans=True)
assert len(sessions) == 1
assert len(sessions[0]) == 1
# When include_spans=True, spans should be populated
assert len(sessions[0][0].data.spans) > 0
@pytest.mark.skipif(
IS_TRACING_SDK_ONLY, reason="Skipping test because mlflow or mlflow-skinny is not installed."
)
def test_search_sessions_include_spans_false():
session_id = f"session-{uuid.uuid4().hex[:8]}"
_create_trace_with_session(session_id)
sessions = mlflow.search_sessions(include_spans=False)
assert len(sessions) == 1
assert len(sessions[0]) == 1
# When include_spans=False, spans should be empty
assert len(sessions[0][0].data.spans) == 0
@pytest.mark.parametrize("invalid_ratio", [-0.1, 1.1, -1, 2, 100])
def test_trace_decorator_sampling_ratio_validation(invalid_ratio: float):
with pytest.raises(
MlflowException, match=r"sampling_ratio_override must be between 0\.0 and 1\.0"
):
mlflow.trace(sampling_ratio_override=invalid_ratio)
@pytest.mark.parametrize(
("sampling_ratio", "num_calls", "expected_min", "expected_max"),
[
(0.0, 10, 0, 0),
(0.5, 100, 30, 70),
(1.0, 10, 10, 10),
],
)
def test_trace_decorator_sampling_ratio(
sampling_ratio: float, num_calls: int, expected_min: int, expected_max: int
):
trace_ids: list[str] = []
@mlflow.trace(sampling_ratio_override=sampling_ratio)
def traced_func():
if trace_id := mlflow.get_active_trace_id():
trace_ids.append(trace_id)
return "result"
for _ in range(num_calls):
assert traced_func() == "result"
assert expected_min <= len(trace_ids) <= expected_max
@pytest.mark.parametrize(
("outer_ratio", "inner_ratio", "expected_outer", "expected_inner"),
[
(1.0, 0.0, 5, 5), # Parent sampled -> child also sampled (inner ratio ignored)
(0.0, 1.0, 0, 0), # Parent not sampled -> child also dropped (follows parent)
],
)
def test_trace_decorator_sampling_ratio_nested(
outer_ratio: float, inner_ratio: float, expected_outer: int, expected_inner: int
):
outer_trace_ids: list[str] = []
inner_trace_ids: list[str] = []
@mlflow.trace(sampling_ratio_override=outer_ratio)
def outer():
if trace_id := mlflow.get_active_trace_id():
outer_trace_ids.append(trace_id)
return inner()
@mlflow.trace(sampling_ratio_override=inner_ratio)
def inner():
if trace_id := mlflow.get_active_trace_id():
inner_trace_ids.append(trace_id)
return "inner result"
for _ in range(5):
assert outer() == "inner result"
assert len(outer_trace_ids) == expected_outer
assert len(inner_trace_ids) == expected_inner
def test_global_sampling_ratio_nested(monkeypatch):
monkeypatch.setenv(MLFLOW_TRACE_SAMPLING_RATIO.name, "0.0")
mlflow.tracing.reset()
inner_trace_ids: list[str] = []
@mlflow.trace
def outer():
return inner()
# Inner uses sampling_ratio_override=1.0 so it would create a sampled
# root trace if the dropped parent context were not propagated.
@mlflow.trace(sampling_ratio_override=1.0)
def inner():
if trace_id := mlflow.get_active_trace_id():
inner_trace_ids.append(trace_id)
return "result"
for _ in range(5):
assert outer() == "result"
assert len(inner_trace_ids) == 0
def test_start_span_no_context_preserves_dropped_parent_context(monkeypatch):
monkeypatch.setenv(MLFLOW_TRACE_SAMPLING_RATIO.name, "0.0")
mlflow.tracing.reset()
trace_ids: list[str] = []
@mlflow.trace(sampling_ratio_override=1.0)
def child():
if trace_id := mlflow.get_active_trace_id():
trace_ids.append(trace_id)
return "result"
root = start_span_no_context("root")
nested_noop = start_span_no_context("nested_noop", parent_span=root)
with safe_set_span_in_context(nested_noop):
assert child() == "result"
assert len(trace_ids) == 0
@pytest.mark.parametrize(
("sampling_ratio", "expected_count"),
[
(0.0, 0),
(1.0, 2),
],
)
def test_trace_decorator_sampling_ratio_generator(sampling_ratio: float, expected_count: int):
trace_ids: list[str] = []
@mlflow.trace(sampling_ratio_override=sampling_ratio)
def gen():
if trace_id := mlflow.get_active_trace_id():
trace_ids.append(trace_id)
for i in range(3):
yield i
assert list(gen()) == [0, 1, 2]
assert list(gen()) == [0, 1, 2]
assert len(trace_ids) == expected_count
@pytest.mark.parametrize(
("sampling_ratio", "expected_child_count"),
[
(0.0, 0),
(1.0, 6),
],
)
def test_trace_decorator_sampling_ratio_generator_with_child_spans(
sampling_ratio: float, expected_child_count: int
):
child_trace_ids: list[str] = []
@mlflow.trace
def child_func(value):
if trace_id := mlflow.get_active_trace_id():
child_trace_ids.append(trace_id)
return value * 2
@mlflow.trace(sampling_ratio_override=sampling_ratio)
def gen():
for i in range(3):
yield child_func(i)
assert list(gen()) == [0, 2, 4]
assert list(gen()) == [0, 2, 4]
assert len(child_trace_ids) == expected_child_count
@pytest.mark.asyncio
@pytest.mark.parametrize(
("sampling_ratio", "num_calls", "expected_min", "expected_max"),
[
(0.0, 10, 0, 0),
(0.5, 100, 30, 70),
(1.0, 10, 10, 10),
],
)
async def test_trace_decorator_sampling_ratio_async(
sampling_ratio: float, num_calls: int, expected_min: int, expected_max: int
):
trace_ids: list[str] = []
@mlflow.trace(sampling_ratio_override=sampling_ratio)
async def traced_func():
if trace_id := mlflow.get_active_trace_id():
trace_ids.append(trace_id)
return "result"
for _ in range(num_calls):
assert await traced_func() == "result"
assert expected_min <= len(trace_ids) <= expected_max
@pytest.mark.asyncio
@pytest.mark.parametrize(
("sampling_ratio", "expected_count"),
[
(0.0, 0),
(1.0, 2),
],
)
async def test_trace_decorator_sampling_ratio_async_generator(
sampling_ratio: float, expected_count: int
):
trace_ids: list[str] = []
@mlflow.trace(sampling_ratio_override=sampling_ratio)
async def gen():
if trace_id := mlflow.get_active_trace_id():
trace_ids.append(trace_id)
for i in range(3):
yield i
assert [item async for item in gen()] == [0, 1, 2]
assert [item async for item in gen()] == [0, 1, 2]
assert len(trace_ids) == expected_count
@pytest.mark.asyncio
@pytest.mark.parametrize(
("sampling_ratio", "expected_child_count"),
[
(0.0, 0),
(1.0, 6),
],
)
async def test_trace_decorator_sampling_ratio_async_generator_with_child_spans(
sampling_ratio: float, expected_child_count: int
):
child_trace_ids: list[str] = []
@mlflow.trace
async def child_func(value):
if trace_id := mlflow.get_active_trace_id():
child_trace_ids.append(trace_id)
return value * 2
@mlflow.trace(sampling_ratio_override=sampling_ratio)
async def gen():
for i in range(3):
yield await child_func(i)
assert [i async for i in gen()] == [0, 2, 4]
assert [i async for i in gen()] == [0, 2, 4]
assert len(child_trace_ids) == expected_child_count
@skip_when_testing_trace_sdk
def test_trace_decorator_sampling_ratio_overrides_global():
code = """
import mlflow
trace_ids: list[str] = []
@mlflow.trace # Should respect global 0.0
def not_traced():
if trace_id := mlflow.get_active_trace_id():
trace_ids.append(trace_id)
return "not traced"
for _ in range(5):
assert not_traced() == "not traced"
assert len(trace_ids) == 0
@mlflow.trace(sampling_ratio_override=1.0) # Should override global 0.0
def traced():
if trace_id := mlflow.get_active_trace_id():
trace_ids.append(trace_id)
return "traced"
for _ in range(5):
assert traced() == "traced"
assert len(trace_ids) == 5
"""
subprocess.check_call(
[sys.executable, "-c", code],
env={
**os.environ,
"MLFLOW_TRACE_SAMPLING_RATIO": "0.0",
},
)
@mlflow.trace
def my_func():
return "hello"
def test_tracing_context_injects_metadata_and_tags():
with mlflow.tracing.context(
metadata={"custom_key": "custom_value"},
tags={"my_tag": "tag_value"},
):
my_func()
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert trace.info.request_metadata["custom_key"] == "custom_value"
assert trace.info.tags["my_tag"] == "tag_value"
# Trace created outside the block should NOT have the metadata
my_func()
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert "session" not in trace.info.request_metadata
def test_tracing_context_session_id_and_user():
with mlflow.tracing.context(session_id="sess-123", user="user-456"):
my_func()
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert trace.info.request_metadata["mlflow.trace.session"] == "sess-123"
assert trace.info.request_metadata["mlflow.trace.user"] == "user-456"
# session_id and user can coexist with explicit metadata
with mlflow.tracing.context(
session_id="sess-abc",
user="user-xyz",
metadata={"custom_key": "custom_value"},
):
my_func()
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
assert trace.info.request_metadata["mlflow.trace.session"] == "sess-abc"
assert trace.info.request_metadata["mlflow.trace.user"] == "user-xyz"
assert trace.info.request_metadata["custom_key"] == "custom_value"
def test_tracing_context_session_id_and_user_nesting():
with mlflow.tracing.context(session_id="outer-sess", user="outer-user"):
with mlflow.tracing.context(session_id="inner-sess"):
my_func()
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
# Inner session_id overrides outer
assert trace.info.request_metadata["mlflow.trace.session"] == "inner-sess"
# Outer user is inherited
assert trace.info.request_metadata["mlflow.trace.user"] == "outer-user"
def test_tracing_context_nesting_merges():
with mlflow.tracing.context(
metadata={"outer_key": "outer_val", "shared": "outer"},
tags={"outer_tag": "outer"},
):
with mlflow.tracing.context(
metadata={"inner_key": "inner_val", "shared": "inner"},
tags={"inner_tag": "inner"},
):
my_func()
trace = mlflow.get_trace(mlflow.get_last_active_trace_id(), flush=True)
# Both outer and inner metadata present
assert trace.info.request_metadata["outer_key"] == "outer_val"
assert trace.info.request_metadata["inner_key"] == "inner_val"
# Inner wins on conflict
assert trace.info.request_metadata["shared"] == "inner"
# Both tags present
assert trace.info.tags["outer_tag"] == "outer"
assert trace.info.tags["inner_tag"] == "inner"
def test_tracing_context_enabled_false_suppresses_traces():
with mlflow.tracing.context(enabled=False):
my_func()
# Child context should inherit the enabled=False from the parent
with mlflow.tracing.context(metadata={"k": "v"}):
my_func()
# Start trace with start_trace_no_context (used in autologging)
span = mlflow.start_span_no_context("test")
span.end()
assert mlflow.get_last_active_trace_id() is None
# After exiting, tracing should work normally
my_func()
assert mlflow.get_last_active_trace_id() is not None
def test_tracing_context_enabled_is_thread_safe():
def run_with_context(enabled):
with mlflow.tracing.context(enabled=enabled):
my_func()
return mlflow.get_last_active_trace_id(thread_local=True)
with ThreadPoolExecutor(
max_workers=10, thread_name_prefix="test-fluent-tracing-context"
) as pool:
futures = {
pool.submit(run_with_context, enabled=(i % 2 == 0)): (i % 2 == 0) for i in range(10)
}
for future in as_completed(futures):
enabled = futures[future]
trace_id = future.result()
assert (trace_id is not None) == enabled
def test_flush_trace_async_logging_calls_flush_when_async_queue_exists():
mock_exporter = mock.MagicMock()
with mock.patch("mlflow.tracking.fluent._get_trace_exporter", return_value=mock_exporter):
mlflow.flush_trace_async_logging(terminate=False)
mock_exporter._async_queue.flush.assert_called_once_with(terminate=False)
def test_flush_trace_async_logging_skips_when_async_queue_missing():
# A bare SpanExporter (as used by StrandsSpanProcessor, mlflow/strands/autolog.py:40)
# has no _async_queue attribute. flush_trace_async_logging(terminate=True) should return without
# reaching the error handler.
exporter = SpanExporter()
assert not hasattr(exporter, "_async_queue")
with (
mock.patch("mlflow.tracking.fluent._get_trace_exporter", return_value=exporter),
mock.patch(
"mlflow.tracking.fluent._logger.error",
side_effect=AssertionError("flush should not reach error handler"),
),
):
mlflow.flush_trace_async_logging(terminate=False)
def test_flush_trace_async_logging_no_spurious_error_when_tracing_disabled():
mlflow.tracing.disable()
with mock.patch("mlflow.tracking.fluent._logger") as mock_logger:
mlflow.flush_trace_async_logging(terminate=True)
mock_logger.error.assert_not_called()