Skip to content

Support crt logs in 'logging' module#728

Merged
azkrishpy merged 39 commits into
mainfrom
py-logging
Apr 16, 2026
Merged

Support crt logs in 'logging' module#728
azkrishpy merged 39 commits into
mainfrom
py-logging

Conversation

@azkrishpy
Copy link
Copy Markdown
Contributor

@azkrishpy azkrishpy commented Apr 2, 2026

Issue #, if available:

Description of changes:
CRT log messages can now be routed through Python's standard logging module via the awscrt.logging module.

Usage:

import logging
from awscrt.logging import init_logging, CRT_LOG_FORMAT

handler = logging.StreamHandler()
handler.setFormatter(logging.Formatter(CRT_LOG_FORMAT))
logging.getLogger('awscrt').addHandler(handler)
init_logging(logging.DEBUG)

Note: Existing awscrt.io.init_logging() is retained for backward compatibility, however CRT cannot publish to multiple subscribers, so only one of the loggers can be initialized.

Log Example:

aws s3 cp filename s3://bucket --debug
2026-04-14 17:44:38,254 - MainThread - botocore.hooks - DEBUG - Event session-initialized: calling handler <function add_timestamp_parser at 0x7f92ec5a9160>
2026-04-14 17:44:38,254 - MainThread - botocore.hooks - DEBUG - Event session-initialized: calling handler <function register_uri_param_handler at 0x7f92ed7a9d30>
2026-04-14 17:44:38,254 - MainThread - botocore.hooks - DEBUG - Event session-initialized: calling handler <function add_binary_formatter at 0x7f92ecb124c0>
2026-04-14 17:44:38,254 - MainThread - botocore.hooks - DEBUG - Event session-initialized: calling handler <function no_pager_handler at 0x7f92ecba4550>
...
2026-04-16 00:11:52,493 - MainThread - botocore.utils - DEBUG - Registering S3 region redirector handler
2026-04-16 00:11:52,493 - MainThread - botocore.utils - DEBUG - Registering S3Express Identity Resolver
2026-04-16 00:11:52,494 - MainThread - botocore.hooks - DEBUG - Event choose-service-name: calling handler <function handle_service_name_alias at 0x7f250444fc10>
2026-04-16 00:11:52,527 - MainThread - botocore.hooks - DEBUG - Event creating-client-class.s3: calling handler <function add_generate_presigned_post at 0x7f250453a3a0>
2026-04-16 00:11:52,528 - MainThread - botocore.hooks - DEBUG - Event creating-client-class.s3: calling handler <function add_generate_presigned_url at 0x7f250453a160>
2026-04-16 00:11:52,528 - MainThread - botocore.configprovider - DEBUG - Looking for endpoint for s3 via: environment_service
2026-04-16 00:11:52,528 - MainThread - botocore.configprovider - DEBUG - Looking for endpoint for s3 via: environment_global
2026-04-16 00:11:52,528 - MainThread - botocore.configprovider - DEBUG - Looking for endpoint for s3 via: config_service
2026-04-16 00:11:52,528 - MainThread - botocore.configprovider - DEBUG - Looking for endpoint for s3 via: config_global
2026-04-16 00:11:52,528 - MainThread - botocore.configprovider - DEBUG - No configured endpoint found.
2026-04-16 00:11:52,530 - MainThread - botocore.endpoint - DEBUG - Setting s3 timeout as (60, 60)
2026-04-16 00:11:52,532 - MainThread - botocore.utils - DEBUG - Registering S3 region redirector handler
2026-04-16 00:11:52,532 - MainThread - botocore.utils - DEBUG - Registering S3Express Identity Resolver
2026-04-16 00:11:52,533 - MainThread - awscrt.common.aws-c-common - DEBUG - static: Lock file /tmp/aws_crt_cross_process_lock/aws-cli.lock acquired by this instance with fd 4
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - INFO - id=0x55c62049dc90: Initializing edge-triggered epoll
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - INFO - id=0x55c62049dc90: Using eventfd for cross-thread notifications.
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - DEBUG - id=0x55c62049dc90: eventfd descriptor 6.
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - INFO - id=0x55c62049dc90: Starting event-loop thread.
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6204d1570: Initializing edge-triggered epoll
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6204d1570: Using eventfd for cross-thread notifications.
2026-04-16 00:11:52,533 - AwsEventLoop1 - awscrt.io.event-loop - INFO - id=0x55c62049dc90: main loop started
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - DEBUG - id=0x55c6204d1570: eventfd descriptor 8.
2026-04-16 00:11:52,533 - AwsEventLoop1 - awscrt.io.event-loop - DEBUG - id=0x55c62049dc90: subscribing to events on fd 6
2026-04-16 00:11:52,533 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6204d1570: Starting event-loop thread.
2026-04-16 00:11:52,534 - AwsEventLoop1 - awscrt.io.event-loop - INFO - id=0x55c62049dc90: default timeout 100000, and max events to process per tick 100
2026-04-16 00:11:52,534 - MainThread - awscrt.io.event-loop - INFO - id=0x55c62043add0: Initializing edge-triggered epoll
2026-04-16 00:11:52,534 - AwsEventLoop1 - awscrt.io.event-loop - DEBUG - id=0x55c62049dc90: waiting for a maximum of 100000 ms
2026-04-16 00:11:52,534 - AwsEventLoop2 - awscrt.io.event-loop - INFO - id=0x55c6204d1570: main loop started
2026-04-16 00:11:52,534 - MainThread - awscrt.io.event-loop - INFO - id=0x55c62043add0: Using eventfd for cross-thread notifications.
2026-04-16 00:11:52,534 - AwsEventLoop2 - awscrt.io.event-loop - DEBUG - id=0x55c6204d1570: subscribing to events on fd 8
2026-04-16 00:11:52,534 - MainThread - awscrt.io.event-loop - DEBUG - id=0x55c62043add0: eventfd descriptor 10.
2026-04-16 00:11:52,534 - AwsEventLoop2 - awscrt.io.event-loop - INFO - id=0x55c6204d1570: default timeout 100000, and max events to process per tick 100
2026-04-16 00:11:52,534 - MainThread - awscrt.io.event-loop - INFO - id=0x55c62043add0: Starting event-loop thread.
2026-04-16 00:11:52,534 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6203d19b0: Initializing edge-triggered epoll
2026-04-16 00:11:52,534 - AwsEventLoop2 - awscrt.io.event-loop - DEBUG - id=0x55c6204d1570: waiting for a maximum of 100000 ms
2026-04-16 00:11:52,535 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6203d19b0: Using eventfd for cross-thread notifications.
2026-04-16 00:11:52,535 - AwsEventLoop3 - awscrt.io.event-loop - INFO - id=0x55c62043add0: main loop started
2026-04-16 00:11:52,535 - MainThread - awscrt.io.event-loop - DEBUG - id=0x55c6203d19b0: eventfd descriptor 12.
2026-04-16 00:11:52,535 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6203d19b0: Starting event-loop thread.
2026-04-16 00:11:52,535 - AwsEventLoop3 - awscrt.io.event-loop - DEBUG - id=0x55c62043add0: subscribing to events on fd 10
2026-04-16 00:11:52,535 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6204f18b0: Initializing edge-triggered epoll
2026-04-16 00:11:52,535 - AwsEventLoop4 - awscrt.io.event-loop - INFO - id=0x55c6203d19b0: main loop started
2026-04-16 00:11:52,535 - AwsEventLoop3 - awscrt.io.event-loop - INFO - id=0x55c62043add0: default timeout 100000, and max events to process per tick 100
2026-04-16 00:11:52,535 - MainThread - awscrt.io.event-loop - INFO - id=0x55c6204f18b0: Using eventfd for cross-thread notifications.
2026-04-16 00:11:52,535 - AwsEventLoop4 - awscrt.io.event-loop - DEBUG - id=0x55c6203d19b0: subscribing to events on fd 12
...
upload: filename to s3://bucket/filename
2026-04-14 17:44:38,541 - AwsEventLoop4 - awscrt.s3.S3MetaRequest - DEBUG - id=0x556489c601e0 Cleaning up meta request
2026-04-14 17:44:38,542 - Thread-17 - awscli.customizations.s3.results - DEBUG - Shutdown request received in result processing thread, shutting down result thread.
2026-04-14 17:44:38,542 - AwsEventLoop5 - awscrt.io.socket - DEBUG - id=0x7f92d80011d0 fd=38: read of -1
2026-04-14 17:44:38,542 - AwsEventLoop8 - awscrt.io.event-loop - DEBUG - id=0x556489bd6dc0: waiting for a maximum of 100000 ms
2026-04-14 17:44:38,542 - AwsEventLoop4 - awscrt.s3.S3MetaRequest - DEBUG - id=0x556489c601e0 Calling virtual meta request destroy function.
2026-04-14 17:44:38,543 - AwsEventLoop5 - awscrt.io.socket - DEBUG - id=0x7f92d80011d0 fd=38: read would block

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

@azkrishpy azkrishpy marked this pull request as ready for review April 7, 2026 00:43
Comment thread source/module.c Outdated
Comment on lines +148 to +152
/* Fill header */
struct s_py_log_header *header = (struct s_py_log_header *)output->bytes;
header->level = level;
header->thread_name_len = thread_name.len;
header->subject_len = subject_name.len;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

wow, this is hacky, I spent 5 mins to understand this...

Comment thread awscrt/logging.py
Comment thread awscrt/logging.py Outdated
_awscrt.set_log_level(int(crt_level))


def logf(level: int, subject: LogSubject, message: str):
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

why naming it as logf? in Java, we name it just log. I believe f stardards for format and google told me:

Log: Takes a variable number of arguments and prints them (similar to fmt.Println).
Logf: Takes a format string and arguments, allowing for formatted output using placeholders like %d or %s (similar to fmt.Printf). 

And here we just take a message and subject, I think it's better to name it to log instead.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

I only called it logf because we are directly calling AWS_LOGF() i some sense.. but yes we can use log as well... but it would also conflict with logger.log() is that a problem we need to worry about?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I don't think so, it's like we have two init_logging method...

Comment thread awscrt/logging.py
Comment thread source/module.c Outdated
Comment on lines +228 to +230
if (!impl) {
return PyErr_AwsLastError();
}
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

stops checking for allocation failures.

Comment thread source/module.c Outdated
#include <memoryobject.h>

static struct aws_logger s_logger;
static bool s_logger_init = false;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

this should also be atomic. Given freethreading python

Comment thread source/module.c Outdated
Comment on lines +68 to +71
if (!buf) {
va_end(args);
return AWS_OP_ERR;
}
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

no need to check for allocation failures,

Comment thread source/module.c
Comment thread source/module.c Outdated

struct aws_string *thread_name_str = NULL;
aws_thread_current_name(logger->allocator, &thread_name_str);
const char *thread_name = thread_name_str ? aws_string_c_str(thread_name_str) : "main";
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

are we using main as the default?
But, why in your example in the description there is python as the thread name? Are we getting the python from our aws_thread_current_name???

2026-04-14 17:44:38,450 - python - awscrt.http.connection-manager - INFO - id=0x556489b95560: Successfully created

I think we should follow what ever thread name python uses. Maybe that if we are not getting a thread_name from our function, we just don't change the thread name from the callback? So, passing null or something

Comment thread source/module.c
Comment thread source/module.c Outdated
return NULL;
}

if (s_logger_init) {
Copy link
Copy Markdown
Contributor

@TingDaoK TingDaoK Apr 14, 2026

Choose a reason for hiding this comment

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

with atomic, you will need fetch and flip to be thread safe.(compare and set https://stackoverflow.com/questions/14370575/why-are-atomic-operations-considered-thread-safe)

Copy link
Copy Markdown
Contributor

@TingDaoK TingDaoK left a comment

Choose a reason for hiding this comment

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

fix and ship

Comment thread source/module.c Outdated
@azkrishpy azkrishpy merged commit 52032a5 into main Apr 16, 2026
77 checks passed
@azkrishpy azkrishpy deleted the py-logging branch April 16, 2026 01:21
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