Device Re-connection Issue.

[DurgaPrasadGavara]

OS and version used: Raspbian GNU /Linux 9

Java runtime used: JDK 1.8 (Oracle's)

SDK version used: 1.14.0

Description of the issue: Disconnected retrying is repeated in a loop once IOT hub connection was lost and we are not able to get status of Disconnected. Logic: boolean iotconnection() { try { // client = null;

                  String connString = this.config.connectionstring;

                  IotHubClientProtocol protocol = IotHubClientProtocol.MQTT;
                  client = new DeviceClient(connString, protocol);
                  MessageCallback callback = new AppMessageCallback();
                  Counter counter = new Counter(0);
                  client.setMessageCallback(callback, counter);
                  Iothubconnectionstate iotstatecallback=new Iothubconnectionstate();
                  client.registerConnectionStatusChangeCallback(iotstatecallback, null);    
                  client.open();

                  return true;
                }
                catch (Exception e)
                {
                  println("MethodName:draw()   lineno:" + e.getStackTrace()[2].getLineNumber() + "   " + "info:" + "Error" + "   " + "Threadname:" + Thread.currentThread() + "   " + "description:" + e);
                 this.drawException = e.getMessage();
                }

                return false;
              }

              public class Iothubconnectionstate implements IotHubConnectionStatusChangeCallback{

                              int internetconnectionstatus1=0;
                                            public void execute(IotHubConnectionStatus status,
                                                                            IotHubConnectionStatusChangeReason statusChangeReason, Throwable throwable,
                                                                            Object callbackContext) {
                                                            // TODO Auto-generated method stub
                                                            try{

                                                            iotconnectionstatus=status.toString();
                                                            System.out.println("IotHubConnectionStatus: "+iotconnectionstatus+" ,"+"IotHubConnectionStatusChangeReason: "+statusChangeReason+","+"Throwable:"+convertStackTraceToString(throwable));
                                                            if(iotconnectionstatus.equals("DISCONNECTED")&&statusChangeReason.toString().equals("CLIENT_CLOSE")){
                                                                            try{
                                                                                            System.out.println("Opening the client instance as statusChangReason is CLIENT_CLOSE");
                                                                                            boolean iotconnectionreturn = iotconnection();

                                                                     while (!iotconnectionreturn) {
                                                                       iotconnectionreturn = iotconnection();
                                                                       Thread.sleep(10000);
                                                                     }

                                                                            }
                                                                            catch(Exception e){
                                                                                            println("MethodName:Iothubconnectionstate()   lineno:" + e.getStackTrace()[2].getLineNumber() + "   " + "info:" + "Error" + "   " + "Threadname:" + Thread.currentThread() + "   " + "description:" + e);       
                                                                            }
                                                            }
                                                            else if(iotconnectionstatus.equals("DISCONNECTED")&&statusChangeReason.toString().equals("RETRY_EXPIRED")){
                                                                            System.out.println("Closing the client instance as statusChangReason is RETRY_EXPIRED");
                                                                            client.closeNow();

                                                            }

                                            }
                                                            catch(Exception e){
                                                                            println("MethodName:Iothubconnectionstate()   lineno:" + e.getStackTrace()[2].getLineNumber() + "   " + "info:" + "Error" + "   " + "Threadname:" + Thread.currentThread() + "   " + "description:" + e);

                                                            }}

                              }

In Logs: IotHubConnectionStatus: DISCONNECTED_RETRYING ,IotHubConnectionStatusChangeReason: NO_NETWORK,Throwable:com.microsoft.azure.sdk.iot.device.exceptions.ProtocolException: Mqtt connection lost at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:75) at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:349) at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:292) at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:423) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:181) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: Connection lost (32109) - java.io.EOFException ... 8 more Caused by: java.io.EOFException at java.io.DataInputStream.readByte(DataInputStream.java:267) at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:133) ... 7 more

Else part: DISCONNECTED_RETRYING statusChangeReason: NO_NETWORK IotHubConnectionStatus: CONNECTED ,IotHubConnectionStatusChangeReason: CONNECTION_OK,Throwable:null Else part: CONNECTED statusChangeReason: CONNECTION_OK IotHubConnectionStatus: DISCONNECTED_RETRYING ,IotHubConnectionStatusChangeReason: NO_NETWORK,Throwable:com.microsoft.azure.sdk.iot.device.exceptions.ProtocolException: Mqtt connection lost at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:75) at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:349) at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:292) at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:423) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:181) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: Connection lost (32109) - java.io.EOFException ... 8 more Caused by: java.io.EOFException at java.io.DataInputStream.readByte(DataInputStream.java:267) at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:133) ... 7 more Above messages are repeatedly.

Can you please help me to solve this issue.

[jasmineymlo]

@DurgaPrasadGavara In case of a network disconnect, the Java SDK is supposed to reconnect. DISCONNECTED_RETRYING indicates that the SDK is retrying. While it should retry for by default 4 minute with the default retry policy. Application should only receive the connection status callback when the connection status changes only. From the above log, the device was in DISCONNECTED_RETRYING->CONNECTED -> DISCONNECTED_RETRYING. Are you seeing only DISCONNECTED_RETRYING from this point or is it toggling between CONNECTED and DISCONNECTECD_RETRYING? The DISCONNECTED state should appear in case where the SDK expires 4 min of retrying. Please fill us with more details on the network status for the above scenario. Thanks.

[DurgaPrasadGavara]

Thank you very much for your detailed response.

yes it is toggling between CONNECTED and DISCONNECTECD_RETRYING? The DISCONNECTED state is not appearing in case where the SDK expires 4 min of retrying.

Note: My Device work scenario is My Device is send information based on time interval and that time interval controlled by user by sending message to device using "serviceClient.SendAsync". So that the reason my device is always wake up mode. 1.Even the network was down, we are trying to sending the messages to the iot hub. 2.My device client object is static object and declared in global.

[jasmineymlo]

@DurgaPrasadGavara Please note that if the device is toggling between CONNECTED and DISCONNECTED_RETRYING, the 4 min timer would have reset every time the state is changed to DISCONNECTED_RETRYING, thus it is expected behavior that your device is not getting DISCONNECTED since the 4 min never has expired.

For 1. Application can keep "sending" messages to iothub in case of no network. SDK is not blocking this and will keep all pending messages in a queue to be send. For extended period of network outage, the memory will grow and application could crash when memory on the device is exhausted in this design.

If your test scenario is that the network is unstable and therefore the device is toggling between states. During the very short period of time when the network is connected, the pending message could have send out but whether the ack from iothub is coming back in time would decide if the outgoing message is send successfully or not.

Hope the above explains it well. Let us know if you have any question.

[DurgaPrasadGavara]

For 1. Application can keep "sending" messages to iothub in case of no network. SDK is not blocking this and will keep all pending messages in a queue to be send. For extended period of network outage, the memory will grow and application could crash when memory on the device is exhausted in this design.

we are validating internet connection before sending the message to iot hub, if the network is good and Device status is Connected then we are sending the messages. But still we are getting the below exception.

I am Creating 3 Callbacks.

1. Message call back
2. Event Call back
3. IotHubConnectionStatusChangeCallback in 3 method we receiving the below logs that is getting repeated.

IotHubConnectionStatusChangeCallback Execution Started iotconnectionstatus: CONNECTED IotHubConnectionStatusChangeCallback Execution end IotHubConnectionStatusChangeCallback Execution Started com.microsoft.azure.sdk.iot.device.exceptions.ProtocolException: Mqtt connection lost at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:75) at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:349) at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:292) at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:423) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:181) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: Connection lost (32109) - java.net.SocketException: Connection reset ... 8 more Caused by: java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:209) at java.net.SocketInputStream.read(SocketInputStream.java:141) at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) at sun.security.ssl.InputRecord.read(InputRecord.java:503) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973) at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930) at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) at sun.security.ssl.AppInputStream.read(AppInputStream.java:71) at java.io.DataInputStream.readByte(DataInputStream.java:265) at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:133) ... 7 more

iotconnectionstatus: DISCONNECTED_RETRYING IotHubConnectionStatusChangeCallback Execution IotHubConnectionStatusChangeCallback Execution Started iotconnectionstatus: CONNECTED IotHubConnectionStatusChangeCallback Execution end IotHubConnectionStatusChangeCallback Execution Started com.microsoft.azure.sdk.iot.device.exceptions.ProtocolException: Mqtt connection lost at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:75) at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connectionLost(Mqtt.java:349) at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:292) at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:423) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:181) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: Connection lost (32109) - java.net.SocketException: Connection reset ... 8 more Caused by: java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:209) at java.net.SocketInputStream.read(SocketInputStream.java:141) at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) at sun.security.ssl.InputRecord.read(InputRecord.java:503) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973) at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930) at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) at sun.security.ssl.AppInputStream.read(AppInputStream.java:71) at java.io.DataInputStream.readByte(DataInputStream.java:265) at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:133) ... 7 more

iotconnectionstatus: DISCONNECTED_RETRYING IotHubConnectionStatusChangeCallback Execution end IotHubConnectionStatusChangeCallback Execution Started iotconnectionstatus: CONNECTED IotHubConnectionStatusChangeCallback Execution end IotHubConnectionStatusChangeCallback Execution Started

[jasmineymlo]

@DurgaPrasadGavara I am a little confused here. The device not going to "DISCONNECTED" is expected result. From the above, SDK seems to be continuously attempting to reconnect and able to. But the somehow network get dropped again. Is the subsequent mqtt connection lost not expected? Please let me know what is the scenario and expected result so that I can investigate further. Thanks.

[jasmineymlo]

@DurgaPrasadGavara Please also check if you have multiple devices with the same device id running and trying to connect at the same time which could lead to the above observation due to devices kicking each other out.

[jasmineymlo]

I'm going to close this issue now due to inactivity. Feel free to re-open if you have any other questions on how reconnection works in this SDK.

[az-iot-builder-01]

@DurgaPrasadGavara, thank you for your contribution to our open-sourced project! Please help us improve by filling out this 2-minute customer satisfaction survey