Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[serve] Improve access log messages #48819

Merged
merged 17 commits into from
Nov 21, 2024

Conversation

edoakes
Copy link
Contributor

@edoakes edoakes commented Nov 20, 2024

Why are these changes needed?

Improves the Serve access log to include HTTP status information on the replica and better resemble standard log formats like uvicorn.

I'm updated the log format to:

  • Include the HTTP method, route and status code for HTTP requests like: "GET / 200".
  • Use "CALL", the method name, and "OK"/"ERROR" for DeploymentHandle calls like: "CALL method_name OK".
  • Stop logging the route information on every message and isolate it to the access log message instead. This adds clutter and it can be tied to the access log message using the request ID.
  • Stop logging the filename and line number in every log message. This has been on my TODO list for awhile after internal discussion.

Examples

Calling a handle method:

INFO 2024-11-20 13:51:44,803 default_D lswbv98w d0cadb74-9fd8-4a68-9e9a-c9ed20b091f4 -- CALL method OK 1.3ms

Calling a basic HTTP route:

INFO 2024-11-20 13:53:00,197 default_A zosusx8c 26891433-a91a-4d27-b543-0936feb5f5c1 -- GET / 200 4.1ms

Calling a wildcard HTTP route (and non-200 status code):

INFO 2024-11-20 13:53:58,102 default_A iovmsu5e 85000f14-8e31-42a5-a1f4-0fa2d39c549a -- GET /{wildcard} 422 3.7ms

Related issue number

Checks

  • I've signed off every commit(by using the -s flag, i.e., git commit -s) in this PR.
  • I've run scripts/format.sh to lint the changes in this PR.
  • I've included any doc changes needed for https://docs.ray.io/en/master/.
    • I've added any new APIs to the API Reference. For example, if I added a
      method in Tune, I've added it in doc/source/tune/api/ under the
      corresponding .rst file.
  • I've made sure the tests are passing. Note that there might be a few flaky tests, see the recent failures at https://flakey-tests.ray.io/
  • Testing Strategy
    • Unit tests
    • Release tests
    • This PR is not tested :(

Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
@edoakes edoakes added the go add ONLY when ready to merge, run all tests label Nov 20, 2024
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
@edoakes edoakes requested review from GeneDer and zcin November 20, 2024 20:08
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Copy link
Contributor

@GeneDer GeneDer left a comment

Choose a reason for hiding this comment

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

Looks great!

python/ray/serve/_private/replica.py Show resolved Hide resolved
@edoakes edoakes self-assigned this Nov 20, 2024
@edoakes edoakes enabled auto-merge (squash) November 20, 2024 20:39
@github-actions github-actions bot disabled auto-merge November 20, 2024 21:47
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Copy link
Contributor

@zcin zcin left a comment

Choose a reason for hiding this comment

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

overall lgtm!

python/ray/serve/_private/replica.py Outdated Show resolved Hide resolved
Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
@edoakes edoakes merged commit 569f7df into ray-project:master Nov 21, 2024
5 checks passed
jecsand838 pushed a commit to jecsand838/ray that referenced this pull request Dec 4, 2024
## Why are these changes needed?

Improves the Serve access log to include HTTP status information on the
replica and better resemble standard log formats like `uvicorn`.

I'm updated the log format to:

- Include the HTTP method, route and status code for HTTP requests like:
"GET / 200".
- Use "CALL", the method name, and "OK"/"ERROR" for `DeploymentHandle`
calls like: "CALL method_name OK".
- Stop logging the `route` information on every message and isolate it
to the access log message instead. This adds clutter and it can be tied
to the access log message using the request ID.
- Stop logging the filename and line number in every log message. This
has been on my TODO list for awhile after internal discussion.

### Examples

Calling a handle method:
```
INFO 2024-11-20 13:51:44,803 default_D lswbv98w d0cadb74-9fd8-4a68-9e9a-c9ed20b091f4 -- CALL method OK 1.3ms
```

Calling a basic HTTP route:
```
INFO 2024-11-20 13:53:00,197 default_A zosusx8c 26891433-a91a-4d27-b543-0936feb5f5c1 -- GET / 200 4.1ms
```

Calling a wildcard HTTP route (and non-200 status code):
```
INFO 2024-11-20 13:53:58,102 default_A iovmsu5e 85000f14-8e31-42a5-a1f4-0fa2d39c549a -- GET /{wildcard} 422 3.7ms
```

---------

Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: Connor Sanders <connor@elastiflow.com>
dentiny pushed a commit to dentiny/ray that referenced this pull request Dec 7, 2024
## Why are these changes needed?

Improves the Serve access log to include HTTP status information on the
replica and better resemble standard log formats like `uvicorn`.

I'm updated the log format to:

- Include the HTTP method, route and status code for HTTP requests like:
"GET / 200".
- Use "CALL", the method name, and "OK"/"ERROR" for `DeploymentHandle`
calls like: "CALL method_name OK".
- Stop logging the `route` information on every message and isolate it
to the access log message instead. This adds clutter and it can be tied
to the access log message using the request ID.
- Stop logging the filename and line number in every log message. This
has been on my TODO list for awhile after internal discussion.

### Examples

Calling a handle method:
```
INFO 2024-11-20 13:51:44,803 default_D lswbv98w d0cadb74-9fd8-4a68-9e9a-c9ed20b091f4 -- CALL method OK 1.3ms
```

Calling a basic HTTP route:
```
INFO 2024-11-20 13:53:00,197 default_A zosusx8c 26891433-a91a-4d27-b543-0936feb5f5c1 -- GET / 200 4.1ms
```

Calling a wildcard HTTP route (and non-200 status code):
```
INFO 2024-11-20 13:53:58,102 default_A iovmsu5e 85000f14-8e31-42a5-a1f4-0fa2d39c549a -- GET /{wildcard} 422 3.7ms
```

---------

Signed-off-by: Edward Oakes <ed.nmi.oakes@gmail.com>
Signed-off-by: hjiang <dentinyhao@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
go add ONLY when ready to merge, run all tests
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants