Updating the NR event timestamps to more accurately reflect when

the messages were generated.
This commit is contained in:
Josh Bonczkowski 2026-03-13 14:52:28 -04:00
parent 4c1ece3379
commit 3c7d50bef8
3 changed files with 55 additions and 1 deletions

View file

@ -585,6 +585,13 @@ class NewRelicLogger(CustomLogger):
if message.get("is_response"):
event_data["is_response"] = True
# Forward actual request/response timestamp (ms) so NR uses the
# real LLM call window rather than the async-logger fire time.
# Requires newrelic>=11.2.0 which reads params["timestamp"] as
# the intrinsic event timestamp.
if "timestamp" in message:
event_data["timestamp"] = message["timestamp"]
if app and app.enabled:
app.record_custom_event("LlmChatCompletionMessage", event_data)

View file

@ -36,7 +36,7 @@ async_generator==1.10.0 # for async ollama calls
langfuse==2.59.7 # for langfuse self-hosted logging
prometheus_client==0.20.0 # for /metrics endpoint on proxy
ddtrace==2.19.0 # for advanced DD tracing / profiling
newrelic>=11.0.1,<13 # for New Relic APM and AI monitoring
newrelic>=11.2.0,<13 # for New Relic APM and AI monitoring
orjson==3.11.7 # fast /embedding responses
polars==1.31.0 # for data processing
apscheduler==3.10.4 # for resetting budget in background

View file

@ -264,6 +264,53 @@ class TestExtractAllMessagesContentDisabled:
assert "content" not in msg
class TestExtractAllMessagesTimestamps:
def setup_method(self):
self.logger = make_logger()
def test_input_messages_get_start_time_timestamp(self):
kwargs = make_kwargs(messages=[{"role": "user", "content": "Hi"}])
# make_kwargs sets start_time=1_000_000.0 and end_time=1_000_001.5
response = make_response()
messages = self.logger._extract_all_messages(
kwargs, response, response_model="gpt-4", vendor="openai"
)
input_msg = next(m for m in messages if not m.get("is_response"))
assert input_msg["timestamp"] == int(1_000_000.0 * 1000.0)
def test_output_messages_get_end_time_timestamp(self):
kwargs = make_kwargs(messages=[{"role": "user", "content": "Hi"}])
response = make_response()
messages = self.logger._extract_all_messages(
kwargs, response, response_model="gpt-4", vendor="openai"
)
output_msg = next(m for m in messages if m.get("is_response"))
assert output_msg["timestamp"] == int(1_000_001.5 * 1000.0)
def test_timestamp_forwarded_to_event_data(self):
logger = make_logger()
mock_app = MagicMock()
mock_app.enabled = True
kwargs = make_kwargs(
traceparent="00-aabbccddeeff00112233445566778899-0011223344556677-01",
messages=[{"role": "user", "content": "Hi"}],
)
response = make_response()
with patch("newrelic.agent.application", return_value=mock_app):
logger._process_success(kwargs, response, start_time=1.0, end_time=2.5)
calls = mock_app.record_custom_event.call_args_list
message_events = [c[0][1] for c in calls if c[0][0] == "LlmChatCompletionMessage"]
for event in message_events:
assert "timestamp" in event
# ---------------------------------------------------------------------------
# 6. Helper edge cases
# ---------------------------------------------------------------------------