ioBroker / ioBroker.mqtt

Mqtt server and client for ioBroker.
MIT License
54 stars 30 forks source link

mosquitto can't connect when TLS is enabled #341

Open tehXor opened 1 year ago

tehXor commented 1 year ago

Describe the bug
When enabling TLS (with the use of Let's Encrypt certificates) mosquitto is unable to connect. After Client (null) sending CONNECT it just throws an Error: Unknown error. without further output, although the -d flag for debug output is set. Connecting with TLS disabled on the MQTT adapter works. Connecting with openssl s_client -connect and TLS enabled on the MQTT adapter also looks good and every certificate in the chain could be verified. Even with the debug flag the MQTT adapter log shows no entries of these failed connections.

To Reproduce
Steps to reproduce the behavior:

  1. In the adapter settings tick the SSL checkbox and use public, private and chain certificate files from Let's Encrypt for your domain under which ioBroker is reachable (and optionally set the port to 8883 to ensure clients will pick up that they should use TLS).
  2. On another machine install all mosquitto packages: apt install mosquitto*
  3. Try to connect with a test message (and optionally TLS flags to ensure mosquitto tries to use TLS): mosquitto_pub -h my.iobroker.domain -t test -m "hello" -p 8883 -u "test" -P "t35t" --tls-use-os-certs -d (you can also try all other TLS related flags)
  4. This always results in an Error: Unknown error. no matter which mosquitto flags you try.

Expected behavior
It should publish the test message just like it does when TLS (the SSL flag in the MQTT adapter options) is disabled.

Screenshots & Logfiles
mosquitto_pub -h my.iobroker.domain -t test -m "hello" -p 8883 -u "test" -P "t35t" --tls-use-os-certs -d:

Client (null) sending CONNECT
Error: Unknown error.

openssl s_client -connect my.iobroker.domain:8883:

CONNECTED(00000003)
depth=2 C = US, O = Internet Security Research Group, CN = ISRG Root X1
verify return:1
depth=1 C = US, O = Let's Encrypt, CN = R3
verify return:1
depth=0 CN = *.iobroker.domain
verify return:1
---
Certificate chain
 0 s:CN = *.iobroker.domain
   i:C = US, O = Let's Encrypt, CN = R3
 1 s:C = US, O = Let's Encrypt, CN = R3
   i:C = US, O = Internet Security Research Group, CN = ISRG Root X1
 2 s:C = US, O = Internet Security Research Group, CN = ISRG Root X1
   i:O = Digital Signature Trust Co., CN = DST Root CA X3
---
Server certificate
-----BEGIN CERTIFICATE-----
XXXXXXXXXXXXXXXXXXXXXXXXXXX
-----END CERTIFICATE-----
subject=CN = *.iobroker.domain

issuer=C = US, O = Let's Encrypt, CN = R3

---
No client certificate CA names sent
Peer signing digest: SHA256
Peer signature type: RSA-PSS
Server Temp Key: X25519, 253 bits
---
SSL handshake has read 5088 bytes and written 385 bytes
Verification: OK
---
New, TLSv1.3, Cipher is TLS_AES_256_GCM_SHA384
Server public key is 4096 bit
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
Early data was not sent
Verify return code: 0 (ok)
---
---
Post-Handshake New Session Ticket arrived:
SSL-Session:
    Protocol  : TLSv1.3
    Cipher    : TLS_AES_256_GCM_SHA384
    Session-ID: XXXXXXXXXXXXXXX
    Session-ID-ctx:
    Resumption PSK: XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
    PSK identity: None
    PSK identity hint: None
    SRP username: None
    TLS session ticket lifetime hint: 7200 (seconds)
    TLS session ticket:
    0000 - XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX   XXXXXXXXXXXXXXXX

    Start Time: 1670990241
    Timeout   : 7200 (sec)
    Verify return code: 0 (ok)
    Extended master secret: no
    Max Early Data: 0
---
read R BLOCK
---
Post-Handshake New Session Ticket arrived:
SSL-Session:
    Protocol  : TLSv1.3
    Cipher    : TLS_AES_256_GCM_SHA384
    Session-ID: XXXXXXXXXXXXXXX
    Session-ID-ctx:
    Resumption PSK: XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
    PSK identity: None
    PSK identity hint: None
    SRP username: None
    TLS session ticket lifetime hint: 7200 (seconds)
    TLS session ticket:
    0000 - XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX   XXXXXXXXXXXXXXXX

    Start Time: 1670990241
    Timeout   : 7200 (sec)
    Verify return code: 0 (ok)
    Extended master secret: no
    Max Early Data: 0
---
read R BLOCK

Adapter log:

mqtt.0 | 2022-12-14 05:27:16.479 | info | Starting MQTT (Secure) authenticated server on 0.0.0.0:8883
-- | -- | -- | --
mqtt.0 | 2022-12-14 05:27:16.297 | info | starting. Version 4.0.7 in /opt/iobroker/node_modules/iobroker.mqtt, node: v16.18.1, js-controller: 4.0.23
mqtt.0 | 2022-12-14 05:27:16.236 | info | Plugin sentry Sentry Plugin disabled for this process because sending of statistic data is disabled for the system

Versions:

stale[bot] commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs within the next 7 days. Please check if the issue is still relevant in the most current version of the adapter and tell us. Also check that all relevant details, logs and reproduction steps are included and update them if needed. Thank you for your contributions. Dieses Problem wurde automatisch als veraltet markiert, da es in letzter Zeit keine Aktivitäten gab. Es wird geschlossen, wenn nicht innerhalb der nächsten 7 Tage weitere Aktivitäten stattfinden. Bitte überprüft, ob das Problem auch in der aktuellsten Version des Adapters noch relevant ist, und teilt uns dies mit. Überprüft auch, ob alle relevanten Details, Logs und Reproduktionsschritte enthalten sind bzw. aktualisiert diese. Vielen Dank für Eure Unterstützung.

bitboy00 commented 1 month ago

same here ... TLS/SSL doesn't work if used as Server.

mcm1957 commented 1 month ago

@Apollon77 Anybody maintaining this adapter?

Apollon77 commented 1 month ago

I think first of all ... a debug level log would be awesome because I do not see any info here about this unknown error anywhere ... Also is that error thrown on iobroker side or on mosquitto side?

bitboy00 commented 1 month ago

A debug (silly) level log shows exactly nothing. It just doesn't work. There is a tcpdump showing that there is a partial handshake but the client (whatever the client is) disconnects for an unknown reason. That might be mqtt-explorer or any other client.

The most basic test:

Create a server mqtt.0 and a client mqtt.1 on the same server. Connect using 127.0.0.1 without TLS and the client and the Server immediately are “green”. Data is running just fine.

Configure both sides SSL(TLS) and try to connect again. The client shows “green” but the server is “orange” ... nothing will happen, and the log shows nothing interesting.

I tried Letsencrypt-Certs and self-signed ones with different Parameters. Now, I installed mosquitto, and it runs just fine with that very certificates. But there is no Admin-integration, of course. Any Client is okay with that. The mqtt.adapter as client like the MQTT-explorer.

Apollon77 commented 1 month ago

Then it is about using wireshark or such and compare between a working and a non working solution to maybe find out whats the difference or find out how to get more detailed errors from mosquitto when they report the "Unknown error", or?!

bitboy00 commented 1 month ago

In my opinion, that's way more than a developer can wait for. I'm user and spent hours with testing and logging and creating certs. An as even a local connect using address 127.0.0.1 is not working... And mosquito is functioning. There are no visible errors. Nothing in the Logofiles.

So if you have interest in providing a working Adapter, you can reproduce it and will find bugs faster than I could do. Otherwise my

Apollon77 commented 1 month ago

So if you have interest in providing a working Adapter ...

Sure we have ... always ... for anyone of the 200+ core managed adapters ... That's why the issue is open. Somewhen someone will have the time to look into it ( just to be sure we see it the same ... 2 users ot of 27k installations of this adapter have this issue rn ..... right?

The more help and info we can get the faster it can be to find and understand the issue.

bitboy00 commented 1 month ago

I can't help you with that. It's 5 minutes to reproduce, and it will tell you much faster than me where to look for. I tried on a raspberry pi 3 an 4 and also a VM with 4 cores, 32gb and SSD. Raspian and Debian bookworm. I followed the available manuals, YouTube tutorials and ask Google and chatgpt. It just can't connect if I switched on SSL. Never. And there where no visible errors in a log.

Meanwhile I use mosquito, even if it's not integrated with admin. Your mqtt.adapter-client connects just fine to it using SSL/TLS. It just worked from the first try.

So don't blame me. I'm out here.

9Mad-Max5 commented 3 weeks ago

Hi,

Same Issue on my side. I'm using the adapter as a Publisher and as a Subscriber on two different machines. While unencrypted was no issue with the encryption enabled the connection is not working anymore. This is the deubg log of the server/broker: ` mqtt.0 2024-10-24 00:24:22.077 debug stateChange mqtt.0.info.connection: {"val":"","ack":true,"ts":1729722262076,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1729721668625}
mqtt.0 2024-10-24 00:24:22.034 debug stateChange mqtt.0.info.clients.iobroker_mqtt_0: {"val":false,"ack":true,"ts":1729722262032,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1729721668624}
mqtt.0 2024-10-24 00:24:21.970 info Starting MQTT (Secure) authenticated server on 0.0.0.0:1885
mqtt.0 2024-10-24 00:24:21.865 info starting. Version 6.1.2 in /opt/iobroker/node_modules/iobroker.mqtt, node: v20.18.0, js-controller: 6.0.9
mqtt.0 2024-10-24 00:24:21.777 debug Plugin sentry Initialize Plugin (enabled=true)
mqtt.0 2024-10-24 00:24:21.766 debug States connected to redis: 127.0.0.1:9000
mqtt.0 2024-10-24 00:24:21.715 debug States create User PubSub Client
mqtt.0 2024-10-24 00:24:21.715 debug States create System PubSub Client
mqtt.0 2024-10-24 00:24:21.709 debug Redis States: Use Redis connection: 127.0.0.1:9000
mqtt.0 2024-10-24 00:24:21.696 debug Objects connected to redis: 127.0.0.1:9001
mqtt.0 2024-10-24 00:24:21.694 debug Objects client initialize lua scripts
mqtt.0 2024-10-24 00:24:21.676 debug Objects create User PubSub Client
mqtt.0 2024-10-24 00:24:21.676 debug Objects create System PubSub Client
mqtt.0 2024-10-24 00:24:21.671 debug Objects client ready ... initialize now
mqtt.0 2024-10-24 00:24:21.658 debug Redis Objects: Use Redis connection: 127.0.0.1:9001

`

This is from the client/subscriber: ` mqtt.0 2024-10-24 00:40:58.290 error Client error: Error: connack timeout
mqtt.0 2024-10-24 00:40:28.294 debug Send to server "info/connection": {"val":true,"ack":true,"ts":1729723228291,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1729723228291}
mqtt.0 2024-10-24 00:40:28.294 info send2Server mqtt.0.info.connection[info/connection]
mqtt.0 2024-10-24 00:40:28.293 debug stateChange mqtt.0.info.connection: {"val":true,"ack":true,"ts":1729723228291,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1729723228291}
mqtt.0 2024-10-24 00:40:28.285 info Reconnected to iobroker.mi-ma.eu
mqtt.0 2024-10-24 00:40:18.292 debug Send to server "info/connection": {"val":false,"ack":true,"ts":1729723218288,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1729723218288}
mqtt.0 2024-10-24 00:40:18.291 info send2Server mqtt.0.info.connection[info/connection]
mqtt.0 2024-10-24 00:40:18.291 debug stateChange mqtt.0.info.connection: {"val":false,"ack":true,"ts":1729723218288,"q":0,"from":"system.adapter.mqtt.0","user":"system.user.admin","lc":1729723218288}
mqtt.0 2024-10-24 00:40:18.284 info Disconnected from iobroker.xxx.xx

`

Is there anything more from logging or information side i can provide for this bug?

tehXor commented 3 weeks ago

@Apollon77

just to be sure we see it the same ... 2 users ot of 27k installations of this adapter have this issue rn ..... right?

This is more likely a problem closer to 27k out of 27k are having than 2 out of 27k. It's just that security isn't really a thing for most ioBroker users as well as a lot of its devs (which is fine, it's for home use and not everybody cares). And I guess some devs prefer to invest 5 minutes in writing a flame post than actually trying to reproduce the issue (just to be sure we see it the same ... reproduction steps don't come much easier than in this issue here ..... right?)

And don't get me wrong, I really value the work in this project as well as your personal work a great deal. And as it is open I also can totally understand that some issues just won't get addressed for what ever reasons. It doesn't matter, every reason is valid since it is mostly your and the other devs free time. I myself am also not an ordinary user, solved this for me in another way long ago and haven't complained. I'm just adding my two cent of ><((((°> since I found you flaming against an ordinary user who really tried being helpful and getting help a bit funny.

Apollon77 commented 3 weeks ago

I would not see where I "flamed" against any user, but as usual communication is how it is received. And no the above posts did not take me 5 minutes.

So all good, in the end it is as it is ... you think it is easy to reproduce. I think I will take a plenty amount of time for this ... at least enough to just out it on the todo list and not jumping on it directly because all "I can not do in some mind directly" tasks I prioritize.

9Mad-Max5 commented 3 weeks ago

Sounds reasonable but still my request is there any idea you have I can do currently to support you. Is there any tool like wireshark I can use to help you out where the hickups are, or anything in that department? And if so, I would really appreciate a short like note where what to do and what you need.

Apollon77 commented 3 weeks ago

@9Mad-Max5 For me it seems to be something in the messaging because when it works without TLS but errors with TLS it could be an idea to catch the data traffic which is sent in in both cases (is it the same traffic just encrpted or are there other changes in there? I did not checked the mqtt specs on that ). And maybe compare the responses from an iobroker vs an other mqtt server where it works. This could at least help to find the right code places maybe

tehXor commented 3 weeks ago

I assume with an attached debugger you would see more or less right away where things fall apart here. @9Mad-Max5 that however is something which is not so easily done when you haven't set up a dev environment for this project and haven't done this before. On the other hand it's not too complicated either and you can use you're normal dev tools from Google Chrome and don't need an IDE. Basically just start node.js for ioBroker with the --inspect flag (see https://nodejs.org/en/learn/getting-started/debugging ), go to chrome://inspect#devices in your Chrome, tick 'Discover network targets' and on 'Configure...' add the network address and inspect port (default 9229) of ioBorker.

9Mad-Max5 commented 2 weeks ago

Thanks @tehXor I got it running using as well this tutorial: https://forum.iobroker.net/topic/4201/adapter-debuggen-mit-chrome

Unfortunately, I'm not really aware of how to debug node js modules so far or more precise which part is the client software or server software. I mean I have good knowledge of working with python and VSCode but never dipped my toes in to node.js really. So it is working, but It really will take me a while till I can understand what is what.

tehXor commented 2 weeks ago

@9Mad-Max5 it seems this is important to you ^^ Since you are already this far I looked a bit at the implementation. So what you are mostly interested in in the debugger is the https://github.com/ioBroker/ioBroker.mqtt/blob/master/lib/server.js. You can for example hit ctrl + shift + f in the debugger and then search for a line of code from it and that should bring it up. Most likely the problem occurs somewhere in that if clause: https://github.com/ioBroker/ioBroker.mqtt/blob/9258a16c0ea606449419a831d0c3d5055459f755/lib/server.js#L1330 (so add breakpoints here) or, if that doesn't fail, somewhere in the startServer function: https://github.com/ioBroker/ioBroker.mqtt/blob/9258a16c0ea606449419a831d0c3d5055459f755/lib/server.js#L748 . So if the first doesn't fail add breakpoints here at the start and at the start of each event callback (so all socket.on('someEvent', () => { //this is the callback logic were you want breakpoints for each } and client.on('someEvent', () => { //this is the callback logic were you want breakpoints for each })

This will give you a lot of infos how far the process comes before failing which you can report back. Also not too unlikely is that some events were forgotten to implement. This seems likely since the code is actually quite well regarding exception handling. So you can (but this is even more advanced) look though the docs of node TLS and mqtt-connection and add missing error or other events with simple adapter.log.debug just to see if it gets fired and to report back. Also at the line https://github.com/ioBroker/ioBroker.mqtt/blob/9258a16c0ea606449419a831d0c3d5055459f755/lib/server.js#L749 you can try to change the 'connection' to 'secureConnection' since it looks to me this is such a forgotten event but maybe it is also handled somehow differently. If I'm right that at least should hit the debugging/try ... catch blocks within that block which you can also report back here.

At some point probably help form the original author would really be helpful but let's see what you find ;-)