[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