This is obviously not getting any traction, so I’m going to write a long description of my setup and hopefully someone can spot something stupid that I’m doing. First a description of how I have the system setup and what happens in various circumstances:
Pertinent network parts:
It looks complex but isn’t really all that bad:
- All internet traffic to my domain.com port 443 is forwarded through the firewall to my web server - I have several services available on that port, and everything is fine.
- Apache running on my web server does the HTTPS part, and sees traffic for:
- The traffic then goes in to the docker instance on web.inside.domain.com/home.inside.domain.com and gets processed by the OpenHab-Cloud instance - the names ensure that the OpenHab-Cloud instance gets the appropriate “home.” leading domain part so it understands the difference between the two connection types.
- Return traffic is properly proxied back out to the internet connection.
For the most part this works fine. The OpenHabian server is just sitting on my internal network and works great with internal connections (and also with myopenhab.org cloud connection).
A bit about the OpenHab-Cloud instance I’m running:
- It was pulled directly from github.
- The .env file was updated reflect the DOMAIN_NAME as home.domain.com (and of course the EXPRESS_KEY was set).
- I’m not using Traefik, so I removed that part from the docker-compose.yml file.
- I had to comment out some stuff about Android notifications and Apple notifications in app.js because without them configured, I couldn’t get app.js to start. Very minimal modifications.
So, here we are, things should be working as best I can tell.
- Web client connection to ohc.domain.com gives me the login or register screen as expected.
- I can log in and register everything.
- Web client connection to home.domain.com asks for an authentication. Since I just went directly there, I assume things aren’t set up, so it just keeps snoopy people out.
So that’s the state of things before I actually TRY to get things working.
Now, I connect to my OpenHabian (Raspian?) and configure the OpenHAB cloud connector to connect to https://ohc.domain.com.
This is where things go south. The OpenHab server logs start getting the disconnections that I pointed out in my first post:
2021-03-20 16:08:29.362 [ERROR] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance
2021-03-20 16:08:29.364 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, base URL = http://localhost:8080)
2021-03-20 16:08:30.778 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, base URL = http://localhost:8080)
2021-03-20 16:08:40.786 [ERROR] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance
2021-03-20 16:08:40.788 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, base URL = http://localhost:8080)
2021-03-20 16:08:42.220 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, base URL = http://localhost:8080)
2021-03-20 16:08:52.227 [ERROR] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance
2021-03-20 16:08:52.229 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, base URL = http://localhost:8080)
2021-03-20 16:08:53.356 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, base URL = http://localhost:8080)
Every 10 seconds. [And what is that http://localhost:8080 about?? In the source code it doesn’t seem to use that for anything on either side]
I’ve trolled through the source code for the OpenHAB-cloud connector and it only seems to make one connection - to https://ohc.domain.com. It sends some “itemupdates” and those are processed by the openHAB-Cloud instance. It seems good, then it just gets a timeout on the OpenHAB cloud connector side.
I have a debug dump of the cloud logs:
app_1 | 2021-03-28T21:45:52.311Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:45:52.313Z engine handling "GET" http request "/socket.io/?EIO=3&transport=polling"
app_1 | 2021-03-28T21:45:52.319Z engine handshaking client "SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:45:52.321Z engine:socket sending packet "open" ({"sid":"SIDSIDSIDSIDSIDSIDSI","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":5000})
app_1 | 2021-03-28T21:45:52.322Z engine:polling setting request
app_1 | 2021-03-28T21:45:52.323Z engine:socket flushing buffer to transport
app_1 | 2021-03-28T21:45:52.326Z engine:polling writing "96:0{"sid":"SIDSIDSIDSIDSIDSIDSI","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":5000}"
app_1 | 2021-03-28T21:45:52.334Z engine:socket executing batch send callback
app_1 | 2021-03-28T21:45:52.334Z socket.io:server incoming connection with id SIDSIDSIDSIDSIDSIDSI
app_1 | 2021-03-28T21:45:52.335Z socket.io:client connecting to namespace /
app_1 | 2021-03-28T21:45:52.336Z socket.io:namespace adding socket to nsp /
app_1 | 2021-03-28T21:45:52.386Z mquery findOne openhabs {
app_1 | uuid: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx',
app_1 | secret: 'SECRETSECRETSECRETSE'
app_1 | } { projection: {} }
app_1 | 2021-03-28T21:45:52.406Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:45:52.407Z engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&sid=SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:45:52.408Z engine setting new request for existing client
app_1 | 2021-03-28T21:45:52.409Z engine:polling setting request
app_1 | 2021-03-28T21:45:52.436Z socket.io:socket socket connected - writing packet
app_1 | 2021-03-28T21:45:52.441Z socket.io:socket joining room SIDSIDSIDSIDSIDSIDSI
app_1 | 2021-03-28T21:45:52.442Z socket.io:client writing packet {"type":0,"nsp":"/"}
app_1 | 2021-03-28T21:45:52.442Z socket.io-parser encoding packet {"type":0,"nsp":"/"}
app_1 | 2021-03-28T21:45:52.442Z socket.io-parser encoded {"type":0,"nsp":"/"} as 0
app_1 | 2021-03-28T21:45:52.443Z engine:socket sending packet "message" (0)
app_1 | 2021-03-28T21:45:52.443Z engine:socket flushing buffer to transport
app_1 | 2021-03-28T21:45:52.444Z engine:polling writing "2:40"
app_1 | 2021-03-28T21:45:52.447Z socket.io:socket joining room xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
app_1 | 2021-03-28T21:45:52.448Z socket.io:socket joined room [ 'SIDSIDSIDSIDSIDSIDSI' ]
app_1 | 2021-03-28T21:45:52.450Z socket.io:socket joined room [ 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx' ]
app_1 | 2021-03-28T21:45:52.452Z mquery findOne openhabs { uuid: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx' } { projection: {} }
app_1 | 2021-03-28T21:45:52.457Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:45:52.458Z engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&sid=SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:45:52.458Z engine setting new request for existing client
app_1 | 2021-03-28T21:45:52.458Z engine:polling setting request
app_1 | 2021-03-28T21:45:52.459Z engine:socket executing batch send callback
app_1 | 2021-03-28T21:45:52.460Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:45:52.461Z engine handling "GET" http request "/socket.io/?EIO=3&transport=websocket&sid=SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:45:52.461Z engine bad request: unexpected transport without upgrade
app_1 | 2021-03-28T21:45:52.509Z mquery findOne openhabs { _id: IDIDIDIDIDIDIDIDIDIDIDID } { session: undefined, projection: { _id: 1 } }
app_1 | 2021-03-28 23:45:51:5151 info: openHAB-cloud: express server listening on port 3000
app_1 | 2021-03-28 23:45:52:5252 info: openHAB-cloud: Successfully connected to mongodb
app_1 | 2021-03-28 23:45:52:5252 info: openHAB-cloud: Redis connect response: OK
app_1 | 2021-03-28 23:45:52:5252 info: openHAB-cloud: Redis is ready
app_1 | 2021-03-28 23:45:52:5252 info: openHAB-cloud: Authorizing incoming openHAB connection
app_1 | 2021-03-28 23:45:52:5252 info: openHAB-cloud: Incoming openHAB connection for uuid xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
app_1 | 2021-03-28 23:45:52:5252 info: openHAB-cloud: Connected openHAB with xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx successfully
app_1 | 2021-03-28 23:45:52:5252 info: debug
app_1 | 2021-03-28 23:45:52:5252 info: openHAB-cloud: uuid xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx server address undefined:undefined my address undefined:undefined
app_1 | 2021-03-28 23:45:52:5252 info: *** 2 ***
app_1 | 2021-03-28T21:45:53.287Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:45:53.287Z engine handling "POST" http request "/socket.io/?EIO=3&transport=polling&sid=SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:45:53.287Z engine setting new request for existing client
app_1 | 2021-03-28T21:45:53.294Z engine:polling received "76:42["itemupdate",{"itemName":"TVRoomStereoLamp_Brightness","itemStatus":"0"}]"
app_1 | 2021-03-28T21:45:53.295Z engine:socket packet
app_1 | 2021-03-28T21:45:53.297Z socket.io-parser decoded 2["itemupdate",{"itemName":"TVRoomStereoLamp_Brightness","itemStatus":"0"}] as {"type":2,"nsp":"/","data":["itemupdate",{"itemName":"TVRoomStereoLamp_Brightness","itemStatus":"0"}]}
app_1 | 2021-03-28T21:45:53.300Z socket.io:socket got packet {"type":2,"nsp":"/","data":["itemupdate",{"itemName":"TVRoomStereoLamp_Brightness","itemStatus":"0"}]}
app_1 | 2021-03-28T21:45:53.300Z socket.io:socket emitting event ["itemupdate",{"itemName":"TVRoomStereoLamp_Brightness","itemStatus":"0"}]
app_1 | 2021-03-28T21:45:53.301Z socket.io:socket dispatching an event ["itemupdate",{"itemName":"TVRoomStereoLamp_Brightness","itemStatus":"0"}]
app_1 | 2021-03-28 23:45:53:5353 info: [object Object]
app_1 | 2021-03-28T21:45:53.305Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:45:53.305Z engine handling "POST" http request "/socket.io/?EIO=3&transport=polling&sid=SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:45:53.306Z engine setting new request for existing client
app_1 | 2021-03-28T21:45:53.307Z engine:polling received "73:42["itemupdate",{"itemName":"TVRoomStereoLamp_Power","itemStatus":"OFF"}]"
app_1 | 2021-03-28T21:45:53.308Z engine:socket packet
app_1 | 2021-03-28T21:45:53.309Z socket.io-parser decoded 2["itemupdate",{"itemName":"TVRoomStereoLamp_Power","itemStatus":"OFF"}] as {"type":2,"nsp":"/","data":["itemupdate",{"itemName":"TVRoomStereoLamp_Power","itemStatus":"OFF"}]}
app_1 | 2021-03-28T21:45:53.310Z socket.io:socket got packet {"type":2,"nsp":"/","data":["itemupdate",{"itemName":"TVRoomStereoLamp_Power","itemStatus":"OFF"}]}
app_1 | 2021-03-28T21:45:53.311Z socket.io:socket emitting event ["itemupdate",{"itemName":"TVRoomStereoLamp_Power","itemStatus":"OFF"}]
app_1 | 2021-03-28T21:45:53.312Z socket.io:socket dispatching an event ["itemupdate",{"itemName":"TVRoomStereoLamp_Power","itemStatus":"OFF"}]
app_1 | 2021-03-28 23:45:53:5353 info: [object Object]
app_1 | 2021-03-28T21:46:02.290Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:46:02.291Z engine handling "POST" http request "/socket.io/?EIO=3&transport=polling&sid=SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:46:02.292Z engine setting new request for existing client
app_1 | 2021-03-28T21:46:02.293Z engine:polling received "71:42["itemupdate",{"itemName":"OutsideLights_Switch","itemStatus":"OFF"}]"
app_1 | 2021-03-28T21:46:02.293Z engine:socket packet
app_1 | 2021-03-28T21:46:02.294Z socket.io-parser decoded 2["itemupdate",{"itemName":"OutsideLights_Switch","itemStatus":"OFF"}] as {"type":2,"nsp":"/","data":["itemupdate",{"itemName":"OutsideLights_Switch","itemStatus":"OFF"}]}
app_1 | 2021-03-28T21:46:02.295Z socket.io:socket got packet {"type":2,"nsp":"/","data":["itemupdate",{"itemName":"OutsideLights_Switch","itemStatus":"OFF"}]}
app_1 | 2021-03-28T21:46:02.296Z socket.io:socket emitting event ["itemupdate",{"itemName":"OutsideLights_Switch","itemStatus":"OFF"}]
app_1 | 2021-03-28T21:46:02.296Z socket.io:socket dispatching an event ["itemupdate",{"itemName":"OutsideLights_Switch","itemStatus":"OFF"}]
app_1 | 2021-03-28 23:46:02:022 info: [object Object]
app_1 | 2021-03-28T21:46:02.468Z engine intercepting request for path "/socket.io/"
app_1 | 2021-03-28T21:46:02.469Z engine handling "POST" http request "/socket.io/?EIO=3&transport=polling&sid=SIDSIDSIDSIDSIDSIDSI"
app_1 | 2021-03-28T21:46:02.470Z engine setting new request for existing client
app_1 | 2021-03-28T21:46:02.471Z engine:polling received "1:1"
app_1 | 2021-03-28T21:46:02.471Z engine:polling got xhr close packet
app_1 | 2021-03-28T21:46:02.472Z engine:polling writing "1:6"
app_1 | 2021-03-28T21:46:02.476Z socket.io:client client close with reason transport close
app_1 | 2021-03-28T21:46:02.477Z socket.io:socket closing socket - reason transport close
app_1 | 2021-03-28T21:46:02.481Z mquery findOne openhabs { _id: IDIDIDIDIDIDIDIDIDIDIDID } { projection: {} }
app_1 | 2021-03-28 23:46:02:022 info: openHAB-cloud: Disconnected xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
Surely someone can see something I can’t or I don’t understand. If I get it correctly, connections to the cloud server from a domain that is NOT “home." should route to the login/registration stuff, and connections to the cloud server from a "home.” domain should be routed to the openHab server – somehow…I assume through the connection it made with cloud server.
What else can I say? If anyone has ANY ideas, please comment.
Addendum:
I tore everything down and rebuilt it (on the cloud server side), and the connection still drops and reconnects just like before, but my openhab server is marked as online. Clicking to view my dashboard now asks me to log in using basic authentication (browser authentication dialog)…it doesn’t accept any name/password that I understand. Why does THAT happen?