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

Connecting mosquitto broker to gBridge: socket error - Do we really need TLS V1.3? #7

Closed
vanceb opened this Issue Oct 19, 2018 · 4 comments

Comments

Projects
None yet
2 participants
@vanceb

vanceb commented Oct 19, 2018

I thought I had my connection from a local mosquitto broker to the hosted gBridge working about a month ago, but coming back to the project now I can't get my mosquitto broker to connect to the hosted gBridge. The mosquitto log shows these errors looping around, repeating the following excerpt:

1539898641: Bridge local.u37 doing local SUBSCRIBE on topic gBridge/u37/d73/onoff/set
1539898641: Bridge local.u37 doing local SUBSCRIBE on topic gBridge/u37/d74/onoff/set
1539898641: Bridge local.u37 doing local SUBSCRIBE on topic gBridge/u37/d75/onoff/set
1539898641: Connecting bridge gbridge (mqtt.gbridge.kappelt.net:8883)
1539898672: Connecting bridge gbridge (mqtt.gbridge.kappelt.net:8883)
1539898672: Bridge u37 sending CONNECT
1539898672: Received CONNACK on connection local.u37.
1539898672: Bridge local.u37 sending SUBSCRIBE (Mid: 85, Topic: gBridge/u37/d73/onoff, QoS: 0)
1539898672: Bridge local.u37 sending UNSUBSCRIBE (Mid: 86, Topic: gBridge/u37/d73/onoff/set)
1539898672: Bridge local.u37 sending SUBSCRIBE (Mid: 87, Topic: gBridge/u37/d74/onoff, QoS: 0)
1539898672: Bridge local.u37 sending UNSUBSCRIBE (Mid: 88, Topic: gBridge/u37/d74/onoff/set)
1539898672: Bridge local.u37 sending SUBSCRIBE (Mid: 89, Topic: gBridge/u37/d75/onoff, QoS: 0)
1539898672: Bridge local.u37 sending UNSUBSCRIBE (Mid: 90, Topic: gBridge/u37/d75/onoff/set)
1539898672: Received SUBACK from local.u37
1539898672: Socket error on client local.u37, disconnecting.

I note that in my account connection details it says that it REQUIRES TLS V1.3, but my mosquitto broker only supports up to TLS V1.2. Do we really REQUIRE TLS V1.3? and if so which version of mosquitto supports this? I am not sure that this is the problem as I seem to establish a connection, get a CONNACK, subscribe to a number of topics, receive a SUBACK and THEN get a socket error.

Any other advice on troubleshooting this would be appreciated.

@vanceb

This comment has been minimized.

vanceb commented Oct 19, 2018

Troubleshooting mqtt bridge connection to Kappelt gBridge

Mosquitto bridge

Config


# =================================================================
# Bridges to Kappelt gBridge for Google Home Automation linkup
# =================================================================

connection gbridge
address mqtt.gbridge.kappelt.net:8883
remote_username gbridge-u37
remote_password <redacted>

# Specifying which topics are bridged
topic gBridge/u37/d73/onoff in 0
topic gBridge/u37/d73/onoff/set out 0
topic gBridge/u37/d74/onoff in 0
topic gBridge/u37/d74/onoff/set out 0
topic gBridge/u37/d75/onoff in 0
topic gBridge/u37/d75/onoff/set out 0

# Setting protocol version explicitly
bridge_attempt_unsubscribe true
bridge_protocol_version mqttv311
bridge_insecure false
bridge_capath /etc/ssl/certs
bridge_tls_version tlsv1.2

# Bridge connection name and MQTT client Id,
# enabling the connection automatically when the broker starts.
try_private true  # Added to try and resolve connection issues
cleansession true
clientid u37
start_type automatic
notifications false
log_type all

Log extract

1539898641: Bridge local.u37 doing local SUBSCRIBE on topic gBridge/u37/d73/onoff/set
1539898641: Bridge local.u37 doing local SUBSCRIBE on topic gBridge/u37/d74/onoff/set
1539898641: Bridge local.u37 doing local SUBSCRIBE on topic gBridge/u37/d75/onoff/set
1539898641: Connecting bridge gbridge (mqtt.gbridge.kappelt.net:8883)
1539898672: Connecting bridge gbridge (mqtt.gbridge.kappelt.net:8883)
1539898672: Bridge u37 sending CONNECT
1539898672: Received CONNACK on connection local.u37.
1539898672: Bridge local.u37 sending SUBSCRIBE (Mid: 85, Topic: gBridge/u37/d73/onoff, QoS: 0)
1539898672: Bridge local.u37 sending UNSUBSCRIBE (Mid: 86, Topic: gBridge/u37/d73/onoff/set)
1539898672: Bridge local.u37 sending SUBSCRIBE (Mid: 87, Topic: gBridge/u37/d74/onoff, QoS: 0)
1539898672: Bridge local.u37 sending UNSUBSCRIBE (Mid: 88, Topic: gBridge/u37/d74/onoff/set)
1539898672: Bridge local.u37 sending SUBSCRIBE (Mid: 89, Topic: gBridge/u37/d75/onoff, QoS: 0)
1539898672: Bridge local.u37 sending UNSUBSCRIBE (Mid: 90, Topic: gBridge/u37/d75/onoff/set)
1539898672: Received SUBACK from local.u37
1539898672: Socket error on client local.u37, disconnecting.

Testing ssl connectivity with openssl

openssl s_client -connect mqtt.gbridge.kappelt.net:8883

CONNECTED(00000005)
depth=2 O = Digital Signature Trust Co., CN = DST Root CA X3
verify return:1
depth=1 C = US, O = Let's Encrypt, CN = Let's Encrypt Authority X3
verify return:1
depth=0 CN = gbridge.kappelt.net
verify return:1
---
Certificate chain
 0 s:/CN=gbridge.kappelt.net
   i:/C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
 1 s:/C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
   i:/O=Digital Signature Trust Co./CN=DST Root CA X3
---
Server certificate
-----BEGIN CERTIFICATE-----
MIIGJzCCBQ+gAwIBAgISA9MbAM82kr6kHDRcE+NMoq0gMA0GCSqGSIb3DQEBCwUA
MEoxCzAJBgNVBAYTAlVTMRYwFAYDVQQKEw1MZXQncyBFbmNyeXB0MSMwIQYDVQQD
ExpMZXQncyBFbmNyeXB0IEF1dGhvcml0eSBYMzAeFw0xODA5MTEyMTAzMjRaFw0x
ODEyMTAyMTAzMjRaMB4xHDAaBgNVBAMTE2dicmlkZ2Uua2FwcGVsdC5uZXQwggEi
MA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQDSi+htM1Cnmlfri0+BYq71ks8+
qpJ4f4/7nJBTHtK7Y5v/4SUCno1wX98yar8qWmRFrH5kDN1dFeEBy9TwSevKe1HE
gcPNTGfsIQwZItZHfaa0pXpNiNYQOVy8l2qzMZ4G4de8DQRgtADF3/TSKETcr0px
aL+K8+JCalWXX5PIZAI84lc3OEpWW1S4WtGZrnHntUr69yBXDjo1ux9qM69CUaZj
144kWHV7v3souChYOP4xsxRwG/PD2uyGhtzesQdOOqqY3TKfw8ChymelExKnS1IR
6j/tYwcF35XP6ilVbqve/82ifWBuiVBipHdjgTSwrJDv4/vJDBWbC32p2AbxAgMB
AAGjggMxMIIDLTAOBgNVHQ8BAf8EBAMCBaAwHQYDVR0lBBYwFAYIKwYBBQUHAwEG
CCsGAQUFBwMCMAwGA1UdEwEB/wQCMAAwHQYDVR0OBBYEFIyFsURVfEkCw2oyLu0w
cOGxgYL8MB8GA1UdIwQYMBaAFKhKamMEfd265tE5t6ZFZe/zqOyhMG8GCCsGAQUF
BwEBBGMwYTAuBggrBgEFBQcwAYYiaHR0cDovL29jc3AuaW50LXgzLmxldHNlbmNy
eXB0Lm9yZzAvBggrBgEFBQcwAoYjaHR0cDovL2NlcnQuaW50LXgzLmxldHNlbmNy
eXB0Lm9yZy8wNQYDVR0RBC4wLIIVKi5nYnJpZGdlLmthcHBlbHQubmV0ghNnYnJp
ZGdlLmthcHBlbHQubmV0MIH+BgNVHSAEgfYwgfMwCAYGZ4EMAQIBMIHmBgsrBgEE
AYLfEwEBATCB1jAmBggrBgEFBQcCARYaaHR0cDovL2Nwcy5sZXRzZW5jcnlwdC5v
cmcwgasGCCsGAQUFBwICMIGeDIGbVGhpcyBDZXJ0aWZpY2F0ZSBtYXkgb25seSBi
ZSByZWxpZWQgdXBvbiBieSBSZWx5aW5nIFBhcnRpZXMgYW5kIG9ubHkgaW4gYWNj
b3JkYW5jZSB3aXRoIHRoZSBDZXJ0aWZpY2F0ZSBQb2xpY3kgZm91bmQgYXQgaHR0
cHM6Ly9sZXRzZW5jcnlwdC5vcmcvcmVwb3NpdG9yeS8wggEDBgorBgEEAdZ5AgQC
BIH0BIHxAO8AdQCkUBJpBVoVVF5iEas3vBA/Yq5VdqReSxcURT4bIhBqJQAAAWXK
qRmeAAAEAwBGMEQCIAcjHYnxZDpl12+a5UVNku9I3kH8Kv4NRI0xSYWT28nvAiAt
RjgE8F+1ZJgfMVQEA8jYMgi4dNgRv87bmX0z3rci9wB2AFWB1MIWkDYBSuoLm1c8
U/DA5Dh4cCUIFy+jqh0HE9MMAAABZcqpG2MAAAQDAEcwRQIgNK/aDkCUM04inRHl
62ryHsCRi7AA2dE/ne+LGBS+yukCIQDH1Y7f4LIF09rSNs4ii/GOUlJfpMSrrJi9
VPZkIfgvIDANBgkqhkiG9w0BAQsFAAOCAQEADbxlkfYmcinjAOpdFWIGi1INeUXK
0NhZpZK+yBH+mWHUnneKfImbZA1cyNYmroutFw/MrZmR73WQujuckdkAF62MAU3N
BGARTx2JSMznB3X4YFXojIMM0nYHHWCQ5mStwylKVOlKfqc3MIms0G3N4xENSsLe
RFCmhBYzcLTKd5yDrD1/dELNEP7zWAs+pqnsOklrfpFIohkN4xmlUVw/UhBJCkNL
fHVUc3Z9BBBjZu0MLjZLwy01iY4bF49xgkr7Y1t6WXGZFlySNjTL13mOJf1gptZ9
La0wPo1WICadNs0l9PkGaJ2QS5+0JN7SzbY0k384t7IJsKMyoySJKExFRg==
-----END CERTIFICATE-----
subject=/CN=gbridge.kappelt.net
issuer=/C=US/O=Let's Encrypt/CN=Let's Encrypt Authority X3
---
No client certificate CA names sent
Server Temp Key: ECDH, X25519, 253 bits
---
SSL handshake has read 3393 bytes and written 293 bytes
---
New, TLSv1/SSLv3, Cipher is ECDHE-RSA-AES256-GCM-SHA384
Server public key is 2048 bit
Secure Renegotiation IS supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
SSL-Session:
    Protocol  : TLSv1.2
    Cipher    : ECDHE-RSA-AES256-GCM-SHA384
    Session-ID: 6595C4EE7B1474541D50B79AEBA23E8024B82643A03D52FABE24BCD6EE70FB4E
    Session-ID-ctx:
    Master-Key: 148ED9730B4DC1275991CAC2FED14BF51C030AA6B1A769E1940DD3E06BC131EFEBD82C69116D7AB1DC582917ED060688
    TLS session ticket lifetime hint: 7200 (seconds)
    TLS session ticket:
    0000 - 01 51 e6 14 7c 02 2a 18-31 8e a4 66 ff f4 af c3   .Q..|.*.1..f....
    0010 - d8 77 42 a1 e1 51 a4 a6-09 e8 6c 26 56 4d 9e fb   .wB..Q....l&VM..
    0020 - 6e ff 0b 3e a5 41 f8 b5-1b b8 67 c0 d0 da 38 4e   n..>.A....g...8N
    0030 - 77 18 f3 91 9f 90 22 ad-2d 28 a7 41 00 96 07 d8   w.....".-(.A....
    0040 - cf 9c f2 a5 0f de 56 b7-8e bb 47 6d bf bb 97 da   ......V...Gm....
    0050 - 60 ed 06 6f 83 b6 5d 16-ca ef 47 61 d5 71 15 91   `..o..]...Ga.q..
    0060 - d6 05 80 fd 3b 48 9a 57-82 ea 38 b2 50 2f 97 a3   ....;H.W..8.P/..
    0070 - 83 cf 94 13 f6 f4 6c 6d-1c 1d 04 25 50 eb 1d 30   ......lm...%P..0
    0080 - 2c a2 fd a4 ff 1e 4d c4-b4 eb 39 22 c8 99 b3 5b   ,.....M...9"...[
    0090 - 11 55 df 51 fc 6d da 05-56 e3 d3 53 9f 79 58 71   .U.Q.m..V..S.yXq
    00a0 - 26 e3 ae ee c9 79 d7 aa-88 e9 e4 ff fb 58 03 db   &....y.......X..

    Start Time: 1539955239
    Timeout   : 7200 (sec)
    Verify return code: 0 (ok)
---

This shows a successful ssl connection from my machine to the server using
TLSV1.2

Testing connectivity with mosquitto_sub

mosquitto_sub -u gbridge-u37 -P xxxxxxxxxxx --capath /etc/ssl/certs -h mqtt.gbridge.kappelt.net -p 8883 -t "gbridge/u37/d74/onoff"

Connection Refused: not authorised.

Reset mosquitto password through the gBridge UI, no change, still Connection Refused: not authorised

This sounds like either I am using the incorrect username/password combination
(I think I have eliminated that), or the gBridge mqtt server is not happy with
my subscription (i.e. the ACL associated with my account on the gBridge
server)

Drawing a bit of a blank here - Any suggestions??

@peterkappelt

This comment has been minimized.

Member

peterkappelt commented Oct 20, 2018

First of all: TLS V1.3 is a documentation error. TLS 1.2 is the current "state of the art"; V 1.3 isn't really established yet. Could you send the relevant documentation link to me, that I'm able to fix this mistake?

I've just tried registering a new account, setting the MQTT password to "abcd1234%" and connecting to it with the same "mosquitto_sub" command you've used. It worked for me without any problems.

Do you use any special chars in your MQTT password that could be interpreted in a wrong way by the command line? What version of mosquitto_sub are you using?

I've just started a log trace with the mosquitto server, filtering for your account. It reported the following:

Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- mosquitto_auth_unpwd_check(gbridge-u37)
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- getuser(gbridge-u37) AUTHENTICATED=1 by mysql
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: New client connected from 81.110.90.244 as u37 (c1, k60, u'gbridge-u37').
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- mosquitto_auth_acl_check(..., client id not available, gbridge-u37, gBridge/u37/d73/onoff, MOSQ_ACL_WRITE)
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- aclcheck(gbridge-u37, gBridge/u37/d73/onoff, 4) CACHEDAUTH: 17
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: Socket error on client u37, disconnecting.

It is sadly only a generic error, not too useful.

Another point: Could you try writing to status topics (with mosquitto_pub) and cross-check with Google Assistant commands whether this works?

@vanceb

This comment has been minimized.

vanceb commented Oct 20, 2018

TL;DR - Password had a $ symbol in it which was causing issues with the mosquitto_sub command, BUT even with new password substituted into the mosquitto bridge config it is STILL NOT connecting - seeing the same errors as my first post.

More detail to specific questions below...

First of all: TLS V1.3 is a documentation error. TLS 1.2 is the current "state of the art"; V 1.3 isn't really established yet. Could you send the relevant documentation link to me, that I'm able to fix this mistake?

The TLS 1.3 note is on my Account home page (https://gbridge.kappelt.net/profile):

screenshot 2018-10-20 17 17 44

I've just tried registering a new account, setting the MQTT password to "abcd1234%" and connecting to it with the same "mosquitto_sub" command you've used. It worked for me without any problems.

Do you use any special chars in your MQTT password that could be interpreted in a wrong way by the command line? What version of mosquitto_sub are you using?

I had a $ symbol in my password which was causing problems with mosquitto_sub. Changed the mqtt password to remove this symbol and I am now able to see topics and data:

mosquitto_sub -u gbridge-u37 -P <redacted> --capath /etc/ssl/certs -h mqtt.gbridge.kappelt.net -p 8883 -t gBridge/u37/# -v -i gbridge-u37
gBridge/u37/d0/grequest EXECUTE
gBridge/u37/d74/onoff 0
gBridge/u37/d0/grequest EXECUTE
gBridge/u37/d74/onoff 1

But even with this password changed in the mosquitto bridge config I am still having the same problems as in my initial post - "Socket error on client, disconnecting"

mosquitto_sub version 1.4.15 running on libmosquitto 1.4.15.
mosquitto version 1.4.15 (build date Sat, 07 Apr 2018 11:16:43 +0100)

I've just started a log trace with the mosquitto server, filtering for your account. It reported the following:

Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- mosquitto_auth_unpwd_check(gbridge-u37)
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- getuser(gbridge-u37) AUTHENTICATED=1 by mysql
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: New client connected from 81.110.90.244 as u37 (c1, k60, u'gbridge-u37').
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- mosquitto_auth_acl_check(..., client id not available, gbridge-u37, gBridge/u37/d73/onoff, MOSQ_ACL_WRITE)
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: |-- aclcheck(gbridge-u37, gBridge/u37/d73/onoff, 4) CACHEDAUTH: 17
Oct 20 12:00:16 helium mosquitto[2529]: 1540029616: Socket error on client u37, disconnecting.

It is sadly only a generic error, not too useful.

Another point: Could you try writing to status topics (with mosquitto_pub) and cross-check with Google Assistant commands whether this works?

@vanceb

This comment has been minimized.

vanceb commented Oct 20, 2018

Issue resolved

Having got mosquitto_sub to work I had elimiated any issues at the gBridge server end, so concentrated on my mosquitto bridge config. I removed all settings not listed in the documentation. The bridge worked. I then gradually re-enabled each of my extra settings to find out which was causing the issue. The config line causing the problem was bridge_protocol_version mqttv311.

My current working config is now as follows:

# =================================================================
# Bridges to Kappelt gBridge for Google Home Automation linkup
# =================================================================

connection gbridge
address mqtt.gbridge.kappelt.net:8883
remote_username gbridge-u37
remote_password <redacted>

# Specifying which topics are bridged
topic gBridge/u37/+/+ in 0
topic gBridge/u37/+/+/set out 0

# Bridge settings
bridge_attempt_unsubscribe true
#bridge_protocol_version mqttv311  # This caused connection errors when enabled
bridge_insecure false
bridge_capath /etc/ssl/certs
bridge_tls_version tlsv1.2

# enabling the connection automatically when the broker starts.
start_type automatic
try_private true
cleansession true
notifications false
log_type all
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment