truss icon indicating copy to clipboard operation
truss copied to clipboard

Logging `request_id` from request header

Open varunshenoy opened this issue 5 months ago • 1 comments

:rocket: What

This PR finishes off the implementation of per request logs in Truss. Requests from Beefeater with the x-baseten-request-id header will be parsed s.t. log lines associated with a given request will be tagged with the appropriate request_id.

:computer: How

There are a couple parts to this PR:

  • We first create an asynchronous middleware function in Python. It assigns a unique request ID to each incoming HTTP request (or uses the one passed from Beefeater), logs the process using this ID, and handles exceptions by returning an error response. Finally, a message is logged to indicate the request's completion (sentinel log).
  • In many places in the server code, we replace logging with loguru, a framework that makes it easier to handle the request ID and additional keys in case we want to add them in the future.
  • The request_id key can also take on global state values in the model lifecycle. For example, it can equal MODEL_STARTUP or MODEL_LOAD based on whether a log deals with a specific request or not.
SCR-20240206-nswp

:microscope: Testing

I've written an integration test that creates three unique requests and checks the logs. It doesn't pass due to a dependency issue (see below).

Concerns/TODOs

  • [DONE] I still need to override {"asctime": "2024-02-02 21:11:46,709", "levelname": "INFO", "message": "172.17.0.1:44856 - \"POST /v1/models/model%3Apredict HTTP/1.1\" 200", "request_id": null} to show a request_id associated with the current call. Not sure what the best way to do that is.
  • [DONE] loguru is not being installed (even though I've put the dependency in every file that includes python-json-logger as a dependency.

varunshenoy avatar Feb 02 '24 01:02 varunshenoy