Simple Python boto3 Logging

Hello!

If you’re writing a lambda function, check out this article instead.

The best way to log output from boto3 is with Python’s logging library. The core docs have a nice tutorial.

If you use print() statements for output, all you’ll get from boto is what you capture and print yourself. But, boto does a lot of internal logging that we can capture for free.

Good libraries, like boto, use Python’s logging library internally. If you set up a logger using the same library, it will automatically capture boto’s logs along with your own.

Here’s how I set up logging. This is a demo script, in the real world you’d parameterize the inputs, etc.

import logging
import boto3

if __name__ == '__main__':
    logging.basicConfig(
        level=logging.INFO,
        format=f'%(asctime)s %(levelname)s %(message)s'
    )
    logger = logging.getLogger()
    logger.debug('The script is starting.')
    logger.info('Connecting to EC2...')
    ec2 = boto3.client('ec2')

That’s it! The basicConfig() function sets up the root logger for you. We’ve told it what amount of output to show (the level) and to show the event time and level on each output line. The logging library docs have more info on what levels and formatting are available.

If you set the level to INFO, it’ll output anything logged with .info() (or higher) by your code and boto’s internal code. You won’t see our 'The script is starting.' line because anything logged at the DEBUG level will be excluded.

2019-08-18 07:59:20,123 INFO Connecting to EC2...
Traceback (most recent call last):
  File "demo.py", line 11, in <module>
    ec2 = boto3.client('ec2')
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/boto3/__init__.py", line 91, in client
    return _get_default_session().client(*args, **kwargs)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/boto3/session.py", line 263, in client
    aws_session_token=aws_session_token, config=config)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/session.py", line 838, in create_client
    client_config=config, api_version=api_version)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/client.py", line 86, in create_client
    verify, credentials, scoped_config, client_config, endpoint_bridge)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/client.py", line 328, in _get_client_args
    verify, credentials, scoped_config, client_config, endpoint_bridge)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/args.py", line 47, in get_client_args
    endpoint_url, is_secure, scoped_config)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/args.py", line 117, in compute_client_args
    service_name, region_name, endpoint_url, is_secure)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/client.py", line 402, in resolve
    service_name, region_name)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/regions.py", line 122, in construct_endpoint
    partition, service_name, region_name)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/regions.py", line 135, in _endpoint_for_partition
    raise NoRegionError()
botocore.exceptions.NoRegionError: You must specify a region.

If you change the level to DEBUG, you’ll get everything:

2019-08-18 08:28:06,189 DEBUG The script is starting.
2019-08-18 08:28:06,190 INFO Connecting to EC2...
2019-08-18 08:28:06,190 DEBUG Changing event name from creating-client-class.iot-data to creating-client-class.iot-data-plane
2019-08-18 08:28:06,193 DEBUG Changing event name from before-call.apigateway to before-call.api-gateway
2019-08-18 08:28:06,193 DEBUG Changing event name from request-created.machinelearning.Predict to request-created.machine-learning.Predict
2019-08-18 08:28:06,194 DEBUG Changing event name from before-parameter-build.autoscaling.CreateLaunchConfiguration to before-parameter-build.auto-scaling.CreateLaunchConfiguration
2019-08-18 08:28:06,195 DEBUG Changing event name from before-parameter-build.route53 to before-parameter-build.route-53
2019-08-18 08:28:06,195 DEBUG Changing event name from request-created.cloudsearchdomain.Search to request-created.cloudsearch-domain.Search
2019-08-18 08:28:06,195 DEBUG Changing event name from docs.*.autoscaling.CreateLaunchConfiguration.complete-section to docs.*.auto-scaling.CreateLaunchConfiguration.complete-section
2019-08-18 08:28:06,197 DEBUG Changing event name from before-parameter-build.logs.CreateExportTask to before-parameter-build.cloudwatch-logs.CreateExportTask
2019-08-18 08:28:06,197 DEBUG Changing event name from docs.*.logs.CreateExportTask.complete-section to docs.*.cloudwatch-logs.CreateExportTask.complete-section
2019-08-18 08:28:06,197 DEBUG Changing event name from before-parameter-build.cloudsearchdomain.Search to before-parameter-build.cloudsearch-domain.Search
2019-08-18 08:28:06,197 DEBUG Changing event name from docs.*.cloudsearchdomain.Search.complete-section to docs.*.cloudsearch-domain.Search.complete-section
2019-08-18 08:28:06,211 DEBUG Looking for credentials via: env
2019-08-18 08:28:06,211 DEBUG Looking for credentials via: assume-role
2019-08-18 08:28:06,211 DEBUG Looking for credentials via: shared-credentials-file
2019-08-18 08:28:06,212 DEBUG Looking for credentials via: custom-process
2019-08-18 08:28:06,212 DEBUG Looking for credentials via: config-file
2019-08-18 08:28:06,212 DEBUG Looking for credentials via: ec2-credentials-file
2019-08-18 08:28:06,212 DEBUG Looking for credentials via: boto-config
2019-08-18 08:28:06,212 DEBUG Looking for credentials via: container-role
2019-08-18 08:28:06,212 DEBUG Looking for credentials via: iam-role
2019-08-18 08:28:06,213 DEBUG Converted retries value: False -> Retry(total=False, connect=None, read=None, redirect=0, status=None)
2019-08-18 08:28:06,213 DEBUG Starting new HTTP connection (1): 169.254.169.254:80
2019-08-18 08:28:07,215 DEBUG Caught retryable HTTP exception while making metadata service request to http://169.254.169.254/latest/meta-data/iam/security-credentials/: Connect timeout on endpoint URL: "http://169.254.169.254/latest/meta-data/iam/security-credentials/"
Traceback (most recent call last):
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/connection.py", line 159, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/util/connection.py", line 80, in create_connection
    raise err
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/util/connection.py", line 70, in create_connection
    sock.connect(sa)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/httpsession.py", line 258, in send
    decode_content=False,
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/connectionpool.py", line 638, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/util/retry.py", line 343, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/packages/six.py", line 686, in reraise
    raise value
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/connectionpool.py", line 354, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/Users/adam/.pyenv/versions/3.7.2/lib/python3.7/http/client.py", line 1229, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/awsrequest.py", line 125, in _send_request
    method, url, body, headers, *args, **kwargs)
  File "/Users/adam/.pyenv/versions/3.7.2/lib/python3.7/http/client.py", line 1275, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/Users/adam/.pyenv/versions/3.7.2/lib/python3.7/http/client.py", line 1224, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/awsrequest.py", line 152, in _send_output
    self.send(msg)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/awsrequest.py", line 236, in send
    return super(AWSConnection, self).send(str)
  File "/Users/adam/.pyenv/versions/3.7.2/lib/python3.7/http/client.py", line 956, in send
    self.connect()
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/connection.py", line 181, in connect
    conn = self._new_conn()
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/urllib3/connection.py", line 164, in _new_conn
    (self.host, self.timeout))
urllib3.exceptions.ConnectTimeoutError: (<botocore.awsrequest.AWSHTTPConnection object at 0x1045a1f98>, 'Connection to 169.254.169.254 timed out. (connect timeout=1)')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/utils.py", line 303, in _get_request
    response = self._session.send(request.prepare())
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/httpsession.py", line 282, in send
    raise ConnectTimeoutError(endpoint_url=request.url, error=e)
botocore.exceptions.ConnectTimeoutError: Connect timeout on endpoint URL: "http://169.254.169.254/latest/meta-data/iam/security-credentials/"
2019-08-18 08:28:07,219 DEBUG Max number of attempts exceeded (1) when attempting to retrieve data from metadata service.
2019-08-18 08:28:07,219 DEBUG Loading JSON file: /Users/adam/opt/env3/lib/python3.7/site-packages/botocore/data/endpoints.json
2019-08-18 08:28:07,224 DEBUG Event choose-service-name: calling handler <function handle_service_name_alias at 0x1044b29d8>
2019-08-18 08:28:07,235 DEBUG Loading JSON file: /Users/adam/opt/env3/lib/python3.7/site-packages/botocore/data/ec2/2016-11-15/service-2.json
2019-08-18 08:28:07,258 DEBUG Event creating-client-class.ec2: calling handler <function add_generate_presigned_url at 0x104474510>
Traceback (most recent call last):
  File "demo.py", line 12, in <module>
    ec2 = boto3.client('ec2')
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/boto3/__init__.py", line 91, in client
    return _get_default_session().client(*args, **kwargs)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/boto3/session.py", line 263, in client
    aws_session_token=aws_session_token, config=config)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/session.py", line 838, in create_client
    client_config=config, api_version=api_version)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/client.py", line 86, in create_client
    verify, credentials, scoped_config, client_config, endpoint_bridge)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/client.py", line 328, in _get_client_args
    verify, credentials, scoped_config, client_config, endpoint_bridge)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/args.py", line 47, in get_client_args
    endpoint_url, is_secure, scoped_config)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/args.py", line 117, in compute_client_args
    service_name, region_name, endpoint_url, is_secure)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/client.py", line 402, in resolve
    service_name, region_name)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/regions.py", line 122, in construct_endpoint
    partition, service_name, region_name)
  File "/Users/adam/opt/env3/lib/python3.7/site-packages/botocore/regions.py", line 135, in _endpoint_for_partition
    raise NoRegionError()
botocore.exceptions.NoRegionError: You must specify a region.

See how it started saying where it found AWS credentials? Imagine you’re trying to figure out why your script worked locally but didn’t work on an EC2 instance; knowing where it found keys is huge. Maybe there are some hardcoded ones you didn’t know about that it’s picking up instead of the IAM role you attached to the instance. In DEBUG mode that’s easy to figure out. With print you’d have to hack out these details yourself.

This is great for simple scripts, but for something you’re going to run in production I recommend this pattern.

Happy automating!

Adam

If this was helpful and you want to save time by getting “copy and paste” patterns for Python in your inbox, subscribe here. If you don’t want to wait for the next one, check out these: