-
Notifications
You must be signed in to change notification settings - Fork 236
Description
Context
- OS and version used: Ubuntu 22.04.5 LTS
- Java runtime used: openjdk version "17.0.8" 2023-07-18
- SDK version used: 2.5.0
Description of the issue
I recently realized that when my device attempts to send a message to a hub that currently has its message quota exceeded, the SDK doesn't handle the error correctly.
Whenever you attempt to make an update to a Device Twin in such a scenario, I receive back a response with a QUOTA_EXCEEDED status code.
However, if you attempt to send a message to the cloud (using the DeviceClient.sendEventAsync() method), the SDK instead fails with a Mqtt connection lost protocol failure, which changes the status to the connection to DISCONNECTED_RETRYING with reason NO_NETWORK.
I'd expect that the message goes through the cloud, but it's then rejected with QUOTA_EXCEEDED status and the device gets notified by it on the callback response.
Instead, the message sending process fails with a java.io.EOFException, that causes the aformentioned MQTT connection lost error.
Code sample exhibiting the issue
For simualtion, I've used a modified version of the device-reconnection-sample provided with the SDK. The only changes I made were to comment out cloud interactions via Device Twins, so we use simply the D2C messages.
package samples.com.microsoft.azure.sdk.iot;
import com.microsoft.azure.sdk.iot.device.*;
import com.microsoft.azure.sdk.iot.device.exceptions.IotHubClientException;
import com.microsoft.azure.sdk.iot.device.transport.IotHubConnectionStatus;
import com.microsoft.azure.sdk.iot.device.twin.*;
import lombok.extern.slf4j.Slf4j;
import java.util.Queue;
import java.util.UUID;
import java.util.concurrent.ConcurrentLinkedQueue;
/**
* Manages the lifetime of a DeviceClient instance such that it is always either connected or attempting to reconnect.
* It also demonstrates the best practices for handling a client's twin. See this sample's readme for a more detailed
* explanation on how this sample works and how it can be modified to fit your needs.
*/
@Slf4j
public class DeviceClientManager implements DesiredPropertiesCallback, MethodCallback, MessageSentCallback, MessageCallback, GetTwinCallback, ReportedPropertiesCallback
{
// The client. Can be replaced with a module client for writing the equivalent code for a module.
private final DeviceClient deviceClient;
// The twin for this client. Stays up to date as reported properties are sent and desired properties are received.
private Twin twin;
// Outgoing work queues of the client
private final Queue<Message> telemetryToResend = new ConcurrentLinkedQueue<>();
private final TwinCollection reportedPropertiesToSend = new TwinCollection();
// Connection state of the client. This sample is written in such a way that you do not actually need to check this
// value before performing any operations, but it is provided here anyways.
private IotHubConnectionStatus connectionStatus = IotHubConnectionStatus.DISCONNECTED;
// This lock is used to wake up the Iot-Hub-Connection-Manager-Thread when a terminal disconnection event occurs
// and the device client needs to be manually re-opened.
private final Object reconnectionLock = new Object();
// State flag that signals that the client is in the process of getting the current twin for this client and that
// any outgoing reported properties should hold off on being sent until this twin has been retrieved.
private boolean gettingTwinAfterReconnection = false;
public DeviceClientManager(String deviceConnectionString, IotHubClientProtocol protocol)
{
// Lower keep alive interval values help the client recognize disconnection events sooner, but do require
// sending keep-alive pings more frequently. Scenarios that prioritize minimizing network traffic should have
// higher values. Scenarios that prioritize minimizing time spent disconnected should have lower values.
ClientOptions clientOptions = ClientOptions.builder().keepAliveInterval(100).build();
this.deviceClient = new DeviceClient(deviceConnectionString, protocol, clientOptions);
}
public void run()
{
try
{
this.deviceClient.setConnectionStatusChangeCallback(
(connectionStatusChangeContext) ->
{
IotHubConnectionStatus newStatus = connectionStatusChangeContext.getNewStatus();
IotHubConnectionStatusChangeReason newStatusReason = connectionStatusChangeContext.getNewStatusReason();
IotHubConnectionStatus previousStatus = connectionStatusChangeContext.getPreviousStatus();
this.connectionStatus = newStatus;
if (newStatusReason == IotHubConnectionStatusChangeReason.BAD_CREDENTIAL)
{
// Should only happen if using a custom SAS token provider and the user-generated SAS token
// was incorrectly formatted. Users who construct the device client with a connection string
// will never see this, and users who use x509 authentication will never see this.
log.error("Ending sample because the provided credentials were incorrect or malformed");
System.exit(-1);
}
if (newStatus == IotHubConnectionStatus.DISCONNECTED && newStatusReason == IotHubConnectionStatusChangeReason.EXPIRED_SAS_TOKEN)
{
// Should only happen if the user provides a shared access signature instead of a connection string.
// indicates that the device client is now unusable because there is no way to renew the shared
// access signature. Users who want to pass in these tokens instead of using a connection string
// should see the custom SAS token provider sample in this repo.
// https://github.com/Azure/azure-iot-sdk-java/blob/main/device/iot-device-samples/custom-sas-token-provider-sample/src/main/java/samples/com/microsoft/azure/sdk/iot/CustomSasTokenProviderSample.java
log.error("Ending sample because the provided credentials have expired.");
System.exit(-1);
}
if (newStatus == IotHubConnectionStatus.DISCONNECTED
&& newStatusReason != IotHubConnectionStatusChangeReason.CLIENT_CLOSE)
{
// only need to reconnect if the device client reaches a DISCONNECTED state and if it wasn't
// from intentionally closing the client.
synchronized (this.reconnectionLock)
{
// Note that you cannot call "deviceClient.open()" or "deviceClient.close()" from here
// since this is a callback thread. You must open/close the client from a different thread.
// Because of that, this sample wakes up the Iot-Hub-Connection-Manager-Thread to do that.
log.debug("Notifying the connection manager thread to start re-opening this client");
this.reconnectionLock.notify();
}
}
// upon reconnecting, it is optional, but recommended, to get the current twin state. This will
// allow you to get the current desired properties state in case this client missed any desired
// property updates while it was temporarily disconnected.
if (previousStatus == IotHubConnectionStatus.DISCONNECTED_RETRYING
&& newStatus == IotHubConnectionStatus.CONNECTED)
{
// hold off on sending any new reported properties until the twin has been retrieved
this.gettingTwinAfterReconnection = true;
this.deviceClient.getTwinAsync(this, null);
}
},
null);
Thread.currentThread().setName("Iot-Hub-Connection-Manager-Thread");
while (true)
{
boolean encounteredFatalException = !openDeviceClientWithRetry();
if (encounteredFatalException)
{
// Fatal error encountered. Exit the sample, but close the client in the finally block first
return;
}
new Thread(() ->
{
try
{
Thread.currentThread().setName("Iot-Hub-Worker-Thread");
// this function simulates how a user may use a device client instance once it is open. In this
// sample, it includes sending telemetry and updating reported properties.
doWork();
}
catch (IllegalStateException e)
{
log.debug("Client was closed while doing work. Ending worker thread while re-opening the client.");
}
}).start();
synchronized (this.reconnectionLock)
{
// Wait until the client needs to be re-opened. This happens when the client reaches a
// terminal DISCONNECTED state unexpectedly. For instance, if the client loses network connectivity
// and does not regain network connectivity before the SDK's retry logic has timed out.
this.reconnectionLock.wait();
}
log.debug("Connection manager thread woken up to start re-opening this client");
}
}
catch (InterruptedException e)
{
log.debug("Connection management function interrupted, likely because the sample has ended");
}
finally
{
deviceClient.close();
}
}
private boolean openDeviceClientWithRetry() throws InterruptedException
{
while (true)
{
try
{
this.deviceClient.close();
log.debug("Attempting to open the device client");
this.deviceClient.open(false);
log.debug("Successfully opened the device client");
// region cloud to device messaging setup
// This region can be removed if no cloud to device messaging will be sent to this client
this.deviceClient.setMessageCallback(this, null);
// endregion
// region direct methods setup
// This region can be removed if no direct methods will be invoked on this client
this.deviceClient.subscribeToMethods(this, null);
// endregion
// region twin setup
// This region can be removed if no twin features will be used by this client
this.deviceClient.subscribeToDesiredProperties(this, null);
// note that this call is optional, but recommended for most scenarios. If a device is booting up for the
// first time, this call is the only way to get all the desired property updates that it missed while
// being offline. However this does send and receive bits over the wire, so it is not free.
// this.twin = this.deviceClient.getTwin();
//
// this.reportedPropertiesToSend.setVersion(twin.getReportedProperties().getVersion());
// log.debug("Current twin received:");
// log.debug(this.twin.toString());
// endregion
return true;
}
catch (IotHubClientException e)
{
switch (e.getStatusCode())
{
case UNAUTHORIZED:
log.error("Failed to open the device client due to incorrect or badly formatted credentials", e);
return false;
case NOT_FOUND:
log.error("Failed to open the device client because the device is not registered on your IoT Hub", e);
return false;
}
if (e.isRetryable())
{
log.debug("Failed to open the device client due to a retryable exception", e);
}
else
{
log.error("Failed to open the device client due to a non-retryable exception", e);
return false;
}
}
// Users may want to have this delay determined by an exponential backoff in order to avoid flooding the
// service with reconnect attempts. Lower delays mean a client will be reconnected sooner, but at the risk
// of wasting CPU cycles with attempts that the service is too overwhelmed to handle anyways.
log.debug("Sleeping a bit before retrying to open device client");
Thread.sleep(1000);
}
}
/**
* Sends telemetry and updates reported properties periodically. Returns if the client's connection was lost during
* this.
* <p>
* This method simulates typical useage of a client, but can be modified to fit your use case without losing the
* automatic reconnection and retry that this sample has.
*
* @throws IllegalStateException If the client's connection was lost as this method attempted to send telemetry or
* update reported properties.
*/
private void doWork() throws IllegalStateException
{
while (true)
{
sendTelemetryAsync();
// updateReportedPropertiesAsync();
try
{
// not recommended for actual applications, but this makes the sample's logs print at a readable pace
Thread.sleep(10000);
}
catch (InterruptedException e)
{
log.debug("Worker function interrupted, likely because the sample is being stopped.");
return;
}
}
}
// region telemetry
private void sendTelemetryAsync()
{
Message messageToSend;
if (this.telemetryToResend.isEmpty())
{
// If no previous messages failed to send, send a new message
messageToSend = new Message("hello world");
}
else
{
// If any previous message failed to send, retry sending it before moving on to new messages
messageToSend = this.telemetryToResend.remove();
}
try
{
this.deviceClient.sendEventAsync(messageToSend, this, null);
}
catch (IllegalStateException e)
{
log.debug("Device client was closed, so requeueing the message locally");
this.telemetryToResend.add(messageToSend);
throw e;
}
}
// callback for when a telemetry message is sent
@Override
public void onMessageSent(Message sentMessage, IotHubClientException e, Object callbackContext)
{
if (e == null)
{
log.debug("Successfully sent message with correlation Id {}", sentMessage.getCorrelationId());
return;
}
if (e.isRetryable())
{
log.warn("Failed to send message with correlation Id {} due to retryable error with status code {}. " +
"Requeueing message.", sentMessage.getCorrelationId(), e.getStatusCode().name());
telemetryToResend.add(sentMessage);
}
else
{
log.error("Failed to send message with correlation Id {} due to an unretryable error with status code {}. " +
"Discarding message as it can never be sent", sentMessage.getCorrelationId(), e.getStatusCode().name());
}
}
// endregion
// region twin
private void updateReportedPropertiesAsync()
{
String newPropertyKey = UUID.randomUUID().toString();
String newPropertyValue = UUID.randomUUID().toString();
this.reportedPropertiesToSend.put(newPropertyKey, newPropertyValue);
if (this.gettingTwinAfterReconnection)
{
log.debug("Delaying sending new reported properties update until the full twin has been retrieved after the most recent disconnection");
return;
}
try
{
this.deviceClient.updateReportedPropertiesAsync(
this.reportedPropertiesToSend,
this,
newPropertyKey);
}
catch (IllegalStateException e)
{
log.debug("Device client was closed. Waiting until the connection has been re-opened to update reported properties.");
throw e;
}
}
// callback for when a reported properties update request has been acknowledged by the service
@Override
public void onReportedPropertiesUpdateAcknowledged(
IotHubStatusCode statusCode,
ReportedPropertiesUpdateResponse response,
IotHubClientException e,
Object context)
{
String newReportedPropertyKey = (String) context;
if (e != null)
{
// no need to do anything with the error here. Below, the status code is checked in order to figure out how to respond
log.warn("Encountered an issue sending a reported properties update request", e);
}
if (e == null)
{
for (String propertyKey : this.reportedPropertiesToSend.keySet())
{
log.debug("Successfully updated reported properties with new key {} with value {}",
propertyKey,
this.reportedPropertiesToSend.get(propertyKey));
}
int newReportedPropertiesVersion = response.getVersion();
log.debug("New reported properties version is {}", newReportedPropertiesVersion);
this.reportedPropertiesToSend.setVersion(newReportedPropertiesVersion);
// update the local twin object now that the reported properties have been sent
twin.getReportedProperties().setVersion(newReportedPropertiesVersion);
if (!this.reportedPropertiesToSend.isEmpty())
{
twin.getReportedProperties().putAll(this.reportedPropertiesToSend);
}
// no need to send these properties again in the next reported properties update, so clear these properties.
this.reportedPropertiesToSend.clear();
}
else if (statusCode == IotHubStatusCode.PRECONDITION_FAILED)
{
for (String propertyKey : this.reportedPropertiesToSend.keySet())
{
log.debug("Failed to update reported properties with new key {} with value {} due to the reported " +
"properties version being out of date. Will try sending again later after updating the " +
"reported properties version.", propertyKey, this.reportedPropertiesToSend.get(propertyKey));
}
this.reportedPropertiesToSend.setVersion(twin.getReportedProperties().getVersion());
}
else if (e.isRetryable())
{
for (String propertyKey : this.reportedPropertiesToSend.keySet())
{
log.warn("Failed to update reported properties with new key {} with value {} due to retryable error " +
"with status code {}. Will try sending again later.",
propertyKey,
this.reportedPropertiesToSend.get(propertyKey),
statusCode.name());
}
}
else
{
String newReportedPropertyValue = (String) twin.getReportedProperties().remove(newReportedPropertyKey);
log.error("Failed to update reported properties with new key {} with value {} due to an unretryable error " +
"with status code {}. Removing new property from twin.",
newReportedPropertyKey,
newReportedPropertyValue,
statusCode.name());
}
}
// callback for when a desired property update is received
@Override
public void onDesiredPropertiesUpdated(Twin newTwin, Object context)
{
log.debug("Desired properties update received by device");
if (!newTwin.getDesiredProperties().isEmpty())
{
this.twin.getDesiredProperties().putAll(newTwin.getDesiredProperties());
}
this.twin.getDesiredProperties().setVersion(newTwin.getDesiredProperties().getVersion());
log.debug("New twin state from device side:");
log.debug(this.twin.toString());
}
// callback for when a get twin call has succeeded and the current twin has been retrieved.
@Override
public void onTwinReceived(Twin twin, IotHubClientException e, Object context)
{
if (e == null)
{
log.debug("Received the current twin state: ");
log.debug(twin.toString());
this.twin = twin;
this.reportedPropertiesToSend.setVersion(twin.getReportedProperties().getVersion());
this.gettingTwinAfterReconnection = false;
}
else if (e.isRetryable())
{
log.warn("Encountered a retryable error with status code {} while trying to get the client's twin. " +
"Trying again...", e.getStatusCode());
this.deviceClient.getTwinAsync(this, null);
}
else
{
log.error("Encountered a non retryable error with status code {} while trying to get the client's twin. " +
"Abandoning getting twin.", e.getStatusCode());
}
}
// endregion
// region direct methods
// callback for when a direct method is invoked on this device
@Override
public DirectMethodResponse onMethodInvoked(String methodName, DirectMethodPayload payload, Object context)
{
// Typically there would be some method handling that differs based on the name of the method and/or the payload
// provided, but this sample's method handling is simplified for brevity. There are other samples in this repo
// that demonstrate handling methods in more depth.
log.debug("Method {} invoked on device.", methodName);
return new DirectMethodResponse(200, null);
}
// endregion
// region cloud to device messaging
// callback for when a cloud to device message is received by this device
@Override
public IotHubMessageResult onCloudToDeviceMessageReceived(Message message, Object callbackContext)
{
log.debug("Received cloud to device message with correlation Id {}", message.getCorrelationId());
return IotHubMessageResult.COMPLETE;
}
// endregion
}Console log of the issue
Connected to the target VM, address: '127.0.0.1:47785', transport: 'socket'
2025-06-20 22:25:56,337 INFO (main) [samples.com.microsoft.azure.sdk.iot.DeviceClientManagerSample] - Starting...
2025-06-20 22:25:56,340 INFO (main) [samples.com.microsoft.azure.sdk.iot.DeviceClientManagerSample] - Setup parameters...
2025-06-20 22:25:56,343 DEBUG (main) [samples.com.microsoft.azure.sdk.iot.DeviceClientManagerSample] - Setup parameter: Protocol = [mqtt]
2025-06-20 22:25:56,343 INFO (main) [samples.com.microsoft.azure.sdk.iot.DeviceClientManagerSample] - Successfully created an IoT Hub client.
2025-06-20 22:25:56,409 INFO (main) [com.microsoft.azure.sdk.iot.device.transport.ExponentialBackoffWithJitter] - NOTE: A new instance of ExponentialBackoffWithJitter has been created with the following properties. Retry Count: 2147483647, Min Backoff Interval: 100, Max Backoff Interval: 10000, Max Time Between Retries: 100, Fast Retry Enabled: true
2025-06-20 22:25:56,595 DEBUG (main) [com.microsoft.azure.sdk.iot.device.ClientConfiguration] - Device configured to use software based SAS authentication provider
2025-06-20 22:25:56,607 DEBUG (main) [com.microsoft.azure.sdk.iot.device.DeviceClient] - Initialized a DeviceClient instance using SDK version 2.5.0
2025-06-20 22:25:56,607 INFO (main) [samples.com.microsoft.azure.sdk.iot.DeviceClientManagerSample] - Starting IoT Hub client...
2025-06-20 22:25:56,608 INFO (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.DeviceClient] - Closing device client...
2025-06-20 22:25:56,608 INFO (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.DeviceClient] - Device client closed successfully
2025-06-20 22:25:57,891 DEBUG (Iot-Hub-Connection-Manager-Thread) [samples.com.microsoft.azure.sdk.iot.DeviceClientManager] - Attempting to open the device client
2025-06-20 22:25:58,369 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection] - Opening MQTT connection...
2025-06-20 22:25:58,401 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sending MQTT CONNECT packet...
2025-06-20 22:25:59,917 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sent MQTT CONNECT packet was acknowledged
2025-06-20 22:25:59,917 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sending MQTT SUBSCRIBE packet for topic devices/GXa05-02/messages/devicebound/#
2025-06-20 22:26:00,108 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sent MQTT SUBSCRIBE packet for topic devices/GXa05-02/messages/devicebound/# was acknowledged
2025-06-20 22:26:00,109 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection] - MQTT connection opened successfully
2025-06-20 22:26:00,109 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - The connection to the IoT Hub has been established
2025-06-20 22:26:00,110 INFO (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Updating transport status to new status CONNECTED with reason CONNECTION_OK
2025-06-20 22:26:00,110 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.DeviceIO] - Starting worker threads
2025-06-20 22:26:00,114 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Invoking connection status callbacks with new status details
2025-06-20 22:26:01,469 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Client connection opened successfully
2025-06-20 22:26:01,478 INFO (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.DeviceClient] - Device client opened successfully
2025-06-20 22:26:02,533 DEBUG (Iot-Hub-Connection-Manager-Thread) [samples.com.microsoft.azure.sdk.iot.DeviceClientManager] - Successfully opened the device client
2025-06-20 22:26:02,540 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Message was queued to be sent later ( Message details: Correlation Id [769175ff-4ae9-4b98-b4ac-b5aa7822a03a] Message Id [c74feb7e-4dc6-4d7b-8044-b3e95cde6d58] Device Operation Type [DEVICE_OPERATION_METHOD_SUBSCRIBE_REQUEST] )
2025-06-20 22:26:02,540 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [769175ff-4ae9-4b98-b4ac-b5aa7822a03a] Message Id [c74feb7e-4dc6-4d7b-8044-b3e95cde6d58] Device Operation Type [DEVICE_OPERATION_METHOD_SUBSCRIBE_REQUEST] )
2025-06-20 22:26:02,543 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sending MQTT SUBSCRIBE packet for topic $iothub/methods/POST/#
2025-06-20 22:26:02,783 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sent MQTT SUBSCRIBE packet for topic $iothub/methods/POST/# was acknowledged
2025-06-20 22:26:02,783 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Invoking the callback function for sent message, IoT Hub responded to message ( Message details: Correlation Id [769175ff-4ae9-4b98-b4ac-b5aa7822a03a] Message Id [c74feb7e-4dc6-4d7b-8044-b3e95cde6d58] Device Operation Type [DEVICE_OPERATION_METHOD_SUBSCRIBE_REQUEST] ) with status OK
2025-06-20 22:26:02,786 DEBUG (Iot-Hub-Connection-Manager-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Message was queued to be sent later ( Message details: Correlation Id [fe47de92-03d5-4943-b7c8-d9547faf06ea] Message Id [bbf0d45f-4022-48d4-b98c-0e5f675f11cd] Device Operation Type [DEVICE_OPERATION_TWIN_SUBSCRIBE_DESIRED_PROPERTIES_REQUEST] )
2025-06-20 22:26:02,794 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [fe47de92-03d5-4943-b7c8-d9547faf06ea] Message Id [bbf0d45f-4022-48d4-b98c-0e5f675f11cd] Device Operation Type [DEVICE_OPERATION_TWIN_SUBSCRIBE_DESIRED_PROPERTIES_REQUEST] )
2025-06-20 22:26:02,794 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sending MQTT SUBSCRIBE packet for topic $iothub/twin/res/#
2025-06-20 22:26:02,988 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sent MQTT SUBSCRIBE packet for topic $iothub/twin/res/# was acknowledged
2025-06-20 22:26:02,988 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sending MQTT SUBSCRIBE packet for topic $iothub/twin/PATCH/properties/desired/#
2025-06-20 22:26:03,176 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sent MQTT SUBSCRIBE packet for topic $iothub/twin/PATCH/properties/desired/# was acknowledged
2025-06-20 22:26:03,176 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Invoking the callback function for sent message, IoT Hub responded to message ( Message details: Correlation Id [fe47de92-03d5-4943-b7c8-d9547faf06ea] Message Id [bbf0d45f-4022-48d4-b98c-0e5f675f11cd] Device Operation Type [DEVICE_OPERATION_TWIN_SUBSCRIBE_DESIRED_PROPERTIES_REQUEST] ) with status OK
2025-06-20 22:26:05,367 DEBUG (Iot-Hub-Worker-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Message was queued to be sent later ( Message details: Correlation Id [b6777977-8348-481f-8074-2c48769aec09] Message Id [ed5d78c3-04fe-4f32-8ae2-e1d5ad0978d3] )
2025-06-20 22:26:05,377 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [b6777977-8348-481f-8074-2c48769aec09] Message Id [ed5d78c3-04fe-4f32-8ae2-e1d5ad0978d3] )
2025-06-20 22:26:05,659 DEBUG (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Mqtt connection lost
com.microsoft.azure.sdk.iot.device.transport.ProtocolException: Mqtt connection lost
at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:63) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:335) [classes/:?]
at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:304) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:441) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: org.eclipse.paho.client.mqttv3.MqttException: Connection lost
... 2 more
Caused by: java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:290) ~[?:?]
at java.io.DataInputStream.readByte(DataInputStream.java:268) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
... 1 more
2025-06-20 22:26:05,664 DEBUG (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Mapping throwable to NO_NETWORK because it was a retryable exception
com.microsoft.azure.sdk.iot.device.transport.ProtocolException: Mqtt connection lost
at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:63) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:335) [classes/:?]
at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:304) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:441) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: org.eclipse.paho.client.mqttv3.MqttException: Connection lost
... 2 more
Caused by: java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:290) ~[?:?]
at java.io.DataInputStream.readByte(DataInputStream.java:268) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
... 1 more
2025-06-20 22:26:05,664 WARN (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Updating transport status to new status DISCONNECTED_RETRYING with reason NO_NETWORK
com.microsoft.azure.sdk.iot.device.transport.ProtocolException: Mqtt connection lost
at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:63) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:335) [classes/:?]
at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:304) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:441) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: org.eclipse.paho.client.mqttv3.MqttException: Connection lost
... 2 more
Caused by: java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:290) ~[?:?]
at java.io.DataInputStream.readByte(DataInputStream.java:268) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
... 1 more
2025-06-20 22:26:05,664 DEBUG (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Invoking connection status callbacks with new status details
2025-06-20 22:26:11,015 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubReconnectTask] - Starting reconnection process
2025-06-20 22:26:11,017 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.RetryDecision] - NOTE: A new instance of RetryDecision has been created with retry enabled, the client will retry after 0 milliseconds
2025-06-20 22:26:11,017 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection] - Closing MQTT connection
2025-06-20 22:26:11,017 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection] - Successfully closed MQTT connection
2025-06-20 22:26:11,018 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection] - Opening MQTT connection...
2025-06-20 22:26:11,018 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sending MQTT CONNECT packet...
2025-06-20 22:26:12,492 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sent MQTT CONNECT packet was acknowledged
2025-06-20 22:26:12,492 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sending MQTT SUBSCRIBE packet for topic devices/GXa05-02/messages/devicebound/#
2025-06-20 22:26:12,716 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Sent MQTT SUBSCRIBE packet for topic devices/GXa05-02/messages/devicebound/# was acknowledged
2025-06-20 22:26:12,716 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection] - MQTT connection opened successfully
2025-06-20 22:26:12,716 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - The connection to the IoT Hub has been established
2025-06-20 22:26:12,716 INFO (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Updating transport status to new status CONNECTED with reason CONNECTION_OK
2025-06-20 22:26:12,716 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.DeviceIO] - Starting worker threads
2025-06-20 22:26:12,716 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Invoking connection status callbacks with new status details
2025-06-20 22:26:12,717 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [b6777977-8348-481f-8074-2c48769aec09] Message Id [ed5d78c3-04fe-4f32-8ae2-e1d5ad0978d3] )
2025-06-20 22:26:15,631 DEBUG (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt] - Mqtt connection lost
com.microsoft.azure.sdk.iot.device.transport.ProtocolException: Mqtt connection lost
at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:63) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:335) [classes/:?]
at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:304) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:441) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: org.eclipse.paho.client.mqttv3.MqttException: Connection lost
... 2 more
Caused by: java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:290) ~[?:?]
at java.io.DataInputStream.readByte(DataInputStream.java:268) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
... 1 more
2025-06-20 22:26:16,687 DEBUG (Iot-Hub-Worker-Thread) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Message was queued to be sent later ( Message details: Correlation Id [5ff3f9e9-1223-4bb0-87fe-b848bce37e6f] Message Id [3e4230bf-e074-4df9-b7b2-6cb44569a565] )
2025-06-20 22:26:16,688 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [5ff3f9e9-1223-4bb0-87fe-b848bce37e6f] Message Id [3e4230bf-e074-4df9-b7b2-6cb44569a565] )
2025-06-20 22:26:16,687 DEBUG (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Mapping throwable to NO_NETWORK because it was a retryable exception
com.microsoft.azure.sdk.iot.device.transport.ProtocolException: Mqtt connection lost
at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:63) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:335) [classes/:?]
at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:304) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:441) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: org.eclipse.paho.client.mqttv3.MqttException: Connection lost
... 2 more
Caused by: java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:290) ~[?:?]
at java.io.DataInputStream.readByte(DataInputStream.java:268) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
... 1 more
2025-06-20 22:26:16,688 WARN (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Updating transport status to new status DISCONNECTED_RETRYING with reason NO_NETWORK
com.microsoft.azure.sdk.iot.device.transport.ProtocolException: Mqtt connection lost
at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:63) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:335) [classes/:?]
at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:304) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:441) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197) [org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: org.eclipse.paho.client.mqttv3.MqttException: Connection lost
... 2 more
Caused by: java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:290) ~[?:?]
at java.io.DataInputStream.readByte(DataInputStream.java:268) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137) ~[org.eclipse.paho.client.mqttv3-1.2.5.jar:?]
... 1 more
2025-06-20 22:26:16,688 WARN (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Encountered exception while sending message with correlation id 5ff3f9e9-1223-4bb0-87fe-b848bce37e6f
com.microsoft.azure.sdk.iot.device.transport.TransportException: Cannot publish when mqtt client is disconnected
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.publish(Mqtt.java:193) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttMessaging.send(MqttMessaging.java:129) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.sendMessage(MqttIotHubConnection.java:373) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendPacket(IotHubTransport.java:1639) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendMessages(IotHubTransport.java:789) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubSendTask.run(IotHubSendTask.java:86) [classes/:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2025-06-20 22:26:16,689 DEBUG (MQTT Rec: GXa05-02) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Invoking connection status callbacks with new status details
2025-06-20 22:26:16,690 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Message was queued to be sent later ( Message details: Correlation Id [d87ba090-7a19-4f9e-a054-044734aeab84] Message Id [9e1221f3-ec8a-4ab3-b5a4-7d6301d6a698] Request Id [d87ba090-7a19-4f9e-a054-044734aeab84] Device Operation Type [DEVICE_OPERATION_TWIN_GET_REQUEST] )
2025-06-20 22:26:16,690 WARN (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Handling an exception from sending message: Attempt number 0
com.microsoft.azure.sdk.iot.device.transport.TransportException: Cannot publish when mqtt client is disconnected
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.publish(Mqtt.java:193) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttMessaging.send(MqttMessaging.java:129) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.sendMessage(MqttIotHubConnection.java:373) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendPacket(IotHubTransport.java:1639) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendMessages(IotHubTransport.java:789) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubSendTask.run(IotHubSendTask.java:86) [classes/:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2025-06-20 22:26:16,690 INFO (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Updating transport status to new status CONNECTED with reason CONNECTION_OK
2025-06-20 22:26:16,690 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.RetryDecision] - NOTE: A new instance of RetryDecision has been created with retry enabled, the client will retry after 186 milliseconds
2025-06-20 22:26:16,690 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.DeviceIO] - Starting worker threads
2025-06-20 22:26:16,692 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [d87ba090-7a19-4f9e-a054-044734aeab84] Message Id [9e1221f3-ec8a-4ab3-b5a4-7d6301d6a698] Request Id [d87ba090-7a19-4f9e-a054-044734aeab84] Device Operation Type [DEVICE_OPERATION_TWIN_GET_REQUEST] )
2025-06-20 22:26:16,692 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Invoking connection status callbacks with new status details
2025-06-20 22:26:16,692 WARN (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Encountered exception while sending message with correlation id d87ba090-7a19-4f9e-a054-044734aeab84
com.microsoft.azure.sdk.iot.device.transport.TransportException: Cannot subscribe when mqtt client is disconnected
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.subscribe(Mqtt.java:263) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttTwin.start(MqttTwin.java:66) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.sendMessage(MqttIotHubConnection.java:366) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendPacket(IotHubTransport.java:1639) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendMessages(IotHubTransport.java:789) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubSendTask.run(IotHubSendTask.java:86) [classes/:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2025-06-20 22:26:16,693 WARN (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Handling an exception from sending message: Attempt number 0
com.microsoft.azure.sdk.iot.device.transport.TransportException: Cannot subscribe when mqtt client is disconnected
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.subscribe(Mqtt.java:263) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttTwin.start(MqttTwin.java:66) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.sendMessage(MqttIotHubConnection.java:366) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendPacket(IotHubTransport.java:1639) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendMessages(IotHubTransport.java:789) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubSendTask.run(IotHubSendTask.java:86) [classes/:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2025-06-20 22:26:16,693 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.RetryDecision] - NOTE: A new instance of RetryDecision has been created with retry enabled, the client will retry after 198 milliseconds
2025-06-20 22:26:16,702 DEBUG (XXX-azure-iot-sdk-IotHubReconnectTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubReconnectTask] - Starting reconnection process
2025-06-20 22:26:16,878 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [5ff3f9e9-1223-4bb0-87fe-b848bce37e6f] Message Id [3e4230bf-e074-4df9-b7b2-6cb44569a565] )
2025-06-20 22:26:16,878 WARN (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Encountered exception while sending message with correlation id 5ff3f9e9-1223-4bb0-87fe-b848bce37e6f
com.microsoft.azure.sdk.iot.device.transport.TransportException: Cannot publish when mqtt client is disconnected
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.publish(Mqtt.java:193) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttMessaging.send(MqttMessaging.java:129) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.sendMessage(MqttIotHubConnection.java:373) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendPacket(IotHubTransport.java:1639) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendMessages(IotHubTransport.java:789) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubSendTask.run(IotHubSendTask.java:86) [classes/:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2025-06-20 22:26:16,878 WARN (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Handling an exception from sending message: Attempt number 1
com.microsoft.azure.sdk.iot.device.transport.TransportException: Cannot publish when mqtt client is disconnected
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.publish(Mqtt.java:193) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttMessaging.send(MqttMessaging.java:129) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.sendMessage(MqttIotHubConnection.java:373) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendPacket(IotHubTransport.java:1639) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendMessages(IotHubTransport.java:789) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubSendTask.run(IotHubSendTask.java:86) [classes/:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
2025-06-20 22:26:16,879 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.RetryDecision] - NOTE: A new instance of RetryDecision has been created with retry enabled, the client will retry after 445 milliseconds
2025-06-20 22:26:16,892 DEBUG (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Sending message ( Message details: Correlation Id [d87ba090-7a19-4f9e-a054-044734aeab84] Message Id [9e1221f3-ec8a-4ab3-b5a4-7d6301d6a698] Request Id [d87ba090-7a19-4f9e-a054-044734aeab84] Device Operation Type [DEVICE_OPERATION_TWIN_GET_REQUEST] )
2025-06-20 22:26:16,892 WARN (XXX-azure-iot-sdk-IotHubSendTask) [com.microsoft.azure.sdk.iot.device.transport.IotHubTransport] - Encountered exception while sending message with correlation id d87ba090-7a19-4f9e-a054-044734aeab84
com.microsoft.azure.sdk.iot.device.transport.TransportException: Cannot subscribe when mqtt client is disconnected
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.subscribe(Mqtt.java:263) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttTwin.start(MqttTwin.java:66) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.sendMessage(MqttIotHubConnection.java:366) ~[classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendPacket(IotHubTransport.java:1639) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.sendMessages(IotHubTransport.java:789) [classes/:?]
at com.microsoft.azure.sdk.iot.device.transport.IotHubSendTask.run(IotHubSendTask.java:86) [classes/:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Disconnected from the target VM, address: '127.0.0.1:47785', transport: 'socket'
``