hassio-addons / addon-mqtt

MQTT Server & Web client - Home Assistant Community Add-ons
https://addons.community
MIT License
35 stars 15 forks source link

"Connect failed: AMQJS0007E Socket error:undefined" with HiveMQ client #24

Closed ronschaeffer closed 5 years ago

ronschaeffer commented 5 years ago

Problem/Motivation

Receive "Connect failed: AMQJS0007E Socket error:undefined" error when trying to connect to Community Add on MQTT broker through built-in HiveMQ client from all browsers (tried Chrome, Opera and Edge).

Issues #6 and #12 are about the same error message, but neither was actually resolved. One submitter stopped using Hassio while the other managed to connect finally "without changing anything". Both issues are closed.

Expected behavior

HiveMQ client connection to add on broker.

Actual behavior

Connction fails with error message as above.

Steps to reproduce

Fresh install of add on. MQTT broker works and I can see devices connecting to it in logs. Hassio integration set up via Configuration/Integration not configuration.yaml. Also tested with MQTT.fx connecting to same IP, port 4884 and with same user/pass. Works. calling mqtt.publish in Hassio also works.

Tried restarting Hassio a few times, restarting the add on and also restarting the Ubuntu host. Hassio is running in a Docker container on Ubuntu server 18.04.

HiveMQ page with error

image

Config

{
  "log_level": "info",
  "certfile": "fullchain.pem",
  "keyfile": "privkey.pem",
  "web": {
    "enabled": true,
    "ssl": true
  },
  "broker": {
    "enabled": true,
    "enable_ws": true,
    "enable_mqtt": true,
    "enable_ws_ssl": true,
    "enable_mqtt_ssl": true,
    "allow_anonymous": true
  },
  "mqttusers": [
    {
      "username": "x",
      "password": "x",
      "readonly": false,
      "topics": [
        "#"
      ]
    }
  ]
}

Port settings image

System info

image

Part of system log

19-02-13 11:24:37 INFO (MainThread) [hassio.auth] Auth request from a0d7b954_mqtt for xxxxxxxx
19-02-13 11:24:37 INFO (MainThread) [hassio.auth] Success login from xxxxxxxx

Add on log

[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] 00-banner.sh: executing... 

-----------------------------------------------------------
 Hass.io Add-on: MQTT Server & Web client v0.3.1

 Mosquitto MQTT Server bundled with Hivemq's web client

 From: Community Hass.io Add-ons
 By: Franck Nijhof <frenck@addons.community>
-----------------------------------------------------------
 amd64 / Ubuntu 18.04.1 LTS / HA 0.87.1 / SU 143 / stable
-----------------------------------------------------------
[cont-init.d] 00-banner.sh: exited 0.
[cont-init.d] 01-log-level.sh: executing... 
Log level is set to INFO
[cont-init.d] 01-log-level.sh: exited 0.
[cont-init.d] 02-updates.sh: executing... 

INFO: You are running the latest version of this add-on
[cont-init.d] 02-updates.sh: exited 0.
[cont-init.d] 10-requirements.sh: executing... 
[cont-init.d] 10-requirements.sh: exited 0.
[cont-init.d] 11-patches.sh: executing... 
patching file /app/index.html
[cont-init.d] 11-patches.sh: exited 0.
[cont-init.d] 20-mqtt_broker.sh: executing... 
INFO: Adding configuration for MQTT Server...
INFO: Setting configuration for websockets...
INFO: Setting configuration for mqtt...
[cont-init.d] 20-mqtt_broker.sh: exited 0.
[cont-init.d] 21-mqtt_web.sh: executing... 
[cont-init.d] 21-mqtt_web.sh: exited 0.
[cont-init.d] 40-nginx.sh: executing... 
[cont-init.d] 40-nginx.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
INFO: Starting mosquitto MQTT Server...
INFO: Starting NGINX for the MQTT client...
1550056408: mosquitto version 1.4.15 (build date 2018-03-04 15:14:46+0000) starting
1550056408: Config loaded from /opt/mosquitto.conf.
1550056408: Opening websockets listen socket on port 1884.
1550056408: Opening websockets listen socket on port 4884.
1550056408: Opening ipv4 listen socket on port 1883.
1550056408: Opening ipv6 listen socket on port 1883.
1550056408: Opening ipv4 listen socket on port 4883.
1550056408: Opening ipv6 listen socket on port 4883.
2019/02/13 11:13:28 [notice] 949#949: using the "epoll" event method
2019/02/13 11:13:28 [notice] 949#949: nginx/1.14.2
2019/02/13 11:13:28 [notice] 949#949: OS: Linux 4.15.0-45-generic
2019/02/13 11:13:28 [notice] 949#949: getrlimit(RLIMIT_NOFILE): 1048576:1048576
2019/02/13 11:13:28 [notice] 949#949: start worker processes
2019/02/13 11:13:28 [notice] 949#949: start worker process 1017
1550056451: New connection from 192.168.86.47 on port 4883.
1550056452: New client connected from 192.168.86.47 as MQTT_FX_Client3 (c1, k60, u'yyyyyyyyy').
2019/02/13 11:14:34 [info] 1017#1017: *1 client closed connection while waiting for request, client: 192.168.86.1, server: 0.0.0.0:5713
1550056524: New connection from 172.30.32.1 on port 1883.
1550056524: Socket error on client <unknown>, disconnecting.
1550056603: New connection from 172.30.32.1 on port 4883.
1550056603: OpenSSL Error: error:140260FC:SSL routines:ACCEPT_SR_CLNT_HELLO:unknown protocol
1550056603: Socket error on client <unknown>, disconnecting.
1550056604: New connection from 172.30.32.1 on port 4883.
1550056604: OpenSSL Error: error:140260FC:SSL routines:ACCEPT_SR_CLNT_HELLO:unknown protocol
1550056604: Socket error on client <unknown>, disconnecting.
1550056606: New connection from 172.30.32.1 on port 4883.
1550056606: OpenSSL Error: error:140260FC:SSL routines:ACCEPT_SR_CLNT_HELLO:unknown protocol
1550056606: Socket error on client <unknown>, disconnecting.
1550056622: New connection from 172.30.32.1 on port 1883.
1550056622: New client connected from 172.30.32.1 as 46WPq4OiinfEzt0wIqG0fQ (c1, k60, u'yyyyyyyyy').
1550056622: Client 46WPq4OiinfEzt0wIqG0fQ disconnected.
1550056654: New connection from 172.30.32.1 on port 1883.
1550056654: New client connected from 172.30.32.1 as e36c9553-5c44-4d72-8876-8ff69f0d15a2 (c1, k60, u'yyyyyyyyy').
2019/02/13 11:24:16 [info] 1017#1017: *5 client sent plain HTTP request to HTTPS port while reading client request headers, client: 192.168.86.1, server: _, request: "GET / HTTP/1.1", host: "yyyyyyyyy.duckdns.org:5713"
192.168.86.1 - - [13/Feb/2019:11:24:16 +0000] "GET / HTTP/1.1" 400 673 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - - [13/Feb/2019:11:24:23 +0000] "GET / HTTP/1.1" 401 29 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
2019/02/13 11:24:37 [info] 1017#1017: *4 client closed connection while SSL handshaking, client: 192.168.86.1, server: 0.0.0.0:5713
2019/02/13 11:24:37 [info] 1017#1017: *8 [lua] ha-auth.lua:59: authenticate(): Authenticated user against Home Assistant., client: 192.168.86.1, server: _, request: "GET / HTTP/1.1", host: "yyyyyyyyy.duckdns.org:5713"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET / HTTP/1.1" 200 14020 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /css/style.css HTTP/1.1" 200 5845 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /css/normalize.css HTTP/1.1" 200 7589 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /css/jquery.minicolors.css HTTP/1.1" 200 4557 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /assets/logo.png HTTP/1.1" 200 5386 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /js/jquery.minicolors.min.js HTTP/1.1" 200 11685 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /js/encoder.js HTTP/1.1" 200 13952 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /js/mqttws31.js HTTP/1.1" 200 82838 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /js/app.js HTTP/1.1" 200 12233 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /config.js HTTP/1.1" 200 44 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /css/foundation.css HTTP/1.1" 200 203133 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:37 +0000] "GET /assets/arrow_up.png HTTP/1.1" 200 271 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:38 +0000] "GET /assets/arrow_down.png HTTP/1.1" 200 268 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - xxxxxx [13/Feb/2019:11:24:38 +0000] "GET /assets/jquery.minicolors.png HTTP/1.1" 200 77459 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
192.168.86.1 - - [13/Feb/2019:11:24:39 +0000] "GET /favicon.ico HTTP/1.1" 401 29 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/18.17763"
2019/02/13 11:25:33 [info] 1017#1017: *13 client closed connection while waiting for request, client: 192.168.86.1, server: 0.0.0.0:5713
2019/02/13 11:25:34 [info] 1017#1017: *14 client closed connection while waiting for request, client: 192.168.86.1, server: 0.0.0.0:5713
192.168.86.1 - xxxxxx [13/Feb/2019:11:25:36 +0000] "GET / HTTP/1.1" 200 14020 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.86.1 - xxxxxx [13/Feb/2019:11:25:36 +0000] "GET /config.js HTTP/1.1" 200 44 "https://yyyyyyyyy.duckdns.org:5713/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
addons-assistant[bot] commented 5 years ago

:wave: Thanks for opening your first issue here! If you're reporting a :bug: bug, please make sure you include steps to reproduce it. Also, logs, error messages and information about your hardware might be usefull.

ronschaeffer commented 5 years ago

Well, as another submitter reported #6 , it spontaneously started working when I tried this morning. As with the other submitter, I have not changed anything. Any ideas as to why we've seen this behavior?

ludeeus commented 5 years ago

First of all, I think this is the best documented issue I have ever seen. 🏅

With your configuration I find it verry strange that you got it working (it should not). When you use SSL and port 4884 it should require a hostname to match with the certificate.

So the fact that you got that working with IP are confusing 🤷‍♂️

ronschaeffer commented 5 years ago

I'm using Caddy with a certificate from Let's Encrypt, both from Hassio add-ons. I'm pretty news to working with SSL.

Strangely, while the web client is still working via Chrome on my PC, I just discovered that it is not working via Chrome on my Android phone with the same settings and connected to the same network. It's throwing the same error as in my original post.

ludeeus commented 5 years ago

Can you put the DNS name in the Broker field? Or open the add-on with IP and http, ten use port 1884 and not checked the box for ssl

ronschaeffer commented 5 years ago

I can't open the client page with IP and http (not https). I get a 404 error.

BTW, this is the relevant entry in the Caddyfile. Don't know if that's relevant to the issue.

}

hivemqttt.xxxx.duckdns.org {
    proxy / localhost:5713 {
        websocket
        transparent
    }
}
ludeeus commented 5 years ago

to use it with http you need to disable ssl

  "web": {
    "enabled": true,
    "ssl": false
  }
ronschaeffer commented 5 years ago

@ludeeus Thanks for you help, but I decided to move away from the add-on and instead use a broker running in a docker container that I have direct control of. Fewer points of failure to check, I hope.

Shall I close this issue?

ludeeus commented 5 years ago

We can reopen it if you choose to come back :)

addons-assistant[bot] commented 5 years ago

This thread has been automatically locked because it has not had recent activity. Please open a new issue for related bugs and link to relevant comments in this thread.