Mqtt broker cannot authenticate for the second time

[wzqallz]

hi,
mqtt broker Run with Docker.
I use esp8266 to connect to the mqtt broker. The mqtt client id uses the esp8266 mac address. The first time the connection was normal, when I disconnected the mqtt connection, I could not connect when I connected again. See docker logs information as shown below:

0|broker | BROKER(22) INFO: broker has been started on port: 1883 --- 2018-05-14T07:17:31.570Z
0|broker | CrossBrokerCommunicator > service.online CrossBrokerCommunicator#eebbf8cb-4ad7-4afa-87cd-4d0fe3b9e89e
0|broker | BROKER(22) DEBUG: client with id: "5CCF7FCCE3E1" has been authenticated --- 2018-05-14T07:18:31.376Z
0|broker | BROKER(22) INFO: client with id: "5CCF7FCCE3E1" connected --- 2018-05-14T07:18:31.396Z
0|broker | BROKER(22) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/command/2/9/5CCF7FCCE3E1/#" --- 2018-05-14T07:18:32.115Z
0|broker | BROKER(22) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-14T07:20:18.572Z
0|broker | BROKER(22) INFO: client with id: "5CCF7FCCE3E1" disconnected --- 2018-05-14T07:20:18.582Z
0|broker | BROKER(22) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-14T07:20:18.596Z
0|broker | BROKER(22) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T07:21:30.602Z
0|broker | BROKER(22) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T07:21:36.615Z
0|broker | BROKER(22) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T07:21:42.605Z
0|broker | BROKER(22) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T07:21:48.600Z

Is this because the websocket is not disconnected? But I see there are disconnected websocket in the source code。

server.on(clientDisconnected, (client) => {
wsManager.close(client.id);
appLogger.info(client with id: "${client.id}" disconnected);
});

How do I fix this problem？
thank you

[itrambovetskyi]

Hello
Could you please add DEBUG: "websocketmanager" to environmental variables and then repeat your actions. It will enable logging for the WebSocket Manager module and will give us more information about the problem.

Thanks,
Ihor T.

[wzqallz]

hello，
When I add DEBUG: "websocketmanager" to environmental variables，Log information is as follows：

0|broker | BROKER(23) INFO: broker has been started on port: 1883 --- 2018-05-14T08:44:40.644Z
0|broker | CrossBrokerCommunicator > service.online CrossBrokerCommunicator#90f74c60-9a89-4b2b-9e19-d4c9543b550a
0|broker | 2018-05-14T08:48:47.115Z websocketmanager createTokens: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.117Z websocketmanager send: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.118Z websocketmanager _lock: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.430Z websocketmanager _unlock: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.432Z websocketmanager authenticate: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.432Z websocketmanager send: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.432Z websocketmanager _lock: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.432Z websocketfactory getSocket: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.472Z websocketmanager setAuthorized: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.474Z websocketmanager _unlock: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.474Z websocketmanager setAuthorized: 5CCF7FCCE3E1
0|broker | BROKER(23) DEBUG: client with id: "5CCF7FCCE3E1" has been authenticated --- 2018-05-14T08:48:47.478Z
0|broker | BROKER(23) INFO: client with id: "5CCF7FCCE3E1" connected --- 2018-05-14T08:48:47.492Z
0|broker | 2018-05-14T08:48:47.577Z websocketmanager send: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.577Z websocketmanager _lock: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.578Z websocketfactory getSocket: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.578Z subscriptionmanager addSubscriptionAttempt: dh/command/2/9/5CCF7FCCE3E1/# 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.626Z websocketmanager _unlock: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:48:47.645Z subscriptionmanager addSubjectSubscriber: dh/command/2/9/5CCF7FCCE3E1/# 5CCF7FCCE3E1, 1526287727587111
0|broker | BROKER(23) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/command/2/9/5CCF7FCCE3E1/#" --- 2018-05-14T08:48:47.647Z
0|broker | BROKER(23) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-14T08:50:03.033Z
0|broker | 2018-05-14T08:50:03.039Z websocketmanager close: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:50:03.040Z websocketmanager removeAuthorized: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:50:03.040Z websocketfactory removeSocket: 5CCF7FCCE3E1
0|broker | BROKER(23) INFO: client with id: "5CCF7FCCE3E1" disconnected --- 2018-05-14T08:50:03.043Z
0|broker | 2018-05-14T08:50:03.053Z websocketmanager sendString: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:50:03.053Z websocketmanager _lock: 5CCF7FCCE3E1
0|broker | BROKER(23) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-14T08:50:03.060Z
0|broker | 2018-05-14T08:50:03.087Z websocketmanager _unlock: 5CCF7FCCE3E1
0|broker | BROKER(23) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T08:50:49.188Z
0|broker | BROKER(23) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T08:50:55.137Z
0|broker | BROKER(23) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T08:51:01.102Z
0|broker | BROKER(23) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T08:51:07.116Z
0|broker | BROKER(23) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T08:51:13.114Z
0|broker | BROKER(23) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-14T08:51:19.115Z

[itrambovetskyi]

At first sight the problem is in

0|broker | BROKER(23) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-14T08:50:03.033Z
0|broker | 2018-05-14T08:50:03.039Z websocketmanager close: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:50:03.040Z websocketmanager removeAuthorized: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:50:03.040Z websocketfactory removeSocket: 5CCF7FCCE3E1
0|broker | BROKER(23) INFO: client with id: "5CCF7FCCE3E1" disconnected --- 2018-05-14T08:50:03.043Z
0|broker | 2018-05-14T08:50:03.053Z websocketmanager sendString: 5CCF7FCCE3E1
0|broker | 2018-05-14T08:50:03.053Z websocketmanager _lock: 5CCF7FCCE3E1
0|broker | BROKER(23) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-14T08:50:03.060Z

it seems like you trying to publish message after closing connection (actually, it's not you, it's because of some bugs in internal broker functionality).

As a temporary fix I would like to suggest adding a delay between publishing and closing connection ( 1-2 sec I think ). If it not help, please, inform me.

I will try to fix it as soon as possible.

Thanks,
Ihor T.

[wzqallz]

Yeah, I called the MQTT_InitLWT() function on the mqtt client. When I don't set last will, it works fine.
Thanks

[wzqallz]

I think that the mqtt broker sent the last will message to the devicehive server, websocket did not disconnect the reason. How do I modify the code? Do you have any suggestions? @itrambovetskyi
Thanks

[itrambovetskyi]

MQTT broker is not able to send any LastWill message because it's a client side functionality.
As I say above, you can add some delay before closing the MQTT connection. I think it should help.

Also, I have found the source of that problem and almost fixed it. Wait a while and you will be able to use custom client id's without that problem.

[wzqallz]

Thank you very much!

[itrambovetskyi]

@wzqallz Please, check the fix and inform me about the results.

[wzqallz]

@itrambovetskyi
hi,I have not found this problem now. However, I discovered another problem during the test.
When my esp8266 connects to the mqtt broker for the first time, it can normally receive the command sent from the devicehive server, and it can also send a notification to the devicehive server. After I disconnected and reconnect again, I found that esp8266 could not receive the command sent by the devicehive server, but could send a notification to the devicehive server. When I re-deploy the mqtt broker, the first connection work is normal, and the second connection is unable to receive the command.
Log information is as follows:

[2018-05-16 01:58:56] PM2 log: Launching in no daemon mode
[2018-05-16 01:58:56] PM2 log: Starting execution sequence in -fork mode- for app name:broker id:0
[2018-05-16 01:58:56] PM2 log: App name:broker id:0 online
Hello! I'm CrossBrokerCommunicator#72d37af1-2bb7-4031-a0c7-9b0a2117eeab

2018-05-16T01:58:59.570Z websocketmanager WebSocketManager: ws://dh_frontend:8080/api/websocket
Hello! I'm CrossBrokerCommunicator#ea5f6a7c-92d8-402f-9807-1950aae1b269 on 8000

CrossBrokerCommunicator > service.online CrossBrokerCommunicator#ea5f6a7c-92d8-402f-9807-1950aae1b269 on 8000
BROKER(16) INFO: broker has been started on port: 1883 --- 2018-05-16T01:59:00.248Z
CrossBrokerCommunicator > service.online CrossBrokerCommunicator#72d37af1-2bb7-4031-a0c7-9b0a2117eeab
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authenticated --- 2018-05-16T02:06:41.279Z
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" connected --- 2018-05-16T02:06:41.293Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:06:41.368Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:06:41.416Z
2018-05-16T02:06:41.417Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:06:41.419Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:06:41.419Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:06:41.442Z
2018-05-16T02:06:41.443Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:06:41.479Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:06:41.566Z websocketmanager setAuthorized: 5CCF7FCCE3E1
BROKER(16) DEBUG: broker has published to private topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:06:41.570Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for receiving packet on the topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:06:41.582Z
2018-05-16T02:06:41.703Z websocketmanager send: 5CCF7FCCE3E1
2018-05-16T02:06:41.704Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:06:41.741Z websocketmanager _unlock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/command/2/9/5CCF7FCCE3E1/#" --- 2018-05-16T02:06:41.743Z
BROKER(16) DEBUG: broker has published to topic: "dh/command/2/9/5CCF7FCCE3E1/#" --- 2018-05-16T02:09:34.374Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for receiving packet on the topic: "dh/command/2/9/5CCF7FCCE3E1/string" --- 2018-05-16T02:09:34.381Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:09:35.636Z
2018-05-16T02:09:35.636Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:09:35.637Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:09:35.637Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:09:35.637Z
2018-05-16T02:09:35.637Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:09:35.639Z websocketmanager _unlock: 5CCF7FCCE3E1
BROKER(16) DEBUG: broker has published to topic: "dh/command/2/9/5CCF7FCCE3E1/#" --- 2018-05-16T02:10:27.731Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for receiving packet on the topic: "dh/command/2/9/5CCF7FCCE3E1/string" --- 2018-05-16T02:10:27.736Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:10:29.138Z
2018-05-16T02:10:29.138Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:10:29.139Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:10:29.139Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:10:29.140Z
2018-05-16T02:10:29.140Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:10:29.141Z websocketmanager _unlock: 5CCF7FCCE3E1
BROKER(16) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-16T02:11:25.901Z
2018-05-16T02:11:59.143Z websocketmanager close: 5CCF7FCCE3E1
2018-05-16T02:11:59.143Z websocketmanager removeAuthorized: 5CCF7FCCE3E1
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" disconnected --- 2018-05-16T02:11:59.149Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authenticated --- 2018-05-16T02:12:34.044Z
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" connected --- 2018-05-16T02:12:34.049Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:12:34.188Z
2018-05-16T02:12:34.188Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:12:34.189Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:12:34.189Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:12:34.196Z
2018-05-16T02:12:34.197Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:12:34.232Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:12:34.285Z websocketmanager setAuthorized: 5CCF7FCCE3E1
BROKER(16) DEBUG: broker has published to private topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:12:34.297Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for receiving packet on the topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:12:34.303Z
2018-05-16T02:28:18.173Z websocketmanager close: 5CCF7FCCE3E1
2018-05-16T02:28:18.173Z websocketmanager removeAuthorized: 5CCF7FCCE3E1
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" disconnected --- 2018-05-16T02:28:18.175Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authenticated --- 2018-05-16T02:28:57.000Z
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" connected --- 2018-05-16T02:28:57.009Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:28:57.090Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:28:57.136Z
2018-05-16T02:28:57.137Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:28:57.137Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:28:57.137Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:28:57.140Z
2018-05-16T02:28:57.140Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:28:57.155Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:28:57.226Z websocketmanager setAuthorized: 5CCF7FCCE3E1
BROKER(16) DEBUG: broker has published to private topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:28:57.228Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for receiving packet on the topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:28:57.235Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/command/2/9/5CCF7FCCE3E1/#" --- 2018-05-16T02:28:57.330Z
2018-05-16T02:35:31.896Z websocketmanager close: 5CCF7FCCE3E1
2018-05-16T02:35:31.896Z websocketmanager removeAuthorized: 5CCF7FCCE3E1
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" disconnected --- 2018-05-16T02:35:31.898Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authenticated --- 2018-05-16T02:42:49.712Z
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" connected --- 2018-05-16T02:42:49.717Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:42:49.780Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:42:49.832Z
2018-05-16T02:42:49.832Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:42:49.833Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:42:49.833Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:42:49.840Z
2018-05-16T02:42:49.841Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:42:49.871Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:42:49.952Z websocketmanager setAuthorized: 5CCF7FCCE3E1
BROKER(16) DEBUG: broker has published to private topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:42:49.954Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for receiving packet on the topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:42:49.957Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been subscribed for topic: "dh/command/2/9/5CCF7FCCE3E1/#" --- 2018-05-16T02:42:50.040Z
BROKER(16) WARN: client with id: "5CCF7FCCE3E1" has not been authenticated. Reason: Error: User with id 5CCF7FCCE3E1 already connected --- 2018-05-16T02:45:49.793Z
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" disconnected --- 2018-05-16T02:46:21.696Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:46:21.694Z
2018-05-16T02:46:21.694Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:46:21.695Z websocketmanager close: 5CCF7FCCE3E1
2018-05-16T02:46:21.697Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:46:21.697Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:46:21.697Z
2018-05-16T02:46:21.697Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:46:21.698Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:46:21.699Z websocketmanager close: 5CCF7FCCE3E1
2018-05-16T02:46:21.699Z websocketmanager removeAuthorized: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authenticated --- 2018-05-16T02:46:25.073Z
BROKER(16) INFO: client with id: "5CCF7FCCE3E1" connected --- 2018-05-16T02:46:25.078Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for publishing in to the topic: "dh/request" --- 2018-05-16T02:46:25.219Z
2018-05-16T02:46:25.219Z websocketmanager _lock: 5CCF7FCCE3E1
2018-05-16T02:46:25.220Z websocketmanager sendString: 5CCF7FCCE3E1
2018-05-16T02:46:25.220Z websocketmanager _lock: 5CCF7FCCE3E1
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has published to topic: "dh/request" --- 2018-05-16T02:46:25.224Z
2018-05-16T02:46:25.225Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:46:25.241Z websocketmanager _unlock: 5CCF7FCCE3E1
2018-05-16T02:46:25.285Z websocketmanager setAuthorized: 5CCF7FCCE3E1
BROKER(16) DEBUG: broker has published to private topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:46:25.288Z
BROKER(16) DEBUG: client with id: "5CCF7FCCE3E1" has been authorized for receiving packet on the topic: "dh/response/authenticate@5CCF7FCCE3E1" --- 2018-05-16T02:46:25.292Z

[itrambovetskyi]

@wzqallz Unfortunately, the logs you provided are not informative to understand the behavior you have described. Also, I can't reproduce it on my side. Could you please provide me with information about what notification/commands are you sending/receiving, or maybe some code snippets...

[wzqallz]

@itrambovetskyi sorry,I did not describe my problem clearly.

1. esp8266 connect mqtt broker, subscribe to the "dh/command/2/9/5CCF7FCCE3E1/#" topic on esp8266 ("2" is network-id "9" is devicetype-id "5CCF7FCCE3E1" is the device-id)

2. Use the Device Hive REST API to send a command to the device

3. I can see that the 5CCF7FCCE3E1 device received the message in devicehive-admin,also .esp8266 can be receive command.

4. esp8266 disconnected, reconnect again, subscribe topic

5. Use the Device Hive REST API to send a command to the device

6. I can see that the 5CCF7FCCE3E1 device received the message in devicehive-admin,but esp8266 did not receive this command.

When I re-deploy the mqtt broker,repeat the above imagination again.