subscribeTimeoutException on shadowUpdate in subscription callback

[daviian]

Scenario

Device connects an AWSIoTMQTTShadowClient and retrieves the used MQTTClient with getMQTTConnection().
The device subscribes to a topic on the MQTTClient und performs sensor readings and a shadow update in the callback.

This results in following log output:
First line is from my callback method.

2018-01-18 07:31:45,728 - AWSIoTPythonSDK.core - INFO - Update Device Shadow
2018-01-18 07:31:46,553 - AWSIoTPythonSDK.core.protocol.mqtt_core - INFO - Performing sync subscribe...
2018-01-18 07:31:46,554 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Adding a new subscription record: $aws/things/<THING_NAME>/shadow/update/accepted qos: 0
2018-01-18 07:31:46,554 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Filling in custom suback event callback...
2018-01-18 07:31:47,940 - AWSIoTPythonSDK.core.protocol.connection.cores - DEBUG - stableConnection: Resetting the backoff time to: 1 sec.
2018-01-18 07:31:51,554 - AWSIoTPythonSDK.core.protocol.internal.clients - DEBUG - Removing custom event callback...
2018-01-18 07:31:51,555 - AWSIoTPythonSDK.core.protocol.mqtt_core - ERROR - Subscribe timed out
2018-01-18 07:31:51,555 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Produced [suback] event
2018-01-18 07:31:51,556 - AWSIoTPythonSDK.core.protocol.internal.workers - DEBUG - Dispatching [suback] event
Exception in thread Thread-2:
Traceback (most recent call last):
  File "/usr/lib/python3.6/threading.py", line 916, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "$HOME/.local/lib/python3.6/site-packages/AWSIoTPythonSDK/core/protocol/internal/workers.py", line 147, in _dispatch
    self._dispatch_one()
  File "$HOME/.local/lib/python3.6/site-packages/AWSIoTPythonSDK/core/protocol/internal/workers.py", line 154, in _dispatch_one
    self._dispatch_methods[event_type](mid, data)
  File "$HOME/.local/lib/python3.6/site-packages/AWSIoTPythonSDK/core/protocol/internal/workers.py", line 237, in _dispatch_message
    message_callback(None, None, message)  # message_callback(client, userdata, message)
  File "$HOME/Development/master-thesis/thermal-sensor/ThermalSensor.py", line 111, in _updateShadow
    self._getState()), self._handleResponse, 5)
  File "$HOME/.local/lib/python3.6/site-packages/AWSIoTPythonSDK/core/shadow/deviceShadow.py", line 356, in shadowUpdate
    self._shadowManagerHandler.basicShadowSubscribe(self._shadowName, "update", self.generalCallback)
  File "$HOME/.local/lib/python3.6/site-packages/AWSIoTPythonSDK/core/shadow/shadowManager.py", line 70, in basicShadowSubscribe
    self._mqttCoreHandler.subscribe(currentShadowAction.getTopicAccept(), 0, srcCallback)
  File "$HOME/.local/lib/python3.6/site-packages/AWSIoTPythonSDK/core/protocol/mqtt_core.py", line 281, in subscribe
    raise subscribeTimeoutException()
AWSIoTPythonSDK.exception.AWSIoTExceptions.subscribeTimeoutException

[tbergeltffs]

I'm seeing the same subscribeTimeoutException when using two AWSIoTMQTTShadowClients and the second shadow client tries to update the shadow. I'm wondering if my issue is because the two clients are on separate threads because I haven't had any issue when they run in the same thead.

[liuszeng]

Hi @daviian ,

Thank you for providing the information.

Let me rephrase to see if I am understanding your case correctly. You are trying to do the following things:

1. Connect to AWS IoT using AWSIoTMQTTShadowClient.
2. Retrieve the underneath AWSIoTMQTTClient. 2 clients share the same MQTT connection.
3. With AWSIoTMQTTClient, it subscribes to a topic and configured a message callback.
4. In that message callback, it performs sensor reading and tries to update the shadow.

The problem with it is that, the SDK does not allow synchronous API invocation within message callback. On the first shadow update request, it needs to subscribe to its corresponding shadow accepted/rejected topics, which are synchronous calls, resulting in subscribeTimeoutException. For more details, please check the following link:
https://github.com/aws/aws-iot-device-sdk-python#synchronous-apis-and-asynchronous-apis

One thing you can do is to have the shadow update running in a separate thread so that it will not interfere with the callback dispatching. Another thing you can do is to use separate MQTT connections to AWS IoT. In that case, 2 clients are independent and will interfere with each other.

Correct me if I am wrong. Hope the above helps.

Thanks,
Liusu

[daviian]

@liuszeng Thanks for your reply.

You are totally right. That's exactly what I want to achieve.

As far as I understand now the shadow client is not able to perform asynchronous tasks on the shadow, that's why the only applicable possibilities are your proposed ones.
But having 2 clients means that I have to register 2 devices in the AWS IoT console, correct?
So it feels like running a separate thread for the shadow update is the best solution?

Best regards,
David

[tbergeltffs]

@daviian
You can have two separate shadow clients that both connect to the same shadow. You create two separate instances of AWSIoTMQTTShadowClient and on each one you call createShadowHandlerWithName with the same shadow name.

[liuszeng]

Hi @daviian ,

@tbergeltffs is also correct. Using 2 instances of the SDK client would also solve the problem. Keep in mind that the client mainly maintains a MQTT connection and perform shadow operations using that connection. As long as the 2 clients are connected with different client ids, you can use createShadowHandlerWithName to operate different shadow JSON document as you want.

Hope the above helps.

Thanks,
Liusu

[daviian]

@tbergeltffs @liuszeng
But having 2 separate instances with seperate clientId leads to two virtual devices in the IoT console, thus requires two certificates, private keys and so on. Or am I wrong?

At first I had one MQTT client and one shadow client, not sharing the connection. But that lead to the other issue I opened also yesterday (#96).
But I think my mistake was using the same clientId, at least that's my guess. ;-)

Hopefully you can enlighten me in my confusion ;-)

Ok I might have found the answer to all the mystery about clientId 😃
clientId != thingName
That's why I can connect twice with the same certificate to the same shadow, but with different clientId.

[liuszeng]

Hi @daviian ,

You are correct. Client id and thing name are totally different things.

Client id is there only to accommodate with the MQTT protocol, as a client id is required to establish the connection to AWS IoT. Thing name is more of an identifier in your account to distinguish different shadow JSON docs. Once the connection is established, you can access any shadow JSON docs using that connection. AWS IoT does not allow 2 connections with the same client id.

Hope the above helps. Please feel free to re-open the issue if you have further questions.

Thanks,
Liusu