Skip to content

Conversation

Pouyanpi
Copy link
Collaborator

@Pouyanpi Pouyanpi commented Oct 2, 2025

Stack Info

This PR is part of a stack:

  1. refactor!: drop reasoning trace extraction logic #1427
  2. feat: add reasoning trace extraction from llm calls #1431
  3. feat: emit BotThinking events with reasoning traces #1432
  4. feat(logging): improve event logging and add bot thinking display #1434 (this PR)

⚠️ Depends on:

#1427#1431#1432

Description

Enhanced event logging in the runtime and callbacks to better display bot thinking events with reasoning traces. Moved event logging to occur after event generation for proper ordering, added reasoning content extraction from LLM completions, and improved console output formatting for different event types.

Changes

  • nemoguardrails/colang/v1_0/runtime/runtime.py: Moved event logging to occur after events are generated to ensure proper logging order
  • nemoguardrails/logging/callbacks.py: Extract and include reasoning_content from ChatGeneration messages in completion logs
  • nemoguardrails/logging/verbose.py: Add special formatting for BotThinking events and improve action event display
  • tests/test_runtime_event_logging.py: Add comprehensive tests for event logging behavior including BotThinking, BotMessage, ContextUpdate events and ordering

@Pouyanpi Pouyanpi self-assigned this Oct 2, 2025
@Pouyanpi Pouyanpi added this to the v0.18.0 milestone Oct 2, 2025
@codecov-commenter
Copy link

Codecov Report

❌ Patch coverage is 91.66667% with 2 lines in your changes missing coverage. Please review.

Files with missing lines Patch % Lines
nemoguardrails/logging/callbacks.py 88.88% 1 Missing ⚠️
nemoguardrails/logging/verbose.py 90.90% 1 Missing ⚠️

📢 Thoughts on this report? Let us know!

Copy link
Collaborator

@tgasser-nv tgasser-nv left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good, just a few small comments

bot_thinking_logs = [
record
for record in caplog.records
if "Event :: BotThinking" in record.message
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: Should we define an enum with these strings if there are a static set of events? It would be more robust to typos

for event in next_events:
if event["type"] != "EventHistoryUpdate":
event_type = event["type"]
log.info(
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: Should this be a log.debug() rather than log.info()? How much noise would this make in logs?

if event_name == "BotThinking":
title = f"[blue]{title}[/] [yellow bold]{event_name}[/]"
elif event_name.startswith("Start") and event_name.endswith("Action"):
title = f"[magenta][bold]Start[/]{event_name[5:]}[/]"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Where does the magic number 5 come from here?

elif event_name.startswith("Start") and event_name.endswith("Action"):
title = f"[magenta][bold]Start[/]{event_name[5:]}[/]"
elif event_name.endswith("ActionFinished"):
title = f"[magenta]{event_name[:-8]}[bold]Finished[/][/]"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Another magic number here, is there a danger we add longer-named events and this breaks?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants