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 855dd592c8
commit 807b8ed72d
2 changed files with 54 additions and 0 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

@ -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
# ---------------------------------------------------------------------------