Skip to main content
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [paho-dev] Client hangs forever if trying to shut down when connection to broker is lost.
Hi,

I am experiencing the exact same behavior with a synchronous sending client with auto reconnect enabled.

My client close logic is just:
client.disconnect()
client.close()

I enabled debug in the client and it shows that paho threads are continuously reconnecting and not shutting down despite the close being called. See paho client debug trace below:

So +1 on getting some help from the community with this,
M

Paho client debug trace after close called:

FINE     17-07-14  15:18:34.0464        nternal.CommsSender      stop                           121     mqtt_client_id_pub: stopping sender
FINE     17-07-14  15:18:34.0464        nternal.ClientState      notifyQueueLock                121     mqtt_client_id_pub: notifying queueLock holders
FINE     17-07-14  15:18:34.0464        nternal.ClientState      get                            122     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:34.0465        nternal.ClientState      get                            122     mqtt_client_id_pub: no outstanding flows and not connected
FINE     17-07-14  15:18:34.0465        nternal.CommsSender      run                            122     mqtt_client_id_pub: get message returned null, stopping}
FINE     17-07-14  15:18:34.0465        nternal.CommsSender      run                            122     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0465        nternal.CommsSender      stop                           121     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0465        tv3.TimerPingSender      stop                           121     null: stop
FINE     17-07-14  15:18:34.0465        nternal.ClientComms      shutdownConnection             121     mqtt_client_id_pub: state=DISCONNECTED
FINE     17-07-14  15:18:34.0465        ernal.CommsCallback      connectionLost                 121     mqtt_client_id_pub: call connectionLost
FINE     17-07-14  15:18:34.0467        tv3.MqttAsyncClient      startReconnectCycle            121     mqtt_client_id_pub: Start reconnect timer for client: mqtt_client_id_pub, delay: 1,000
FINE     17-07-14  15:18:34.0467        nternal.ClientState      send                           121     mqtt_client_id_pub: pending send key=1 message PUBREL msgId 1
FINE     17-07-14  15:18:34.0467        ernal.CommsReceiver      run                            121     mqtt_client_id_pub: Stopping, MQttException
Throwable occurred: Client is currently disconnecting (32102)
        at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:350)
        at org.eclipse.paho.client.mqttv3.internal.CommsCallback.asyncOperationReachedIntermediateStage(CommsCallback.java:429)
        at org.eclipse.paho.client.mqttv3.internal.ClientState.notifyIntermediaryResult(ClientState.java:1113)
        at org.eclipse.paho.client.mqttv3.internal.ClientState.notifyReceivedAck(ClientState.java:941)
        at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:128)
        at java.lang.Thread.run(Thread.java:745)
FINE     17-07-14  15:18:34.0467        nternal.ClientComms      shutdownConnection             121     mqtt_client_id_pub: state=DISCONNECTING
FINE     17-07-14  15:18:34.0467        ernal.CommsCallback      stop                           121     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0467        ernal.CommsReceiver      stop                           121     mqtt_client_id_pub: stopping
FINE     17-07-14  15:18:34.0467        ernal.CommsReceiver      stop                           121     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0468        nal.CommsTokenStore      quiesce                        121     mqtt_client_id_pub: resp=Client is currently disconnecting (32102)
FINE     17-07-14  15:18:34.0468        nternal.ClientComms      handleOldTokens                121     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0468        nternal.ClientState      resolveOldTokens               121     mqtt_client_id_pub: reason Client is currently disconnecting (32102)
FINE     17-07-14  15:18:34.0468        nal.CommsTokenStore      getOutstandingTokens           121     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0468        ernal.CommsCallback      handleActionComplete           121     mqtt_client_id_pub: callback and notify for key=1
FINE     17-07-14  15:18:34.0468        ttv3.internal.Token      notifyComplete                 121     mqtt_client_id_pub: >key=1 response=null excep=Client is currently disconnecting (32102)
FINE     17-07-14  15:18:34.0468        nternal.ClientState      disconnected                   121     mqtt_client_id_pub: disconnected
FINE     17-07-14  15:18:34.0468        nternal.CommsSender      stop                           121     mqtt_client_id_pub: stopping sender
FINE     17-07-14  15:18:34.0468        nternal.CommsSender      stop                           121     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0468        tv3.TimerPingSender      stop                           121     null: stop
FINE     17-07-14  15:18:34.0468        nternal.ClientComms      shutdownConnection             121     mqtt_client_id_pub: state=DISCONNECTED
FINE     17-07-14  15:18:34.0468        ernal.CommsReceiver      run                            121     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0472        tv3.MqttAsyncClient      disconnect                     97      mqtt_client_id_pub: > quiesceTimeout=30,000 userContext=null callback=null
FINE     17-07-14  15:18:34.0472        nternal.ClientComms      disconnect                     97      mqtt_client_id_pub: failed: already disconnected
FINE     17-07-14  15:18:34.0472        tv3.MqttAsyncClient      disconnect                     97      mqtt_client_id_pub: < exception
Throwable occurred: Client is disconnected (32101)
        at org.eclipse.paho.client.mqttv3.internal.ExceptionHelper.createMqttException(ExceptionHelper.java:31)
        at org.eclipse.paho.client.mqttv3.internal.ClientComms.disconnect(ClientComms.java:467)
        at org.eclipse.paho.client.mqttv3.MqttAsyncClient.disconnect(MqttAsyncClient.java:705)
        at org.eclipse.paho.client.mqttv3.MqttAsyncClient.disconnect(MqttAsyncClient.java:674)
        at org.eclipse.paho.client.mqttv3.MqttAsyncClient.disconnect(MqttAsyncClient.java:681)
        at org.eclipse.paho.client.mqttv3.MqttClient.disconnect(MqttClient.java:258)
        at com.intech.volt.flink.mqtt.PooledMQTTClientFactory.destroyObject(MQTTClientFactory.scala:154)
        at org.apache.commons.pool2.impl.GenericObjectPool.destroy(GenericObjectPool.java:897)
        at org.apache.commons.pool2.impl.GenericObjectPool.clear(GenericObjectPool.java:675)
        at org.apache.commons.pool2.impl.GenericObjectPool.close(GenericObjectPool.java:718)
        at com.intech.volt.flink.mqtt.MQTTSink.close(MQTTSink.scala:93)
        at org.apache.flink.api.common.functions.util.FunctionUtils.closeFunction(FunctionUtils.java:43)
        at org.apache.flink.streaming.api.operators.AbstractUdfStreamOperator.dispose(AbstractUdfStreamOperator.java:127)
        at org.apache.flink.streaming.runtime.tasks.StreamTask.disposeAllOperators(StreamTask.java:431)
        at org.apache.flink.streaming.runtime.tasks.StreamTask.invoke(StreamTask.java:332)
        at org.apache.flink.runtime.taskmanager.Task.run(Task.java:665)
        at java.lang.Thread.run(Thread.java:745)
FINE     17-07-14  15:18:34.0500        tv3.MqttAsyncClient      disconnect                     145     mqtt_client_id_pub: > quiesceTimeout=30,000 userContext=null callback=null
FINE     17-07-14  15:18:34.0500        nternal.ClientComms      disconnect                     145     mqtt_client_id_pub: state=DISCONNECTING
FINE     17-07-14  15:18:34.0501        tv3.MqttAsyncClient      disconnect                     145     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0502        nternal.ClientComms      disconnectBG:run               148     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0502        nternal.ClientState      quiesce                        148     mqtt_client_id_pub: timeout=30,000
FINE     17-07-14  15:18:34.0502        ernal.CommsCallback      quiesce                        148     mqtt_client_id_pub: quiesce notify spaceAvailable
FINE     17-07-14  15:18:34.0502        nternal.ClientState      notifyQueueLock                148     mqtt_client_id_pub: notifying queueLock holders
FINE     17-07-14  15:18:34.0503        nternal.ClientState      get                            118     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:34.0503        nternal.ClientState      quiesce                        148     mqtt_client_id_pub: finished
FINE     17-07-14  15:18:34.0503        nternal.ClientComms      internalSend                   148     mqtt_client_id_pub: 200
FINE     17-07-14  15:18:34.0503        tv3.MqttAsyncClient      disconnect                     147     mqtt_client_id_pub: > quiesceTimeout=30,000 userContext=null callback=null
FINE     17-07-14  15:18:34.0503        nternal.ClientComms      disconnect                     147     mqtt_client_id_pub: state=DISCONNECTING
FINE     17-07-14  15:18:34.0503        nternal.ClientState      get                            118     mqtt_client_id_pub: wait for new work or for space in the inflight window
FINE     17-07-14  15:18:34.0503        nternal.ClientState      send                           148     mqtt_client_id_pub: pending send key=0 message DISCONNECT
FINE     17-07-14  15:18:34.0504        nal.CommsTokenStore      saveToken                      148     mqtt_client_id_pub: key=Disc message=DISCONNECT
FINE     17-07-14  15:18:34.0504        tv3.MqttAsyncClient      disconnect                     147     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0505        nal.CommsTokenStore      saveToken                      148     mqtt_client_id_pub: key=Disc token=org.eclipse.paho.client.mqttv3.MqttToken@7ae63d87
FINE     17-07-14  15:18:34.0505        nternal.ClientState      get                            118     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:34.0505        nternal.CommsSender      run                            118     mqtt_client_id_pub: network send key=Disc msg=DISCONNECT
FINE     17-07-14  15:18:34.0506        nternal.ClientState      notifySentBytes                118     mqtt_client_id_pub: sent bytes count=2
FINE     17-07-14  15:18:34.0505        nternal.ClientComms      disconnectBG:run               151     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0506        nternal.ClientState      quiesce                        151     mqtt_client_id_pub: timeout=30,000
FINE     17-07-14  15:18:34.0506        ernal.CommsCallback      quiesce                        151     mqtt_client_id_pub: quiesce notify spaceAvailable
FINE     17-07-14  15:18:34.0506        nternal.ClientState      notifyQueueLock                151     mqtt_client_id_pub: notifying queueLock holders
FINE     17-07-14  15:18:34.0506        re.MqttOutputStream      write                          118     null: Attempting to reconnect client: DISCONNECT
FINE     17-07-14  15:18:34.0506        nternal.ClientState      notifySent                     118     mqtt_client_id_pub: key=Disc
FINE     17-07-14  15:18:34.0507        nternal.ClientState      get                            118     mqtt_client_id_pub: wait for new work or for space in the inflight window
FINE     17-07-14  15:18:34.0507        nternal.ClientComms      shutdownConnection             148     mqtt_client_id_pub: state=DISCONNECTING
FINE     17-07-14  15:18:34.0507        ernal.CommsCallback      stop                           148     mqtt_client_id_pub: stopping
FINE     17-07-14  15:18:34.0507        ernal.CommsCallback      stop                           148     mqtt_client_id_pub: notify workAvailable and wait for run
FINE     17-07-14  15:18:34.0507        nternal.ClientState      quiesce                        151     mqtt_client_id_pub: finished
FINE     17-07-14  15:18:34.0507        nternal.ClientComms      internalSend                   151     mqtt_client_id_pub: 200
FINE     17-07-14  15:18:34.0508        nternal.ClientState      send                           151     mqtt_client_id_pub: pending send key=0 message DISCONNECT
FINE     17-07-14  15:18:34.0508        nal.CommsTokenStore      saveToken                      151     mqtt_client_id_pub: key=Disc message=DISCONNECT
FINE     17-07-14  15:18:34.0508        nal.CommsTokenStore      saveToken                      151     mqtt_client_id_pub: key=Disc token=org.eclipse.paho.client.mqttv3.MqttToken@246ebdd5
FINE     17-07-14  15:18:34.0508        ernal.CommsCallback      run                            119     mqtt_client_id_pub: notify spaceAvailable
FINE     17-07-14  15:18:34.0508        nternal.ClientState      get                            115     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:34.0508        ernal.CommsCallback      stop                           148     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0508        ernal.CommsReceiver      stop                           148     mqtt_client_id_pub: stopping
FINE     17-07-14  15:18:34.0508        nternal.CommsSender      run                            115     mqtt_client_id_pub: network send key=Disc msg=DISCONNECT
FINE     17-07-14  15:18:34.0510        nternal.ClientState      notifySentBytes                115     mqtt_client_id_pub: sent bytes count=2
FINE     17-07-14  15:18:34.0509        ernal.CommsReceiver      run                            117     mqtt_client_id_pub: Stopping due to IOException
FINE     17-07-14  15:18:34.0510        ernal.CommsReceiver      run                            117     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0510        re.MqttOutputStream      write                          115     null: Attempting to reconnect client: DISCONNECT
FINE     17-07-14  15:18:34.0510        nternal.ClientState      notifySent                     115     mqtt_client_id_pub: key=Disc
FINE     17-07-14  15:18:34.0510        nternal.ClientState      get                            115     mqtt_client_id_pub: wait for new work or for space in the inflight window
FINE     17-07-14  15:18:34.0510        ernal.CommsReceiver      stop                           148     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0511        nternal.ClientComms      shutdownConnection             151     mqtt_client_id_pub: state=DISCONNECTING
FINE     17-07-14  15:18:34.0511        ernal.CommsReceiver      run                            114     mqtt_client_id_pub: Stopping due to IOException
FINE     17-07-14  15:18:34.0511        ernal.CommsCallback      stop                           151     mqtt_client_id_pub: stopping
FINE     17-07-14  15:18:34.0512        ernal.CommsCallback      stop                           151     mqtt_client_id_pub: notify workAvailable and wait for run
FINE     17-07-14  15:18:34.0512        nal.CommsTokenStore      quiesce                        148     mqtt_client_id_pub: resp=Client is currently disconnecting (32102)
FINE     17-07-14  15:18:34.0513        nternal.ClientComms      handleOldTokens                148     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0513        nternal.ClientState      resolveOldTokens               148     mqtt_client_id_pub: reason null
FINE     17-07-14  15:18:34.0513        nal.CommsTokenStore      getOutstandingTokens           148     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0513        nal.CommsTokenStore      removeToken                    148     mqtt_client_id_pub: key=Disc
FINE     17-07-14  15:18:34.0513        nternal.ClientState      disconnected                   148     mqtt_client_id_pub: disconnected
FINE     17-07-14  15:18:34.0513        nternal.CommsSender      stop                           148     mqtt_client_id_pub: stopping sender
FINE     17-07-14  15:18:34.0513        nternal.ClientState      notifyQueueLock                148     mqtt_client_id_pub: notifying queueLock holders
FINE     17-07-14  15:18:34.0511        ernal.CommsReceiver      run                            114     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0513        ernal.CommsCallback      run                            116     mqtt_client_id_pub: notify spaceAvailable
FINE     17-07-14  15:18:34.0514        nternal.ClientState      get                            118     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:34.0514        nternal.ClientState      get                            118     mqtt_client_id_pub: no outstanding flows and not connected
FINE     17-07-14  15:18:34.0514        nternal.CommsSender      run                            118     mqtt_client_id_pub: get message returned null, stopping}
FINE     17-07-14  15:18:34.0514        nternal.CommsSender      run                            118     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0514        ernal.CommsCallback      stop                           151     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0515        ernal.CommsReceiver      stop                           151     mqtt_client_id_pub: stopping
FINE     17-07-14  15:18:34.0515        ernal.CommsReceiver      stop                           151     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0515        nternal.CommsSender      stop                           148     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0515        tv3.TimerPingSender      stop                           148     null: stop
FINE     17-07-14  15:18:34.0515        nal.CommsTokenStore      quiesce                        151     mqtt_client_id_pub: resp=Client is currently disconnecting (32102)
FINE     17-07-14  15:18:34.0515        nternal.ClientComms      handleOldTokens                151     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0516        nternal.ClientState      resolveOldTokens               151     mqtt_client_id_pub: reason null
FINE     17-07-14  15:18:34.0516        nal.CommsTokenStore      getOutstandingTokens           151     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0516        nal.CommsTokenStore      removeToken                    151     mqtt_client_id_pub: key=Disc
FINE     17-07-14  15:18:34.0517        nternal.ClientState      disconnected                   151     mqtt_client_id_pub: disconnected
FINE     17-07-14  15:18:34.0517        nternal.ClientComms      shutdownConnection             148     mqtt_client_id_pub: state=DISCONNECTED
FINE     17-07-14  15:18:34.0517        nternal.CommsSender      stop                           151     mqtt_client_id_pub: stopping sender
FINE     17-07-14  15:18:34.0517        ernal.CommsCallback      handleActionComplete           148     mqtt_client_id_pub: callback and notify for key=Disc
FINE     17-07-14  15:18:34.0517        nternal.ClientState      notifyQueueLock                151     mqtt_client_id_pub: notifying queueLock holders
FINE     17-07-14  15:18:34.0518        tv3.MqttAsyncClient      close                          145     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0518        nternal.ClientState      get                            115     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:34.0518        nternal.ClientState      get                            115     mqtt_client_id_pub: no outstanding flows and not connected
FINE     17-07-14  15:18:34.0518        nternal.CommsSender      run                            115     mqtt_client_id_pub: get message returned null, stopping}
FINE     17-07-14  15:18:34.0518        nternal.CommsSender      run                            115     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0519        nal.CommsTokenStore      clear                          145     mqtt_client_id_pub: > 0 tokens
FINE     17-07-14  15:18:34.0519        tv3.MqttAsyncClient      close                          145     mqtt_client_id_pub: >
FINE     17-07-14  15:18:34.0519        nternal.CommsSender      stop                           151     mqtt_client_id_pub: stopped
FINE     17-07-14  15:18:34.0519        tv3.TimerPingSender      stop                           151     null: stop
FINE     17-07-14  15:18:34.0520        nternal.ClientComms      shutdownConnection             151     mqtt_client_id_pub: state=DISCONNECTED
FINE     17-07-14  15:18:34.0520        ernal.CommsCallback      handleActionComplete           151     mqtt_client_id_pub: callback and notify for key=Disc
FINE     17-07-14  15:18:34.0521        tv3.MqttAsyncClient      close                          147     mqtt_client_id_pub: <
FINE     17-07-14  15:18:34.0521        nal.CommsTokenStore      clear                          147     mqtt_client_id_pub: > 0 tokens
FINE     17-07-14  15:18:34.0522        tv3.MqttAsyncClient      close                          147     mqtt_client_id_pub: >
FINE     17-07-14  15:18:35.0163        ernal.CommsReceiver      run                            57      mqtt_client_id_pub: network read message
FINE     17-07-14  15:18:35.0179        ernal.CommsReceiver      run                            46      mqtt_client_id_pub: network read message
FINE     17-07-14  15:18:35.0335        ernal.CommsReceiver      run                            51      mqtt_client_id_pub: network read message
FINE     17-07-14  15:18:35.0471        tv3.MqttAsyncClient      ReconnectTask.run              142     mqtt_client_id_pub: Triggering Automatic Reconnect attempt.
FINE     17-07-14  15:18:35.0471        tv3.MqttAsyncClient      attemptReconnect               142     mqtt_client_id_pub: Attempting to reconnect client: mqtt_client_id_pub
FINE     17-07-14  15:18:35.0472        tv3.MqttAsyncClient      connect                        142     mqtt_client_id_pub: cleanSession=false connectionTimeout=30 TimekeepAlive=60 userName=null password=[null] will=[null] userContext=null callback=org.eclipse.paho.client.mqttv3.MqttAsyncClient$2@32965fe1
FINE     17-07-14  15:18:35.0472        tv3.MqttAsyncClient      createNetworkModules           142     mqtt_client_id_pub: URI=tcp://localhost:1883
FINE     17-07-14  15:18:35.0472        tv3.MqttAsyncClient      createNetworkModule            142     mqtt_client_id_pub: URI=tcp://localhost:1883
FINE     17-07-14  15:18:35.0472        tv3.MqttAsyncClient      createNetworkModules           142     mqtt_client_id_pub: <
FINE     17-07-14  15:18:35.0472        nternal.ClientComms      connect                        142     mqtt_client_id_pub: state=CONNECTING
FINE     17-07-14  15:18:35.0472        nal.CommsTokenStore      open                           142     mqtt_client_id_pub: >
FINE     17-07-14  15:18:35.0473        nternal.ClientComms      connectBG:run                  169     mqtt_client_id_pub: >
FINE     17-07-14  15:18:35.0473        nal.CommsTokenStore      getOutstandingDelTokens        169     mqtt_client_id_pub: >
FINE     17-07-14  15:18:35.0473        nal.CommsTokenStore      saveToken                      169     mqtt_client_id_pub: key=Con message=CONNECT clientId mqtt_client_id_pub keepAliveInterval 60
FINE     17-07-14  15:18:35.0473        nal.CommsTokenStore      saveToken                      169     mqtt_client_id_pub: key=Con token=org.eclipse.paho.client.mqttv3.MqttToken@6f5053b2
FINE     17-07-14  15:18:35.0473        al.TCPNetworkModule      start                          169     mqtt_client_id_pub: connect to host localhost port 1,883 timeout 30,000
FINE     17-07-14  15:18:35.0474        ernal.CommsReceiver      start                          169     mqtt_client_id_pub: starting
FINE     17-07-14  15:18:35.0474        ernal.CommsReceiver      run                            170     mqtt_client_id_pub: network read message
FINE     17-07-14  15:18:35.0474        nternal.ClientState      get                            171     mqtt_client_id_pub: wait for new work or for space in the inflight window
FINE     17-07-14  15:18:35.0475        nternal.ClientComms      internalSend                   169     mqtt_client_id_pub: 200
FINE     17-07-14  15:18:35.0475        ernal.CommsCallback      run                            172     mqtt_client_id_pub: wait for workAvailable
FINE     17-07-14  15:18:35.0475        nternal.ClientState      send                           169     mqtt_client_id_pub: pending send key=0 message CONNECT clientId mqtt_client_id_pub keepAliveInterval 60
FINE     17-07-14  15:18:35.0475        nal.CommsTokenStore      saveToken                      169     mqtt_client_id_pub: key=Con message=CONNECT clientId mqtt_client_id_pub keepAliveInterval 60
FINE     17-07-14  15:18:35.0475        nal.CommsTokenStore      saveToken                      169     mqtt_client_id_pub: key=Con token=org.eclipse.paho.client.mqttv3.MqttToken@6f5053b2
FINE     17-07-14  15:18:35.0475        nternal.ClientState      get                            171     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:35.0475        nternal.CommsSender      run                            171     mqtt_client_id_pub: network send key=Con msg=CONNECT clientId mqtt_client_id_pub keepAliveInterval 60
FINE     17-07-14  15:18:35.0475        nternal.ClientState      notifySentBytes                171     mqtt_client_id_pub: sent bytes count=12
FINE     17-07-14  15:18:35.0475        nternal.ClientState      notifySentBytes                171     mqtt_client_id_pub: sent bytes count=47
FINE     17-07-14  15:18:35.0475        re.MqttOutputStream      write                          171     null: Attempting to reconnect client: CONNECT clientId mqtt_client_id_pub keepAliveInterval 60
FINE     17-07-14  15:18:35.0475        nternal.ClientState      notifySent                     171     mqtt_client_id_pub: key=Con
FINE     17-07-14  15:18:35.0476        ttv3.internal.Token      notifySent                     171     mqtt_client_id_pub: > key=Con
FINE     17-07-14  15:18:35.0476        nternal.ClientState      get                            171     mqtt_client_id_pub: wait for new work or for space in the inflight window
FINE     17-07-14  15:18:35.0476        nternal.ClientState      notifyReceivedBytes            170     mqtt_client_id_pub: received bytes count=1
FINE     17-07-14  15:18:35.0476        nternal.ClientState      notifyReceivedBytes            170     mqtt_client_id_pub: received bytes count=2
FINE     17-07-14  15:18:35.0476        ire.MqttInputStream      readMqttWireMessage            170     null: Automatic Reconnect Successful: CONNACK msgId 0 session present:true return code: 0
FINE     17-07-14  15:18:35.0477        nternal.ClientState      notifyReceivedAck              170     mqtt_client_id_pub: received key=0 message=CONNACK msgId 0 session present:true return code: 0
FINE     17-07-14  15:18:35.0477        nternal.ClientState      restoreInflightMessages        170     mqtt_client_id_pub: QoS 2 pubrel key=1
FINE     17-07-14  15:18:35.0477        nternal.ClientState      connected                      170     mqtt_client_id_pub: connected
FINE     17-07-14  15:18:35.0477        tv3.TimerPingSender      start                          170     null: start timer for client:mqtt_client_id_pub
FINE     17-07-14  15:18:35.0477        nternal.ClientComms      connectComplete                170     mqtt_client_id_pub: state=CONNECTED
FINE     17-07-14  15:18:35.0477        ttv3.internal.Token      markComplete                   170     mqtt_client_id_pub: >key=Con response=CONNACK msgId 0 session present:true return code: 0 excep=null
FINE     17-07-14  15:18:35.0477        ttv3.internal.Token      notifyComplete                 170     mqtt_client_id_pub: >key=Con response=CONNACK msgId 0 session present:true return code: 0 excep=null
FINE     17-07-14  15:18:35.0477        nternal.ClientState      notifyResult                   170     mqtt_client_id_pub: keyCon, msg=CONNACK msgId 0 session present:true return code: 0, excep=null
FINE     17-07-14  15:18:35.0477        ernal.CommsCallback      asyncOperationComplete         170     mqtt_client_id_pub: new workAvailable. key=Con
FINE     17-07-14  15:18:35.0478        nal.CommsTokenStore      removeToken                    170     mqtt_client_id_pub: key=Con
FINE     17-07-14  15:18:35.0478        ernal.CommsReceiver      run                            170     mqtt_client_id_pub: network read message
FINE     17-07-14  15:18:35.0478        nternal.ClientState      get                            171     mqtt_client_id_pub: new work or ping arrived
FINE     17-07-14  15:18:35.0478        ernal.CommsCallback      handleActionComplete           172     mqtt_client_id_pub: callback and notify for key=Con
FINE     17-07-14  15:18:35.0478        nternal.ClientState      get                            171     mqtt_client_id_pub: +1 inflightpubrels=1
FINE     17-07-14  15:18:35.0478        nternal.ClientState      notifyComplete                 172     mqtt_client_id_pub: received key=0 token=org.eclipse.paho.client.mqttv3.MqttToken@6f5053b2 message=CONNACK msgId 0 session present:true return code: 0
FINE     17-07-14  15:18:35.0478        ttv3.internal.Token      notifyComplete                 172     mqtt_client_id_pub: >key=Con response=CONNACK msgId 0 session present:true return code: 0 excep=null
FINE     17-07-14  15:18:35.0478        nternal.CommsSender      run                            171     mqtt_client_id_pub: network send key=1 msg=PUBREL msgId 1
FINE     17-07-14  15:18:35.0478        nternal.ClientState      notifySentBytes                171     mqtt_client_id_pub: sent bytes count=4
FINE     17-07-14  15:18:35.0478        ernal.CommsCallback      fireActionEvent                172     mqtt_client_id_pub: call onSuccess key=Con
FINE     17-07-14  15:18:35.0478        re.MqttOutputStream      write                          171     null: Attempting to reconnect client: PUBREL msgId 1
FINE     17-07-14  15:18:35.0479        nternal.ClientState      notifySent                     171     mqtt_client_id_pub: key=1
FINE     17-07-14  15:18:35.0479        ttv3.internal.Token      notifySent                     171     mqtt_client_id_pub: > key=1
FINE     17-07-14  15:18:35.0479        nternal.ClientState      get                            171     mqtt_client_id_pub: wait for new work or for space in the inflight window
FINE     17-07-14  15:18:35.0479        ttv3.internal.Token      markComplete                   172     mqtt_client_id_pub: >key=null response=CONNACK msgId 0 session present:true return code: 0 excep=null
FINE     17-07-14  15:18:35.0479        ttv3.internal.Token      notifyComplete                 172     mqtt_client_id_pub: >key=null response=CONNACK msgId 0 session present:true return code: 0 excep=null
FINE     17-07-14  15:18:35.0479        tv3.MqttAsyncClient      attemptReconnect               172     mqtt_client_id_pub: Automatic Reconnect Successful: mqtt_client_id_pub
FINE     17-07-14  15:18:35.0480        tv3.MqttAsyncClient      stopReconnectCycle             172     mqtt_client_id_pub: Stop reconnect timer for client: mqtt_client_id_pub
FINE     17-07-14  15:18:35.0480        ernal.CommsCallback      run                            172     mqtt_client_id_pub: notify spaceAvailable
FINE     17-07-14  15:18:35.0480        ernal.CommsCallback      run                            172     mqtt_client_id_pub: wait for workAvailable
FINE     17-07-14  15:18:35.0480        nternal.ClientState      notifyReceivedBytes            170     mqtt_client_id_pub: received bytes count=1
FINE     17-07-14  15:18:35.0481        nternal.ClientState      notifyReceivedBytes            170     mqtt_client_id_pub: received bytes count=2
FINE     17-07-14  15:18:35.0481        ire.MqttInputStream      readMqttWireMessage            170     null: Automatic Reconnect Successful: PUBCOMP msgId 1
FINE     17-07-14  15:18:35.0481        nternal.ClientState      notifyReceivedBytes            57      mqtt_client_id_pub: received bytes count=1
FINE     17-07-14  15:18:35.0481        nternal.ClientState      notifyReceivedAck              170     mqtt_client_id_pub: received key=1 message=PUBCOMP msgId 1
FINE     17-07-14  15:18:35.0481        nternal.ClientState      notifyReceivedBytes            57      mqtt_client_id_pub: received bytes count=65
FINE     17-07-14  15:18:35.0481        ttv3.internal.Token      markComplete                   170     mqtt_client_id_pub: >key=1 response=PUBCOMP msgId 1 excep=null

On Tue, Jul 18, 2017 at 7:24 AM, <nidhi.kushwaha@xxxxxxxxxxx> wrote:

Hi

 

I am using Paho(Java client) in auto re-connect mode. I am unable to properly shut down the client when connection to broker is lost.

Client hangs forever and java application does not terminate.

 

Code snippet -

private void runClient() throws MqttException, InterruptedException {

       ………… …………. …………. ………….

       ………… …………. …………. ………….

 

        // Connect to Broker

        final IMqttToken connect = gcdClient.connect( connOpt );

        connect.waitForCompletion();

 

        Thread.sleep( 10_000 );

        // SCENARIO - If connection to broker is lost at this point. May be broker is down or other reason.

 

        // Trying to shutdown the connection

        log.info( "Trying to shutdown the client" );

        try {

            gcdClient.disconnect().waitForCompletion();

        } catch ( MqttException ex ) {

            log.error( "Exception while disconnecting", ex );

        } finally {

            log.info( "Close the client" );

            gcdClient.close();

        }

 

    }

 

Attaching the java file. Here is the stack trace –

 

11:50:29.459 [main] INFO TestMqtt - Connecting to MQTT Broker

11:50:29.489 [MQTT Call: clientID123] INFO TestMqtt - connectComplete - MQTT Publisher connected to MQTT Broker : tcp://localhost:1883  reconnect=false

11:50:30.989 [MQTT Rec: clientID123] ERROR TestMqtt - connectionLost - MQTT Publisher disconnected from MQTT Broker

11:50:39.498 [main] INFO TestMqtt - Trying to shutdown the client

11:50:39.498 [main] ERROR TestMqtt - Exception while disconnecting

org.eclipse.paho.client.mqttv3.MqttException: Client is disconnected

               at org.eclipse.paho.client.mqttv3.internal.ExceptionHelper.createMqttException(ExceptionHelper.java:31)

               at org.eclipse.paho.client.mqttv3.internal.ClientComms.disconnect(ClientComms.java:451)

               at org.eclipse.paho.client.mqttv3.MqttAsyncClient.disconnect(MqttAsyncClient.java:632)

               at org.eclipse.paho.client.mqttv3.MqttAsyncClient.disconnect(MqttAsyncClient.java:601)

               at org.eclipse.paho.client.mqttv3.MqttAsyncClient.disconnect(MqttAsyncClient.java:608)

               at TestMqtt.runClient(TestMqtt.java:47)

               at TestMqtt.main(TestMqtt.java:22)

11:50:39.498 [main] INFO TestMqtt - Close the client


If you are not the addressee, please inform us immediately that you have received this e-mail by mistake, and delete it. We thank you for your support.

_______________________________________________
paho-dev mailing list
paho-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/paho-dev

Back to the top