feat(iorails): Logging and unique request ID - #1661
Conversation
|
@greptile review this PR |
Greptile SummaryThis PR successfully implements end-to-end request ID tracking and comprehensive logging throughout the Guardrails and IORails hierarchy. Key Changes:
Previous Issues Resolved:
Implementation Quality:
|
| Filename | Overview |
|---|---|
| nemoguardrails/guardrails/init.py | Added configure_logging() function with proper handler management and level updates. Previous threading issues resolved. |
| nemoguardrails/guardrails/guardrails_types.py | Implemented request ID tracking using ContextVar with new_request_id(), get_request_id(), and reset_request_id() functions. Added truncate() helper for log content. |
| nemoguardrails/guardrails/iorails.py | Integrated request ID generation and comprehensive logging throughout generate_async() with proper try/finally cleanup. |
| nemoguardrails/guardrails/model_engine.py | Added request ID logging, timing metrics, and content truncation for HTTP requests/responses. |
| nemoguardrails/guardrails/rails_manager.py | Integrated request ID logging throughout rail checks (content safety, topic safety, jailbreak detection) with content truncation. |
| tests/guardrails/test_request_id.py | Extensive tests (388 lines) for request ID propagation, context isolation, and concurrent request handling. |
Sequence Diagram
sequenceDiagram
participant Client
participant IORails
participant RailsManager
participant ModelManager
participant ModelEngine
participant ExternalAPI
Client->>IORails: generate_async(messages)
activate IORails
Note over IORails: new_request_id() generates<br/>8-char hex correlation ID
IORails->>RailsManager: is_input_safe(messages)
activate RailsManager
Note over RailsManager: get_request_id() retrieves<br/>same ID for logging
RailsManager->>ModelManager: generate_async(content_safety, messages)
activate ModelManager
ModelManager->>ModelEngine: call(messages)
activate ModelEngine
Note over ModelEngine: Logs HTTP request with<br/>request ID prefix
ModelEngine->>ExternalAPI: POST /v1/chat/completions
ExternalAPI-->>ModelEngine: Safety check response
ModelEngine-->>ModelManager: Parsed response
deactivate ModelEngine
ModelManager-->>RailsManager: Safety result
deactivate ModelManager
RailsManager-->>IORails: RailResult
deactivate RailsManager
IORails->>ModelManager: generate_async(main, messages)
Note over ModelManager: Same request ID flows through
ModelManager->>ExternalAPI: POST /v1/chat/completions
ExternalAPI-->>ModelManager: LLM response
ModelManager-->>IORails: Generated text
IORails->>RailsManager: is_output_safe(messages, response)
RailsManager->>ModelManager: generate_async(content_safety, ...)
ModelManager->>ExternalAPI: POST /v1/chat/completions
ExternalAPI-->>ModelManager: Safety check response
ModelManager-->>RailsManager: Safety result
RailsManager-->>IORails: RailResult
Note over IORails: finally: reset_request_id(token)<br/>Restores previous context
IORails-->>Client: Response message
deactivate IORails
Last reviewed commit: 5bf91ca
![greptile-apps[bot]](https://avatars.githubusercontent.com/in/867647?s=60&v=4){kind=small}
Codecov Report✅ All modified and coverable lines are covered by tests. 📢 Thoughts on this report? Let us know! |
|
@tgasser-nv reminder to examine the |
e5dbd94 to
d401df8
Compare
0d5ac90 to
7836e35
Compare
…ve duplicate log from ModelManager
|
@greptile Review this PR with latest commit SHA |
|
@greptile review latest PR and update summary and score |
|
@greptile review PR |
Pouyanpi
left a comment
Pouyanpi
left a comment
There was a problem hiding this comment.
LGTM! Thank you Tim. Please merge after looking at the comments (mostly nits).
Another note for the future works. the current approach calls get_request_id() in 11 methods and threads [%s], req_id through 37+ log lines across 5 files. This works, but it doesn't scale as every new log statement has to remember to include the request ID and forgetting it silently drops correlation.
The standard Python pattern for this is a https://docs.python.org/3/library/logging.html#filter-objects that stamps request_id onto every LogRecord automatically:
Something like:
class RequestContextFilter(logging.Filter):
def filter(self, record):
record.request_id = get_request_id()
return True
Then the formatter handle it only once ("%(asctime)s %(levelname)s [%(request_id)s]: %(message)s") and all call sites become plain log calls with no req_id boilerplate:
# we have before
req_id = get_request_id()
log.info("[%s] Running input rails", req_id)
# after
log.info("Running input rails")Not blocking this PR, but can be in the next refactoring pass.
| log.info("[%s] Output blocked: %s", req_id, output_result.reason) | ||
| return {"role": "assistant", "content": REFUSAL_MESSAGE} | ||
|
|
||
| log.info("[%s] generate_async completed", req_id) |
There was a problem hiding this comment.
only logs on happy path, blocked requests have no end marker, maybe move to finally?
This is a great idea, created NGUARD-677 to track it |
* Add trackable request ID and logging in Guardrails and below * Clean linting error * Add request ID test, remove ModelManager time logging that duplicates ModelEngine's * Use SingleUseBarrier rather than asyncio.Barrier (Python 3.11+), remove duplicate log from ModelManager * Fix configure_logging() * Clean up logging handler level changes * Fix handler shadowing * Address PR feedback * Remove redundant log line
2 participants
Description
This PR adds a unique request ID that's tracked from end-to-end and consistent logging throughout the Guardrails and IORails hierarchy,
Related Issue(s)
This is a stacked PR, review in the order of the list below:
#1638
#1649
#1654
#1656
#1658
#1660
#1661 <- This PR
Test Plan
Pre-commit
Unit-test
Chat
LLMRails
IORails
Checklist