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] integrate with Ray structured logging #46215

Merged

Conversation

GeneDer
Copy link
Contributor

@GeneDer GeneDer commented Jun 24, 2024

Why are these changes needed?

Integrated Ray structured logging into Serve's logger. Two things are done in this PR:

  1. Moved the logics to flatten serve's special key for extra logging attributes to _append_flatten_attributes() and called it from generate_record_format_attrs() so Ray structured logging can apply those nested attributes
  2. Refactored Serve's json formatter into context filters and applied them onto Serve's log handlers. Reuses core's JSONFormatter when formatting structured logs

The main difference after integrated with Ray structured logging is there are new attributes provided by Ray (e.g. node_id, filename, and lineno). Also, the message format is just the message body itself, without filename and line number prefix.

Example log before the change

{
   "levelname":"INFO",
   "asctime":"2024-06-24 22:15:34,526",
   "actor_id":"59ef544fa6127fffd1b6c4ad01000000",
   "worker_id":"ce0efd00c47b08f51a5c04e2cdfb8919ed6df4d0b4b938d3e75b4321",
   "deployment":"app_Counter",
   "replica":"j8fhh1bm",
   "component_name":"replica",
   "request_id":"6f04a2fd-db85-4687-8302-ef478e7abee8",
   "route":"/favicon.ico",
   "application":"app",
   "message":"replica.py:373 - __CALL__ OK 2.8ms"
}

Example log after the change

{
   "asctime":"2024-06-24 22:10:57,906",
   "levelname":"INFO",
   "message":"__CALL__ OK 4.3ms",
   "filename":"replica.py",
   "lineno":373,
   "worker_id":"833490a0fcc662b86c04403694c85b1d14364a05b5c6d6dfec5d5d47",
   "node_id":"1f3b2424bccc7f407fad2bf549954b723ea46405dded64d7386239a7",
   "actor_id":"b5f78e9af7148f019d9e89ab01000000",
   "route":"/favicon.ico",
   "request_id":"59f62350-7da6-47a2-a964-b6dd4e512003",
   "application":"app",
   "deployment":"app_Counter",
   "replica":"8p7guoov",
   "component_name":"replica"
}

Related issue number

Closes #46125

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: Gene Su <e870252314@gmail.com>
@GeneDer GeneDer added the go add ONLY when ready to merge, run all tests label Jun 24, 2024
Signed-off-by: Gene Su <e870252314@gmail.com>
Signed-off-by: Gene Su <e870252314@gmail.com>
Signed-off-by: Gene Su <e870252314@gmail.com>
Signed-off-by: Gene Su <e870252314@gmail.com>
Signed-off-by: Gene Su <e870252314@gmail.com>
@GeneDer GeneDer added enhancement Request for new feature and/or capability serve Ray Serve Related Issue labels Jun 25, 2024
@GeneDer GeneDer marked this pull request as ready for review June 25, 2024 06:11
@edoakes
Copy link
Contributor

edoakes commented Jun 25, 2024

As discussed offline let's pop off task_id and job_id for serve replica logs.

Also why is this now included? "serve_access_log":true

@GeneDer
Copy link
Contributor Author

GeneDer commented Jun 25, 2024

As discussed offline let's pop off task_id and job_id for serve replica logs.

Also why is this now included? "serve_access_log":true

oops, didn't pay attention, will remove serve_access_log. But basically core's formatter will take all the attributes on the log record

@kevin85421 kevin85421 self-assigned this Jun 25, 2024
Signed-off-by: Gene Su <e870252314@gmail.com>
Signed-off-by: Gene Su <e870252314@gmail.com>
Copy link
Collaborator

@jjyao jjyao left a comment

Choose a reason for hiding this comment

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

So we decided to only config "ray.serve" logger not the root logger?

python/ray/_private/ray_logging/formatters.py Outdated Show resolved Hide resolved
Co-authored-by: Jiajun Yao <jeromeyjj@gmail.com>
Signed-off-by: Gene Der Su <gdsu@ucdavis.edu>
@GeneDer
Copy link
Contributor Author

GeneDer commented Jun 26, 2024

So we decided to only config "ray.serve" logger not the root logger?

Yea, I still feel it's a bit odd (and unnecessary) for Serve to configure the root logger. We can follow up on this if there are users who wants it :)

@edoakes edoakes enabled auto-merge (squash) June 26, 2024 15:14
@edoakes edoakes disabled auto-merge June 26, 2024 15:14
@edoakes edoakes enabled auto-merge (squash) June 26, 2024 15:14
@edoakes edoakes merged commit f21b7f8 into ray-project:master Jun 26, 2024
8 checks passed
@GeneDer GeneDer deleted the integrate-core-structured-logger-into-serve branch June 26, 2024 17:00
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement Request for new feature and/or capability go add ONLY when ready to merge, run all tests serve Ray Serve Related Issue
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[Logs] Integrate Serve's logger with Core's structured logger
4 participants