search

aws / aws-iot-device-sdk-python-v2

Next generation AWS IoT Client SDK for Python using the AWS Common Runtime
Apache License 2.0
408 stars 213 forks source link

On upgrade 0.10->0.11: RuntimeError: 1033 (AWS_IO_TLS_CTX_ERROR): Failed to create tls context #188

Closed davidparks21 closed 3 years ago

davidparks21 commented 3 years ago

Confirm by changing [ ] to [x] below to ensure that it's a bug:

Known Issue

Describe the bug Originally posted on SO: https://stackoverflow.com/questions/67308198/awsiot-runtimeerror-1033-aws-io-tls-ctx-error-failed-to-create-tls-context

I recently upgraded the packaged awsiotsdk and awscrt from versions 1.5.7 -> 1.5.10 and 0.10.8 -> 0.11.4. After doing so I'm getting the following error:

RuntimeError: 1033 (AWS_IO_TLS_CTX_ERROR): Failed to create tls context

The error is coming from the following function which works in the previous version.

awsiot.mqtt_connection_builder.websockets_with_default_aws_signing(...)

SDK version number awsiotsdk: 1.5.7 -> 1.5.10 awscrt: 0.10.8 -> 0.11.4

Platform/OS/Device Ubuntu 20.10

Logs/output

Traceback (most recent call last):
  File "opt/anaconda3/lib/python3.8/unittest/case.py", line 60, in testPartExecutor
    yield
  File "opt/anaconda3/lib/python3.8/unittest/case.py", line 676, in run
    self._callTestMethod(testMethod)
  File "opt/anaconda3/lib/python3.8/unittest/case.py", line 633, in _callTestMethod
    method()
  File "tests/utils/test_messaging.py", line 101, in test_list_devices_basic
    self.mb.subscribe_message('devices/test', callback=unittest.mock.Mock())
  File "src/messaging.py", line 154, in subscribe_message
    subscribe_future, packet_id = self.mqtt_connection.subscribe(
  File "src/messaging.py", line 417, in mqtt_connection
    self._mqtt_connection = awsiot.mqtt_connection_builder.websockets_with_default_aws_signing(
  File "opt/anaconda3/lib/python3.8/site-packages/awsiot/mqtt_connection_builder.py", line 274, in websockets_with_default_aws_signing
    return websockets_with_custom_handshake(_sign_websocket_handshake_request, websocket_proxy_options, **kwargs)
  File "opt/anaconda3/lib/python3.8/site-packages/awsiot/mqtt_connection_builder.py", line 305, in websockets_with_custom_handshake
    return _builder(tls_ctx_options=tls_ctx_options,
  File "opt/anaconda3/lib/python3.8/site-packages/awsiot/mqtt_connection_builder.py", line 174, in _builder
    tls_ctx = awscrt.io.ClientTlsContext(tls_ctx_options)
  File "opt/anaconda3/lib/python3.8/site-packages/awscrt/io.py", line 424, in __init__
    self._binding = _awscrt.client_tls_ctx_new(
RuntimeError: 1033 (AWS_IO_TLS_CTX_ERROR): Failed to create tls context
awscrt.io.init_logging(awscrt.io.LogLevel.Warn, 'stderr')
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Non-default profile declarations in config files must use the "profile" keyword
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 5
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Property definition seen outside a profile
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 6
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Property definition seen outside a profile
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 7
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Non-default profile declarations in config files must use the "profile" keyword
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 9
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Property definition seen outside a profile
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 10
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "output" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "output" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "region" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "password" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Non-default profile declarations in config files must use the "profile" keyword
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 5
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Property definition seen outside a profile
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 6
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Property definition seen outside a profile
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 7
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Non-default profile declarations in config files must use the "profile" keyword
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 9
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Property definition seen outside a profile
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - Profile Parse context:
 Source File:/home/davidparks21/.aws/config
 Line: 10
 Current Profile: <None>
 Current Property: <None>
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "output" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "output" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "region" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "password" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_access_key_id" has value "" replaced during merge
[WARN] [2021-04-29T00:45:01Z] [00007feb97ebc740] [AuthProfile] - property "aws_secret_access_key" has value "" replaced during merge
[WARN] [2021-04-29T00:45:02Z] [00007feb6f77e640] [socket] - id=0x7feb60000c90 fd=11: setsockopt() for NO_SIGNAL failed with errno 92. If you are having SIGPIPE signals thrown, you may want to install a signal trap in your application layer.
[ERROR] [2021-04-29T00:45:02Z] [00007feb6f77e640] [socket] - id=0x7feb60000c90 fd=11: connect failed with error code 101.
[ERROR] [2021-04-29T00:45:02Z] [00007feb6f77e640] [channel-bootstrap] - id=0x55d73fb055e0: failed to create socket with error 1049
[WARN] [2021-04-29T00:45:02Z] [00007feb6f77e640] [socket] - id=0x7feb60000c90 fd=11: setsockopt() for NO_SIGNAL failed with errno 92. If you are having SIGPIPE signals thrown, you may want to install a signal trap in your application layer.
[ERROR] [2021-04-29T00:45:03Z] [00007feb6f77e640] [http-connection] - id=0x7feb60017840: Destroying write message without passing it along, error 1031 (AWS_IO_TLS_ERROR_WRITE_FAILURE)

Error
Traceback (most recent call last):
  File "opt/anaconda3/lib/python3.8/unittest/case.py", line 60, in testPartExecutor
    yield
  File "opt/anaconda3/lib/python3.8/unittest/case.py", line 676, in run
    self._callTestMethod(testMethod)
  File "opt/anaconda3/lib/python3.8/unittest/case.py", line 633, in _callTestMethod
    method()
  File "tests/utils/test_messaging.py", line 103, in test_list_devices_basic
    self.mb.subscribe_message('devices/test', callback=unittest.mock.Mock())
  File "src/messaging.py", line 154, in subscribe_message
    subscribe_future, packet_id = self.mqtt_connection.subscribe(
  File "src/messaging.py", line 431, in mqtt_connection
    logger.info('MQTT connected: ', connect_future.result())
  File "opt/anaconda3/lib/python3.8/concurrent/futures/_base.py", line 439, in result
    return self.__get_result()
  File "opt/anaconda3/lib/python3.8/concurrent/futures/_base.py", line 388, in __get_result
    raise self._exception
awscrt.exceptions.AwsCrtError: AWS_ERROR_MQTT_UNEXPECTED_HANGUP: The connection was closed unexpectedly.
LukasBernhard commented 3 years ago

I have the same problem, tried to update from awscrt==0.9.10 awsiotsdk==1.5.2

to awsiotsdk==1.5.14

and got the exact same error

bretambrose commented 3 years ago

If you could attach trace level logs that would be very helpful, as well as the code snippet that triggers it. Also I see two completely different errors, one post-connection, one building the tls context -- a log for the tls context error would be ideal.

AGiantSquid commented 3 years ago

I noticed a very strange bug that causes the runtime issue RuntimeError: 1033 (AWS_IO_TLS_CTX_ERROR): Failed to create tls context mentioned here while using the pubsub.py script included in this SDK.

When I used the SDK as instructed in the tutorial it worked fine the first time. Then, I simply added a few print statements before the connection builder ran, which caused the error to appear:

mqtt-bug

I'm guessing there is some kind of a race condition between when the connection dependency stuff is set up, and when it is used in the mqtt_connection_builder.mtls_from_path():

    event_loop_group = io.EventLoopGroup(1)
    host_resolver = io.DefaultHostResolver(event_loop_group)
    client_bootstrap = io.ClientBootstrap(event_loop_group, host_resolver)
    ...

        mqtt_connection = mqtt_connection_builder.mtls_from_path(
            endpoint=args.endpoint,
            cert_filepath=args.cert,
            pri_key_filepath=args.key,
            client_bootstrap=client_bootstrap,
            ...

When I push that stuff into the mtls_from_path definition, like so: client_bootstrap=io.ClientBootstrap(event_loop_group, io.DefaultHostResolver(event_loop_group)), the code works again:

mqtt-bug-workaround

bretambrose commented 3 years ago

A fix for this is pending. We should be able to have it released on Monday.

bretambrose commented 3 years ago

We are hoping this has been addressed in the v1.5.17 release. Please reopen if you're still seeing an issue.

github-actions[bot] commented 3 years ago

⚠️COMMENT VISIBILITY WARNING⚠️

Comments on closed issues are hard for our team to see. If you need more assistance, please either tag a team member or open a new issue that references this one. If you wish to keep having a conversation with other community members under this issue feel free to do so.