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 212 forks source link

pubsub sample failed to run on Mac Ventura OS due to SSLRead/SSLWrite #514

Closed miteshkoradia-amazon closed 1 year ago

miteshkoradia-amazon commented 1 year ago

Describe the bug

I am following steps mentioned on https://docs.aws.amazon.com/iot/latest/developerguide/using-laptop-as-device.html When I try to run pubsub sample, it give me following error 

[ERROR] [2023-09-21T15:58:12Z] [00007000062c3000] [socket] - id=0x7fcf5d91f990 fd=18: connect failed with error code 65.
[ERROR] [2023-09-21T15:58:12Z] [00007000062c3000] [channel-bootstrap] - id=0x600001220230: failed to create socket with error 1049
[ERROR] [2023-09-21T15:58:13Z] [00007000062c3000] [tls-handler] - id=0x7fcf5da0a6e0: error reported during SSLRead. OSStatus code -9805
Exception ignored in: <class 'AttributeError'>
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/awscrt/mqtt.py", line 483, in _on_connection_failure
Traceback (most recent call last):
  File "pubsub.py", line 107, in <module>
    self._on_connection_failure_cb(connection=self, callback_data=data)
  File "pubsub.py", line 68, in on_connection_failure
    connect_future.result()
  File "/usr/local/Cellar/python@3.8/3.8.5/Frameworks/Python.framework/Versions/3.8/lib/python3.8/concurrent/futures/_base.py", line 439, in result
    assert isinstance(callback_data, mqtt.OnConnectionFailuredata)
    return self.__get_result()
  File "/usr/local/Cellar/python@3.8/3.8.5/Frameworks/Python.framework/Versions/3.8/lib/python3.8/concurrent/futures/_base.py", line 388, in __get_result
AttributeError: module 'awscrt.mqtt' has no attribute 'OnConnectionFailuredata'
    raise self._exception
awscrt.exceptions.AwsCrtError: AWS_ERROR_MQTT_UNEXPECTED_HANGUP: The connection was closed unexpectedly.
[ERROR] [2023-09-21T15:58:13Z] [00007ff85ce16640] [mqtt-client] - id=0x7fcf5e024200: Connection is not open, and may not be closed
koradia@f8ffc21b00f2 samples %

Expected Behavior

Expected behaviour is to publish message/receive message.

Current Behavior

Error as added in Description

Reproduction Steps

https://docs.aws.amazon.com/iot/latest/developerguide/using-laptop-as-device.html -- steps as per this guide for GGV2

Possible Solution

No response

Additional Information/Context

No response

SDK version used

GGSDKV2

Environment details (OS name and version, etc.)

Mac Ventura 13.4.1

miteshkoradia-amazon commented 1 year ago

@jmklix Do we have any more insight into this?

xiazhvera commented 1 year ago

The handshake failed with error error reported during SSLRead. OSStatus code -9805. The error code indicates the connection was closed by the server due to issues during connection establish. There are couple things you can try:

  1. The most common case is that the certificate or private key had issue. If you directly downloaded the certificate and private key file from the IoT Thing creation process described in the doc, it should work fine. You can try with a new Thing and new certificates. Please make sure you use the AmazonRootCA1 for RSA encoded keys.
  2. It could also be an issue with Mac keychain system, restart the machine should help.
  3. Make sure local firewall or network configuration does not block the packages.

There are multiple reasons why we are seeing it and it is hard to identify the root cause. It would be helpful if you could provide the full log. (Please make sure remove any confidential information from the log)

miteshkoradia-amazon commented 1 year ago

Full log.

[INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b68050: Initializing edge-triggered kqueue [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b68050: starting event-loop thread. [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b680a0: Initializing edge-triggered kqueue [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b680a0: starting event-loop thread. [INFO] [2023-10-10T14:46:07Z] [000070000be24000] [event-loop] - id=0x600001b68050: main loop started [INFO] [2023-10-10T14:46:07Z] [000070000be24000] [event-loop] - id=0x600001b68050: default timeout 100s, and max events to process per tick 100 [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b600a0: Initializing edge-triggered kqueue [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b600a0: starting event-loop thread. [INFO] [2023-10-10T14:46:07Z] [000070000bea7000] [event-loop] - id=0x600001b680a0: main loop started [INFO] [2023-10-10T14:46:07Z] [000070000bea7000] [event-loop] - id=0x600001b680a0: default timeout 100s, and max events to process per tick 100 [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b60190: Initializing edge-triggered kqueue [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [event-loop] - id=0x600001b60190: starting event-loop thread. [INFO] [2023-10-10T14:46:07Z] [000070000bf2a000] [event-loop] - id=0x600001b600a0: main loop started [INFO] [2023-10-10T14:46:07Z] [000070000bf2a000] [event-loop] - id=0x600001b600a0: default timeout 100s, and max events to process per tick 100 [INFO] [2023-10-10T14:46:07Z] [000070000bfad000] [event-loop] - id=0x600001b60190: main loop started [INFO] [2023-10-10T14:46:07Z] [000070000bfad000] [event-loop] - id=0x600001b60190: default timeout 100s, and max events to process per tick 100 [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [dns] - id=0x600000d60000: Initializing default host resolver with 16 max host entries. [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [channel-bootstrap] - id=0x600001360850: Initializing client bootstrap with event-loop group 0x600001c680c0 [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [tls-handler] - static: certificate and key have been set, setting them up now. [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [pki-utils] - static: certificate has an existing certificate-key pair that was previously imported into the Keychain. Using key from Keychain instead of the one provided. [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [tls-handler] - static: loading custom CA file. [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [mqtt-client] - client=0x6000036484e0: Initalizing MQTT client [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [channel-bootstrap] - id=0x600001360850: acquiring bootstrap reference [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [mqtt-client] - id=0x7fdd15009600: Creating new mqtt 311 connection [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [mqtt-topic-tree] - tree=0x7fdd15009918: Creating new topic tree Connecting to a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com with client ID 'test-df0ec640-9fd7-40bc-99cb-487479800990'... [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [mqtt-client] - id=0x7fdd15009600: Begin connecting process, switch state to CONNECTING. [INFO] [2023-10-10T14:46:07Z] [00007ff8514d1640] [mqtt-client] - id=0x7fdd15009600: using ping timeout of 3000000000 ns [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [channel-bootstrap] - id=0x600001360850: acquiring bootstrap reference [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [dns] - id=0x600000d60000: Host resolution requested for a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com [DEBUG] [2023-10-10T14:46:07Z] [00007ff8514d1640] [dns] - id=0x600000d60000: No cached entries found for a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com starting new resolver thread. [DEBUG] [2023-10-10T14:46:07Z] [000070000c136000] [dns] - static: resolving host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 50.19.147.165 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 52.87.126.58 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 54.152.50.254 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 52.87.99.188 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 54.84.180.129 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 52.203.212.80 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 52.205.114.236 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 52.1.233.53 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::36d2:f213 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::3211:30a6 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::22e9:ad4a [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::3416:4aa5 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::34cc:fe6 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::3698:90a4 [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::3692:633b [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: resolved record: 2406:da00:ff00::3693:e89f [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static, resolving host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com successful, returned 16 addresses [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 50.19.147.165 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 52.87.126.58 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 54.152.50.254 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 52.87.99.188 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 54.84.180.129 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 52.203.212.80 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 52.205.114.236 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 52.1.233.53 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::36d2:f213 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::3211:30a6 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::22e9:ad4a for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::3416:4aa5 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::34cc:fe6 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::3698:90a4 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::3692:633b for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static: new address resolved 2406:da00:ff00::3693:e89f for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com caching [DEBUG] [2023-10-10T14:46:08Z] [000070000c136000] [dns] - static, invoking resolution callback for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com with 2 addresses [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd13d2d560: Scheduling attempt_connection task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd13d1be30: Scheduling attempt_connection task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd13d2d560: Running attempt_connection task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd13d18010 fd=18: initializing with domain 1 and type 0 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd13d18010 fd=18: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd13d18010 fd=18: beginning connect. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd13d18010 fd=18: connecting to endpoint 2406:da00:ff00::36d2:f213:8883. [ERROR] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd13d18010 fd=18: connect failed with error code 65. [INFO] [2023-10-10T14:46:08Z] [000070000be24000] [dns] - id=0x600000d60000: recording failure for record 2406:da00:ff00::36d2:f213 for a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com, moving to bad list [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [dns] - static: purging address 2406:da00:ff00::36d2:f213 for host a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com from the cache due to cache eviction or shutdown [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd13d18010 fd=18: is still open, closing... [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd13d18010 fd=18: closing [ERROR] [2023-10-10T14:46:08Z] [000070000be24000] [channel-bootstrap] - id=0x600001360850: failed to create socket with error 1049 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd13d1be30: Running attempt_connection task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd12f2a020 fd=18: initializing with domain 0 and type 0 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd12f2a020 fd=18: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd12f2a020 fd=18: beginning connect. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd12f2a020 fd=18: connecting to endpoint 50.19.147.165:8883. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f603a0: Scheduling kqueue_event_loop_subscribe task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600001b60b40: Scheduling (null) task for future execution at time 1332161014382090 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f603a0: Running kqueue_event_loop_subscribe task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f603e0: Scheduling kqueue_event_loop_clean_up_handle_data task for immediate execution [INFO] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd12f2a020 fd=18: connection success [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd12f2a020 fd=18: assigning to event loop 0x600001b68050 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f60450: Scheduling kqueue_event_loop_subscribe task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel-bootstrap] - id=0x600001360850: client connection on socket 0x7fdd12f2a020 completed with error 0. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: Beginning creation and setup of new channel. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600001c60740: Scheduling on_channel_setup_complete task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f603e0: Running kqueue_event_loop_clean_up_handle_data task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f60450: Running kqueue_event_loop_subscribe task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600001c60740: Running on_channel_setup_complete task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: setup complete, notifying caller. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: no message pool is currently stored in the event-loop local storage, adding 0x6000009619a0 with max message size 16384, message count 4, with 4 small blocks of 128 bytes. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel-bootstrap] - id=0x600001360850: channel 0x7fdd12f2a170 setup succeeded: bootstrapping. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket-handler] - id=0x7fdd12f2af20: Socket handler created with max_read_size of 16384 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2b2e0: Scheduling tls_timeout task for future execution at time 1332166142420856 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Scheduling socket_written_task task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Running socket_written_task task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Scheduling socket_written_task task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Running socket_written_task task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [tls-handler] - id=0x7fdd12f2b2b0: negotiation succeeded [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [tls-handler] - id=0x7fdd12f2b2b0: Remote Server Name: a3rqcuaiy7ojvt-ats.iot.us-east-1.amazonaws.com [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel-bootstrap] - id=0x600001360850: tls negotiation result 0 on channel 0x7fdd12f2a170 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [mqtt-client] - id=0x7fdd15009600: Connection successfully opened, sending CONNECT packet [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600001364e70: Scheduling mqtt_connack_timeout task for future execution at time 1332159671164181 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [mqtt-client] - id=0x7fdd15009600: MQTT Connection initializing CONNECT packet for client-id 'test-df0ec640-9fd7-40bc-99cb-487479800990' [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [mqtt-client] - id=0x7fdd15009600: Adding username ?SDK=PythonV2&Version=1.0.0.dev0 to connection [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Scheduling socket_written_task task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Running socket_written_task task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Scheduling socket_written_task task for immediate execution [ERROR] [2023-10-10T14:46:08Z] [000070000be24000] [tls-handler] - id=0x7fdd12f2b2b0: error reported during SSLRead. OSStatus code -9805 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2a388: Scheduling channel_shutdown task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000d601c0: Running socket_written_task task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2a388: Running channel_shutdown task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: beginning shutdown process [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: handler 0x7fdd12f2af20 shutdown in read dir completed. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [tls-handler] - id=0x7fdd12f2b2b0: shutting down read direction with error 0. Flushing queues. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: handler 0x7fdd12f2b2b0 shutdown in read dir completed. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: handler 0x7fdd15009638 shutdown in read dir completed. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2a198: Scheduling (null) task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2a198: Running (null) task with status [INFO] [2023-10-10T14:46:08Z] [000070000be24000] [mqtt-client] - id=0x7fdd15009600: sending disconnect message as part of graceful shutdown. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [tls-handler] - id=0x7fdd12f2b2b0: SSLWrite failed with OSStatus error code -9805. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [mqtt-client] - id=0x7fdd15009600: failed to send courteous disconnect io message [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: handler 0x7fdd15009638 shutdown in write dir completed. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: handler 0x7fdd12f2b2b0 shutdown in write dir completed. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [socket] - id=0x7fdd12f2a020 fd=18: closing [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f60490: Scheduling kqueue_event_loop_clean_up_handle_data task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2afc0: Scheduling socket_handler_close task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600000f60490: Running kqueue_event_loop_clean_up_handle_data task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2afc0: Running socket_handler_close task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: handler 0x7fdd12f2af20 shutdown in write dir completed. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2a198: Scheduling (null) task for immediate execution [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2a198: Running (null) task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: during shutdown, canceling task 0x7fdd12f2b2e0 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x7fdd12f2b2e0: Running tls_timeout task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: during shutdown, canceling task 0x600001364e70 [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [task-scheduler] - id=0x600001364e70: Running mqtt_connack_timeout task with status [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel-bootstrap] - id=0x600001360850: channel 0x7fdd12f2a170 shutdown with error 0. Exception ignored in: <class 'AttributeError'> Traceback (most recent call last): File "/usr/local/lib/python3.8/site-packages/awscrt/mqtt.py", line 483, in _on_connection_failure Traceback (most recent call last): File "pubsub.py", line 107, in connect_future.result() File "/usr/local/Cellar/python@3.8/3.8.5/Frameworks/Python.framework/Versions/3.8/lib/python3.8/concurrent/futures/_base.py", line 439, in result self._on_connection_failure_cb(connection=self, callback_data=data) File "pubsub.py", line 68, in on_connection_failure assert isinstance(callback_data, mqtt.OnConnectionFailuredata) AttributeError: module 'awscrt.mqtt' has no attribute 'OnConnectionFailuredata' [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel] - id=0x7fdd12f2a170: destroying channel. [DEBUG] [2023-10-10T14:46:08Z] [000070000be24000] [channel-bootstrap] - id=0x600001360850: releasing bootstrap reference return self.get_result() File "/usr/local/Cellar/python@3.8/3.8.5/Frameworks/Python.framework/Versions/3.8/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. [DEBUG] [2023-10-10T14:46:08Z] [00007ff8514d1640] [mqtt-client] - id=0x7fdd15009600: user called disconnect. [ERROR] [2023-10-10T14:46:08Z] [00007ff8514d1640] [mqtt-client] - id=0x7fdd15009600: Connection is not open, and may not be closed [DEBUG] [2023-10-10T14:46:08Z] [00007ff8514d1640] [mqtt-client] - id=0x7fdd15009600: Last refcount on connection has been released, start destroying the connection. [DEBUG] [2023-10-10T14:46:08Z] [00007ff8514d1640] [mqtt-client] - id=0x7fdd15009600: Destroying connection [DEBUG] [2023-10-10T14:46:08Z] [00007ff8514d1640] [mqtt-topic-tree] - tree=0x7fdd15009918: Cleaning up topic tree

miteshkoradia-amazon commented 1 year ago

1) I created Things from Console and downloaded Certs and used AmazonRootCA1 2) Tried restart and collected full logs as attached above. 3) There is no specific config to block package.

xiazhvera commented 1 year ago

Update: Mitesh shared policy with us. And it turns out to be an issue with the policy setup. The issue is gone after fixing the policy. Closed the issue.

github-actions[bot] commented 1 year 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.