aws/aws-iot-device-sdk-python

Failed to connect to AWS through device shadow

carollion105 opened this issue · 7 comments

Describe the bug

A connection failure occurred when I run the device shadow report message:

2023-01-06 10:13:13,772 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Initializing MQTT layer...
2023-01-06 10:13:13,773 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Registering internal event callbacks to MQTT layer...
2023-01-06 10:13:13,773 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - MqttCore initialized
2023-01-06 10:13:13,773 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Client id: Shadow
2023-01-06 10:13:13,773 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Protocol version: MQTTv3.1.1
2023-01-06 10:13:13,773 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Authentication type: TLSv1.2 certificate based Mutual Auth.
2023-01-06 10:13:13,773 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Configuring offline requests queueing: max queue size: 0
2023-01-06 10:13:13,773 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Configuring offline requests queue draining interval: 0.100000 sec
2023-01-06 10:13:13,774 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Configuring endpoint...
2023-01-06 10:13:13,774 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Configuring certificates and ciphers...
2023-01-06 10:13:13,774 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Configuring reconnect back off timing...
2023-01-06 10:13:13,774 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Base quiet time: 1.000000 sec
2023-01-06 10:13:13,774 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Max quiet time: 32.000000 sec
2023-01-06 10:13:13,775 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Stable connection time: 20.000000 sec
2023-01-06 10:13:13,775 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Configuring connect/disconnect time out: 60.000000 sec
2023-01-06 10:13:13,775 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Configuring MQTT operation time out: 60.000000 sec
2023-01-06 10:13:13,775 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Performing sync connect...
2023-01-06 10:13:13,775 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Performing async connect...
2023-01-06 10:13:13,775 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Keep-alive: 600.000000 sec
2023-01-06 10:13:13,776 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Event consuming thread started
2023-01-06 10:13:13,776 - AWSIoTPythonSDK.core.protocol.mqtt_core - DEBUG - Passing in general notification callbacks to internal client...
2023-01-06 10:13:13,776 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Filling in fixed event callbacks: CONNACK, DISCONNECT, MESSAGE
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Cleaning up before stopping event consuming
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Event queue cleared
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Stopping network I/O thread...
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Network thread stopped
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Event callbacks cleared
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Event consuming thread stopped
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Waiting for event consumer to completely stop
2023-01-06 10:15:19,521 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Exiting dispatching loop...
2023-01-06 10:15:19,521 - AWSIoTPythonSDK.core.protocol.mqtt_core - DEBUG - Event consumer stopped
Traceback (most recent call last):
  File "/opt/tsti/ReportInfo_bkg/winmain.py", line 486, in <module>
    myAWSIoTMQTTShadowClient.connect()
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/MQTTLib.py", line 1278, in connect
    return self._AWSIoTMQTTClient.connect(keepAliveIntervalSecond)
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/MQTTLib.py", line 520, in connect
    return self._mqtt_core.connect(keepAliveIntervalSecond)
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/protocol/mqtt_core.py", line 196, in connect
    self.connect_async(keep_alive_sec, self._create_blocking_ack_callback(event))
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/protocol/mqtt_core.py", line 223, in connect_async
    raise e
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/protocol/mqtt_core.py", line 211, in connect_async
    rc = self._internal_async_client.connect(keep_alive_sec, ack_callback)
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/protocol/internal/clients.py", line 125, in connect
    rc = self._paho_client.connect(host, port, keep_alive_sec)
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/protocol/paho/client.py", line 665, in connect
    return self.reconnect()
  File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/protocol/paho/client.py", line 819, in reconnect
    self._ssl = ssl.wrap_socket(
  File "/usr/lib/python3.8/ssl.py", line 1405, in wrap_socket
    return context.wrap_socket(
  File "/usr/lib/python3.8/ssl.py", line 500, in wrap_socket
    return self.sslsocket_class._create(
  File "/usr/lib/python3.8/ssl.py", line 1040, in _create
    self.do_handshake()
  File "/usr/lib/python3.8/ssl.py", line 1309, in do_handshake
    self._sslobj.do_handshake()
ssl.SSLError: [SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:1131)

Process finished with exit code 1

My python version is 3.8.10 and ssl version is 1.1.1.

Expected Behavior

If it runs successfully, it should start the thread to connect to AWS and report information to update the device shadow.
It should look something like this:

2023-01-06 10:25:02,102 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Filling in fixed event callbacks: CONNACK, DISCONNECT, MESSAGE
2023-01-06 10:25:02,994 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Starting network I/O thread...

Current Behavior

It is now connected until the timeout stop thread exits:

2023-01-06 10:13:13,776 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Filling in fixed event callbacks: CONNACK, DISCONNECT, MESSAGE
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Cleaning up before stopping event consuming
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Event queue cleared
2023-01-06 10:15:19,515 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Stopping network I/O thread…

Reproduction Steps

The device shadow connection AWS code is as follows:

awsiotHost = get_awsiot_host()  
awsiotPort = 8883
rootCAPath = "/opt/tsti/cert/AmazonRootCA1.pem"
privateKeyPath = "/opt/tsti/cert/private.pem.key"
certificatePath = "/opt/tsti/cert/device.pem.crt"
myAWSIoTMQTTShadowClient = None
myAWSIoTMQTTShadowClient = AWSIoTMQTTShadowClient("ShadowReport")

myAWSIoTMQTTShadowClient.configureEndpoint(awsiotHost, awsiotPort)
myAWSIoTMQTTShadowClient.configureCredentials(
    rootCAPath, privateKeyPath, certificatePath
)

myAWSIoTMQTTShadowClient.configureAutoReconnectBackoffTime(1, 32, 20)
myAWSIoTMQTTShadowClient.configureConnectDisconnectTimeout(60)  # 10sec
myAWSIoTMQTTShadowClient.configureMQTTOperationTimeout(30)  # 5sec

myAWSIoTMQTTShadowClient.connect()

Possible Solution

No response

Additional Information/Context

No response

SDK version used

AWSIoTPythonSDK==1.5.2

Environment details (OS name and version, etc.)

ubuntu20.04

Have you seen the shadow sample included in this repo: Shadow.py
It connects with the following:

    mqtt_connection = cmdUtils.build_mqtt_connection(None, None)
    connected_future = mqtt_connection.connect()
    shadow_client = iotshadow.IotShadowClient(mqtt_connection)

And it build the mqtt connection in command_line_utils.py

    def build_direct_mqtt_connection(self, on_connection_interrupted, on_connection_resumed):
        proxy_options = self.get_proxy_options_for_mqtt_connection()
        mqtt_connection = mqtt_connection_builder.mtls_from_path(
            endpoint=self.get_command_required(self.m_cmd_endpoint),
            port=self.get_command_required("port"),
            cert_filepath=self.get_command_required(self.m_cmd_cert_file),
            pri_key_filepath=self.get_command_required(self.m_cmd_key_file),
            ca_filepath=self.get_command(self.m_cmd_ca_file),
            on_connection_interrupted=on_connection_interrupted,
            on_connection_resumed=on_connection_resumed,
            client_id=self.get_command_required("client_id"),
            clean_session=False,
            keep_alive_secs=30,
            http_proxy_options=proxy_options)
        return mqtt_connection


    def build_mqtt_connection(self, on_connection_interrupted, on_connection_resumed):
        if self.get_command(self.m_cmd_signing_region) is not None:
            return self.build_websocket_mqtt_connection(on_connection_interrupted, on_connection_resumed)
        else:
            return self.build_direct_mqtt_connection(on_connection_interrupted, on_connection_resumed)

Can you try running the sample first to make sure your credentials/policies are setup correctly?

@jmklix Thank you for your answer. I have no problem with my credentials/policies through shadow test.
I run shadow which connects to the AWS update device Shadow.

In addition,myAWSIoTMQTTShadowClient.connect() I run several times may connect successfully once, others are connection failure reported above error.

Sorry for my confusion, I linked how to connect with the python-v2 sdk rather then this v1 sdk. (I would recommend using the v2 sdk if you have a choice)

Just to clarify for the current error that you are seeing only happens some times when running the above code?

Often the connection fails, occasionally connected correctly but information reported for a few minutes appear subscribeTimeoutException again.

Traceback (most recent call last):

File "winmain.py", line 489, in
deviceShadowHandler.shadowRegisterDeltaCallback(custom_shadow_callback_delta)
File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/shadow/deviceShadow.py", line 398, in shadowRegisterDeltaCallback
self._shadowManagerHandler.basicShadowSubscribe(self._shadowName, "delta", self.generalCallback)
File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/shadow/shadowManager.py", line 68, in basicShadowSubscribe
self._mqttCoreHandler.subscribe(currentShadowAction.getTopicDelta(), 0, srcCallback)
File "/usr/local/lib/python3.8/dist-packages/AWSIoTPythonSDK/core/protocol/mqtt_core.py", line 302, in subscribe
raise subscribeTimeoutException()
AWSIoTPythonSDK.exception.AWSIoTExceptions.subscribeTimeoutException

I can successfully run the connection on another device with the same code.

Is you device experiencing any interruptions to the connection to IoT core?

Can you also check the cloudwatch logs to see what the server is seeing, and what errors might be causing you to not connect? You can do this by following this: https://docs.aws.amazon.com/iot/latest/developerguide/cloud-watch-logs.html

⚠️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.