Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MQTT client can't connect leafnode after cluster restart #3027

Closed
LLLLimbo opened this issue Apr 12, 2022 · 1 comment · Fixed by #3031
Closed

MQTT client can't connect leafnode after cluster restart #3027

LLLLimbo opened this issue Apr 12, 2022 · 1 comment · Fixed by #3031

Comments

@LLLLimbo
Copy link

LLLLimbo commented Apr 12, 2022

This issue may be related to #3009 .

Description

The problem is currently found to occur with the problem described in #3009.

  1. Under normal circumstances, restarting the entire cluster will not cause this problem.
  2. After removing the Jetstream storage from the leaf node and reboot, the MQTT client can connect to it normally.
  3. When the problem occurs, I can connect to the remote node normally using the MQTT client

Environment
nats-version : 2.7.3
system: centos 7.6

Cluster Information
3 remote nodes, 1 leaf node
Configuration as follows:
https://github.com/LLLLimbo/nats-conf

The full log and Jetstream storage file as follows (After restarting the cluster, trying to connect to the leaf node with the MQTT client) :
https://github.com/LLLLimbo/nats-logs/releases/tag/before-delete
Restarted at around 2022/04/12 09:30.
When I try to connect to the leaf node using the MQTT client, the log for the leaf node shows the following message:

[15891] 2022/04/12 09:44:07.556991 [TRC] 192.168.9.251:60863 - mid:311 - "mqttx_8fec4c09" - <<- [CONNECT clientID=mqttx_8fec4c09 keepAlive=1m30s username=seeiner-edge-mqtt password=****]
[15891] 2022/04/12 09:44:07.557184 [INF] Creating MQTT streams/consumers with replicas 1 for account "SEEINER"
[15891] 2022/04/12 09:44:07.557406 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS+ $MQTT.JSA.gf9flzF3.*.*]
[15891] 2022/04/12 09:44:07.557470 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS+ $MQTT.JSA.*.SP.*]
[15891] 2022/04/12 09:44:07.557504 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS+ $MQTT.sub.6mH3UM68HpFqAzAHYU9lix]
[15891] 2022/04/12 09:44:07.557521 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS+ $MQTT.JSA.*.RD]
[15891] 2022/04/12 09:44:07.558531 [DBG] JETSTREAM - JetStream connection closed: Client Closed
[15891] 2022/04/12 09:44:07.558559 [DBG] JETSTREAM - JetStream connection closed: Client Closed
[15891] 2022/04/12 09:44:07.558669 [DBG] 192.168.3.135:7422 - lid:15 - Not permitted to deliver to "$JS.API.STREAM.CREATE.$MQTT_sess"
[15891] 2022/04/12 09:44:07.558789 [TRC] ACCOUNT - <<- [PUB $JS.EVENT.ADVISORY.API  824]
[15891] 2022/04/12 09:44:07.558878 [TRC] ACCOUNT - <<- MSG_PAYLOAD: ["{\"type\":\"io.nats.jetstream.advisory.v1.api_audit\",\"id\":\"6mH3UM68HpFqAzAHYU9llu\",\"timestamp\":\"2022-04-12T01:44:07.558598406Z\",\"server\":\"nats-edge\",\"client\":{\"start\":\"2022-04-12T01:44:07.55710069Z\",\"id\":312,\"acc\":\"SEEINER\",\"server\":\"nats-edge\",\"cluster\":\"nats-edge\",\"kind\":\"Account\"},\"subject\":\"$JS.API.STREAM.CREATE.$MQTT_sess\",\"request\":\"{\\\"name\\\":\\\"$MQTT_sess\\\",\\\"subjects\\\":[\\\"$MQTT.sess.\\\\u003e\\\"],\\\"retention\\\":\\\"limits\\\",\\\"max_consumers\\\":0,\\\"max_msgs\\\":0,\\\"max_bytes\\\":0,\\\"max_age\\\":0,\\\"max_msgs_per_subject\\\":1,\\\"discard\\\":\\\"old\\\",\\\"storage\\\":\\\"file\\\",\\\"num_replicas\\\":1,\\\"sealed\\\":false,\\\"deny_delete\\\":false,\\\"deny_purge\\\":false,\\\"allow_rollup_hdrs\\\":false}\",\"response\":\"{\\\"type\\\":\\\"io.nats.jetstream.api.v1.stream_create_response\\\",\\\"error\\\":{\\\"code\\\":500,\\\"err_code\\\":10049,\\\"description\\\":\\\"deleted message\\\"}}\"}"]
[15891] 2022/04/12 09:44:07.558881 [TRC] ACCOUNT - <-> [DELSUB 1]
[15891] 2022/04/12 09:44:07.559014 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS- $MQTT.JSA.gf9flzF3.*.*]
[15891] 2022/04/12 09:44:07.559040 [TRC] ACCOUNT - <-> [DELSUB 2]
[15891] 2022/04/12 09:44:07.559055 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS- $MQTT.JSA.*.SP.*]
[15891] 2022/04/12 09:44:07.559067 [TRC] ACCOUNT - <-> [DELSUB 3]
[15891] 2022/04/12 09:44:07.559081 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS- $MQTT.sub.6mH3UM68HpFqAzAHYU9lix]
[15891] 2022/04/12 09:44:07.559107 [TRC] ACCOUNT - <-> [DELSUB 4]
[15891] 2022/04/12 09:44:07.559122 [TRC] 192.168.3.135:7422 - lid:15 - ->> [LS- $MQTT.JSA.*.RD]
[15891] 2022/04/12 09:44:07.559151 [ERR] 192.168.9.251:60863 - mid:311 - "mqttx_8fec4c09" - unable to connect: create sessions stream for account "SEEINER": deleted message (10049)
[15891] 2022/04/12 09:44:07.559169 [DBG] 192.168.9.251:60863 - mid:311 - "mqttx_8fec4c09" - Client connection closed: Protocol Violation

Next, I stopped the leaf node using signal, deleted the jetstream storage, and restarted. I tried to connect to the leaf node using the MQTT client (client_id: mqttx_8fec4c09)and found that I was able to connect successfully.

The jetstream storage files and logs after these operations (only the most recent parts are intercepted):
https://github.com/LLLLimbo/nats-logs/releases/tag/after-delete

@LLLLimbo LLLLimbo changed the title MQTT client can't connect after cluster restart MQTT client can't connect leafnode after cluster restart Apr 12, 2022
kozlovic added a commit that referenced this issue Apr 13, 2022
When using subscriptions through import/exports, the server with
a leafnode connection would properly send the interest over, but
if the connection is recreated, this would not happen.

In case of JetStream where that happens under the cover, message
flow would stop after the leafnode restart because the subscriptions
would be created on recovery of the JetStream assets but *before*
the LeafNode connection could be established.

Resolves #3024
Resolves #3027
Resolves #3009

Signed-off-by: Ivan Kozlovic <ivan@synadia.com>
kozlovic added a commit that referenced this issue Apr 13, 2022
When using subscriptions through import/exports, the server with
a leafnode connection would properly send the interest over, but
if the connection is recreated, this would not happen.

In case of JetStream where that happens under the cover, message
flow would stop after the leafnode restart because the subscriptions
would be created on recovery of the JetStream assets but *before*
the LeafNode connection could be established.

Resolves #3024
Resolves #3027
Resolves #3009

Signed-off-by: Ivan Kozlovic <ivan@synadia.com>
@kozlovic
Copy link
Member

@LLLLimbo I believe that the issue has to do with a leafnode restarting or recreating a connection and should be addressed in PR that has just been merged. It should be available in the nightly today or in the release v2.8.0 that should be coming out very shortly.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants