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

Contextual logging #413

Open
wants to merge 4 commits into
base: main
Choose a base branch
from
Open

Contextual logging #413

wants to merge 4 commits into from

Conversation

mjh1
Copy link
Contributor

@mjh1 mjh1 commented Feb 6, 2025

To make debugging easier this change implements tagging of logs with some identifiers, request_id which is generated by the gateway is specific to a single session and stream_id. The runner receives the IDs from the orchestrator via request headers and configures the various loggers with them. With this change we can simply search our logs with one of the IDs and view all relevant logs (across the different apps G, O and runner).

Example:

2025-02-07 11:23:16 - root - INFO - request_id=53ac8af3 stream_id=foo Starting stream, subscribe=https://192.168.122.69:8935/ai/trickle/53ac8af3 publish=https://192.168.122.69:8935/ai/trickle/53ac8af3-out, control=https://192.168.122.69:8935/ai/trickle/53ac8af3-control, events=https://192.168.122.69:8935/ai/trickle/53ac8af3-events
2025-02-07 11:23:16,372 INFO:     172.17.0.1:59172 - "POST /live-video-to-video HTTP/1.1" 200 OK
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo Starting encoder
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo Starting Control subscriber at https://192.168.122.69:8935/ai/trickle/53ac8af3-control
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo Trickle sub No pending connection, preconnecting...
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo Trickle sub Preconnecting attempt: 0 URL: https://192.168.122.69:8935/ai/trickle/53ac8af3-control/-1
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo launching subscribe loop for https://192.168.122.69:8935/ai/trickle/53ac8af3
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo Trickle sub No pending connection, preconnecting...
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo Trickle sub Preconnecting attempt: 0 URL: https://192.168.122.69:8935/ai/trickle/53ac8af3/-1
[infer.py] 2025-02-07 11:23:16 INFO     request_id=53ac8af3 stream_id=foo HTTP server started on port 8888
[infer.py] 2025-02-07 11:23:19 INFO     request_id=53ac8af3 stream_id=foo ComfyUI Pipeline Prompt: {'1': {'_meta': {'title': 'SaveTensor'}, 'class_type': 'SaveTensor', 'inputs': {'images': ['2', 0]}}, '2': {'_meta': {'title': 'Depth Anything Tensorrt'}, 'class_type': 'DepthAnythingTensorrt', 'inputs': {'engine': 'depth_anything_vitl14-fp16.engine', 'images': ['3', 0]}}, '3': {'_meta': {'title': 'LoadTensor'}, 'class_type': 'LoadTensor', 'inputs': {}}}
[infer.py] 2025-02-07 11:23:21 INFO     request_id=53ac8af3 stream_id=foo 127.0.0.1 [07/Feb/2025:11:23:21 +0000] "GET /api/status HTTP/1.1" 200 990 "-" "-"`

My python experience is pretty limited so please let me know what I could do better. I'd particularly like to avoid the switching from logger to logging in runner/app/pipelines/live_video_to_video.py, whatever I tried it seemed like the logging.getLogger(__name__) logger wouldn't have the ContextFilter filter added to it.

@mjh1 mjh1 marked this pull request as ready for review February 7, 2025 11:56
@mjh1 mjh1 requested review from rickstaa and varshith15 February 7, 2025 11:56
@@ -46,6 +44,8 @@ def __call__( # type: ignore
control_url=control_url,
events_url=events_url,
initial_params=json.dumps(params),
request_id=request_id_var.get(),
Copy link
Collaborator

Choose a reason for hiding this comment

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

@mjh1 i think instead of passing request_id everywhere, you can just add a configure_logging function in app.log, which you can just call inside the piplinestreamer class init method, that way it'll be a bit clean and all the logging params setting is localized to a single place, easier to add and remove things later on

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@varshith15 That would be great, I'm unsure of how to do that though. I won't be able to set the requestID value in a class init method right but do you just mean setting up the logger? Are you suggesting using a single logging setup and removing all these different logging configs we have?

@@ -160,12 +162,12 @@ def _setup_logging(self):

level = logging.DEBUG if os.environ.get('VERBOSE_LOGGING') == '1' else logging.INFO
logging.basicConfig(
format='%(asctime)s %(levelname)-8s %(message)s',
format=f"%(asctime)s %(levelname)-8s request_id={self.request_id} stream_id={self.stream_id} %(message)s",
level=level,
datefmt='%Y-%m-%d %H:%M:%S')

queue_handler = LogQueueHandler(self)
Copy link
Collaborator

@varshith15 varshith15 Feb 7, 2025

Choose a reason for hiding this comment

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

maybe adding the main queue config_logging to LogQueueHandler init should remove all this extra param passing

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I tried that in this commit but it can't even import it 😕 can you see what the issue is?

[infer.py] Traceback (most recent call last):
[infer.py]   File "/app/app/live/infer.py", line 12, in <module>
[infer.py]     from streamer import PipelineStreamer
[infer.py]   File "/app/app/live/streamer/__init__.py", line 1, in <module>
[infer.py]     from .streamer import PipelineStreamer
[infer.py]   File "/app/app/live/streamer/streamer.py", line 13, in <module>
[infer.py]     from .process import PipelineProcess
[infer.py]   File "/app/app/live/streamer/process.py", line 16, in <module>
[infer.py]     from app.log import config_logging
[infer.py] ModuleNotFoundError: No module named 'app.log'

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Is everything under app/live a totally separate app?

@mjh1 mjh1 requested a review from ecmulli February 7, 2025 19:24
def config_logging():
formatter = logging.Formatter(
"%(asctime)s - %(name)s - %(levelname)s - request_id=%(request_id)s stream_id=%(stream_id)s %(message)s",
defaults={"request_id": "", "stream_id": ""},
Copy link
Collaborator

Choose a reason for hiding this comment

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

maybe this is not needed? contextfilter is gonna add them anyway

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.

2 participants