mosquitto icon indicating copy to clipboard operation
mosquitto copied to clipboard

mosquitto_sub fails with malformed --url while mosquitto_pub succeeds. Error message should be improved instead of looping

Open DaveDavenport opened this issue 2 years ago • 13 comments

I've setup a mqtt server (mqtts) and everything works.

listener 8883
protocol mqtt
allow_anonymous false
password_file /etc/mosquitto/passwd_file

persistence true
persistence_location /var/lib/mosquitto/data/
log_dest file /var/log/mosquitto.log

acl_file /etc/mosquitto/aclfile

per_listener_settings false


keyfile  /etc/mosquitto/ca/x.key
certfile /etc/mosquitto/ca/x.cer
cafile   /etc/mosquitto/ca/x.ca
log_type all

I can publish to it via mosquitto_pub, I can subscribe using MQTT explorer without issue. However when I try to subscribe with mosquitto_sub it keeps reconnecing:

Sep 28 11:05:18 Client (null) sending SUBSCRIBE (Mid: 1, Topic: , QoS: 0, Options: 0x00)
Sep 28 11:05:18 Client (null) sending SUBSCRIBE (Mid: 1, Topic: /x/x/test, QoS: 0, Options: 0x00)
Sep 28 11:05:19 Client (null) sending CONNECT
Sep 28 11:05:19 Client (null) received CONNACK (0)
Sep 28 11:05:19 Client (null) sending SUBSCRIBE (Mid: 2, Topic: , QoS: 0, Options: 0x00)
Sep 28 11:05:19 Client (null) sending SUBSCRIBE (Mid: 2, Topic: /x/x/test, QoS: 0, Options: 0x00)
Sep 28 11:05:20 Client (null) sending CONNECT
Sep 28 11:05:20 Client (null) received CONNACK (0)
Sep 28 11:05:20 Client (null) sending SUBSCRIBE (Mid: 3, Topic: , QoS: 0, Options: 0x00)
Sep 28 11:05:20 Client (null) sending SUBSCRIBE (Mid: 3, Topic: /x/x/test, QoS: 0, Options: 0x00)

On the server I see:

1695891832: New connection from x:42458 on port 8883.
1695891832: New client connected from x:42458 as auto-8F2420E5-2DCB-0BBD-0C8A-CEB07839F4A4 (p2, c1, k60, u'x').
1695891832: No will message specified.
1695891832: Sending CONNACK to auto-8F2420E5-2DCB-0BBD-0C8A-CEB07839F4A4 (0, 0)
1695891832: Received SUBSCRIBE from auto-8F2420E5-2DCB-0BBD-0C8A-CEB07839F4A4
1695891832: Client auto-8F2420E5-2DCB-0BBD-0C8A-CEB07839F4A4 disconnected due to malformed packet.
1695891833: New connection from x:42464 on port 8883.
1695891833: New client connected from x:42464 as auto-47BC40CD-A771-0738-BD26-CD376ED9E5DA (p2, c1, k60, u'x').
1695891833: No will message specified.
1695891833: Sending CONNACK to auto-47BC40CD-A771-0738-BD26-CD376ED9E5DA (0, 0)
1695891833: Received SUBSCRIBE from auto-47BC40CD-A771-0738-BD26-CD376ED9E5DA
1695891833: Client auto-47BC40CD-A771-0738-BD26-CD376ED9E5DA disconnected due to malformed packet.

Server version: 2.0.15 Client version: 2.0.15/2.0.11

I've tested the certificate chain with 'openssl s_client -connect' and it sais it is correct. mosquitto_pub works, if I use the same but do a mosquitto_sub it fails .

I must be missing something, any ideas?

DaveDavenport avatar Sep 28 '23 09:09 DaveDavenport

what flags are you using for the respective mosquitto_pub/sub commands?

Daedaluz avatar Sep 28 '23 09:09 Daedaluz

mosquitto_sub -L mqtts://x:x@x/  -t '/x/x/test' -d --capath /etc/ssl/certs/ |ts

this fails, this works:


mosquitto_pub -L mqtts://x:x@x/  -t '/x/x/test' -d --capath /etc/ssl/certs/  -m 'test4'

DaveDavenport avatar Sep 28 '23 09:09 DaveDavenport

I also tried to setup version without tls, and I get the same behaviour .

DaveDavenport avatar Sep 28 '23 09:09 DaveDavenport

One thing i noticed, is that you can specify the topic straight up in the URL. Try mosquitto_sub -L mqtts://x:x@x//x/x/test (the double // is not a typo because your example topic begins with /)

Daedaluz avatar Sep 28 '23 10:09 Daedaluz

That works, but is a bit confusing. In another situation I use -h (and no authentication) and -t and this works fine.

How do I subscribe to multiple topics? and why does this not give an error on the client, but a malformed package on the server.

DaveDavenport avatar Sep 28 '23 10:09 DaveDavenport

mosquitto_sub -L mqtt://localhost:8884//x/x/test -L mqtt://localhost:8884//x/x/test2

yields:

1695896239: New connection from 127.0.0.1:59774 on port 8884.
1695896239: New client connected from 127.0.0.1:59774 as auto-0B567ECB-20DA-0EE0-CDFF-1F15B075201F (p2, c1, k60).
1695896239: No will message specified.
1695896239: Sending CONNACK to auto-0B567ECB-20DA-0EE0-CDFF-1F15B075201F (0, 0)
1695896239: Received SUBSCRIBE from auto-0B567ECB-20DA-0EE0-CDFF-1F15B075201F
1695896239: 	/x/x/test (QoS 0)
1695896239: auto-0B567ECB-20DA-0EE0-CDFF-1F15B075201F 0 /x/x/test
1695896239: 	/x/x/test2 (QoS 0)
1695896239: auto-0B567ECB-20DA-0EE0-CDFF-1F15B075201F 0 /x/x/test2
1695896239: Sending SUBACK to auto-0B567ECB-20DA-0EE0-CDFF-1F15B075201F

as why -t throws malformed packet, i can only speculate.. Maybe because the url is simply supposed to contain the topic , and a subscription to an empty topic is a malformed packet error?

Daedaluz avatar Sep 28 '23 10:09 Daedaluz

That sounds plausible, thanks for helping me resolve this. (I think a better error message both server/client side would be beneficial).

DaveDavenport avatar Sep 28 '23 10:09 DaveDavenport

Reading in the spec:

The payload of a SUBSCRIBE packet MUST contain at least one Topic Filter / QoS pair. A SUBSCRIBE packet with no payload is a protocol violation [MQTT-3.8.3-3]. See section 4.8 for information about handling errors.

So, it looks like this is the case.

But a client side check should probably be put in place if not already done.

Daedaluz avatar Sep 28 '23 10:09 Daedaluz

In hind side it is kinda in the message:

Sep 28 11:05:18 Client (null) sending SUBSCRIBE (Mid: 1, Topic: , QoS: 0, Options: 0x00)

but I completely missed this. To me it just looked like it got stuck in loop.

DaveDavenport avatar Sep 28 '23 10:09 DaveDavenport

running mosquitto_sub -t "" actually gives the same issue

Daedaluz avatar Sep 28 '23 10:09 Daedaluz

@ralight I checked how to fix this. If you agree, I will provide a PR:

The reference in the spec is

All Topic Names and Topic Filters MUST be at least one character long [MQTT-4.7.3-1]

  • best approach is to check for zero length topics / topic filters is in lib/util_topic.c and add tests in test/unit/util_topic_test.c
  • need to change the special handling of "" for bridge prefixes in src/bridge_topic.c
  • change the handling of zero length topics in src/handle_subscribe.c to log the actual cause of the problem (make it like src/handle_unsubscribe.c)

ckrey avatar Oct 10 '24 11:10 ckrey

I checked how to fix this. If you agree, I will provide a PR:

That would be lovely, thank you.

@ralight I checked how to fix this. If you agree, I will provide a PR:

* best approach is to check for zero length topics / topic filters is in `lib/util_topic.c` and add tests in `test/unit/util_topic_test.c`

Agreed

* need to change the special handling of `""` for bridge prefixes in `src/bridge_topic.c`

Yes, so when we load the config it should check the final length of any remapped topic to make sure it is >0 long.

* change the handling of zero length topics in `src/handle_subscribe.c` to log the actual cause of the problem (make it like `src/handle_unsubscribe.c`)

It looks to me like it does this already.

ralight avatar Oct 10 '24 12:10 ralight

* change the handling of zero length topics in `src/handle_subscribe.c` to log the actual cause of the problem (make it like `src/handle_unsubscribe.c`)

It looks to me like it does this already.

It does not explicitly and doesn't log the cause, just "malformed message". I fixed this.

ckrey avatar Oct 12 '24 17:10 ckrey