3232 lines
109 KiB
Python
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()
|