Coming back to a problem similar to what user fanavity had.
Originally I had the RPi and two gateways connected to a spare Fritzbox wifi router, and my OH definition & rules worked OK.
Now I moved to the intended network setup and nothing works anymore. From what I can tell it looks like an issue with the binding or OH:
I loaded the RPi3 with a fresh Openhabian image. The RPi is connected to my wired Ethernet and has internet access.
The Openhabian image was flashed today and I did only the modifications listed below.
I followed this guide to set up a hotspot (less IP forwarding):
Hotspot using Stretch
I switched off wifi power save mode, and configured DHCP to provide fixed IPs to the Xiaomi gateways.
Overall this is working well: I can connect to the RPi from my laptop using the RPi hotspot or using my wired Ethernet. The RPi has internet access, but devices connected to the hotspot are isolated from the internet (no IP forwarding). The Xiaomi gateways connect to the hotspot, and I can ping both successfully from the RPi.
Except the Xiaomi gateway discovery doesn’t work, and things / items are never updated.
I think its a binding / OH issue, and here is the reason why:
This is what happens when doing a Xiaomi discovery with Ethernet plugged in:
2018-02-12 20:03:58.313 [DEBUG] [nternal.socket.XiaomiDiscoverySocket] - Setup discovery socket
2018-02-12 20:03:58.319 [DEBUG] [nternal.socket.XiaomiDiscoverySocket] - Initialized socket to null:-1 on 0.0.0.0/0.0.0.0:37063
2018-02-12 20:03:58.327 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - There are 1 open sockets: {37063=java.net.DatagramSocket@189230f}
2018-02-12 20:03:58.334 [DEBUG] [scovery.XiaomiBridgeDiscoveryService] - Start scan for bridges
2018-02-12 20:04:08.316 [DEBUG] [scovery.XiaomiBridgeDiscoveryService] - Stop scan
2018-02-12 20:04:08.320 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Interrupting Thread Thread[Thread-84,5,main]
2018-02-12 20:04:08.322 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Closing socket java.net.DatagramSocket@189230f
2018-02-12 20:04:08.328 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Receiver thread ended
No Xiaomi Gateway Bridge is discovered.
If I unplug the Ethernet cable and repeat the discovery I get an error in the log:
2018-02-12 21:19:37.447 [DEBUG] [scovery.XiaomiBridgeDiscoveryService] - Stop scan
2018-02-12 21:19:37.468 [DEBUG] [nternal.socket.XiaomiDiscoverySocket] - Setup discovery socket
2018-02-12 21:19:37.472 [DEBUG] [nternal.socket.XiaomiDiscoverySocket] - Initialized socket to null:-1 on 0.0.0.0/0.0.0.0:59893
2018-02-12 21:19:37.491 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - There are 1 open sockets: {59893=java.net.DatagramSocket@1cc699b}
2018-02-12 21:19:37.495 [DEBUG] [scovery.XiaomiBridgeDiscoveryService] - Start scan for bridges
2018-02-12 21:19:37.503 [ERROR] [.mihome.internal.socket.XiaomiSocket] - Sending error
java.io.IOException: Network is unreachable (sendto failed)
at java.net.PlainDatagramSocketImpl.send(Native Method) ~[?:?]
at java.net.DatagramSocket.send(DatagramSocket.java:693) [?:?]
at org.openhab.binding.mihome.internal.socket.XiaomiSocket.sendMessage(XiaomiSocket.java:146) [202:org.openhab.binding.mihome:2.2.0]
at org.openhab.binding.mihome.internal.socket.XiaomiDiscoverySocket.sendMessage(XiaomiDiscoverySocket.java:64) [202:org.openhab.binding.mihome:2.2.0]
at org.openhab.binding.mihome.internal.discovery.XiaomiBridgeDiscoveryService.discoverGateways(XiaomiBridgeDiscoveryService.java:99) [202:org.openhab.binding.mihome:2.2.0]
at org.openhab.binding.mihome.internal.discovery.XiaomiBridgeDiscoveryService.startScan(XiaomiBridgeDiscoveryService.java:64) [202:org.openhab.binding.mihome:2.2.0]
at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.startScan(AbstractDiscoveryService.java:222) [104:org.eclipse.smarthome.config.discovery:0.10.0.b1]
[snip]
So to me it seems like the binding just looks for the gateway on the wired interface. If its present, it can’t find anything (because the gateways are on the wireless interface). If the wired interface is offline, it gives an error.
Now if I add the gateway thing manually to the Inbox the binding successfully identifies the gateway, and populates the Inbox with things for all sub-devices that are assigned to it. If I approve any sub-device thing in the inbox it shows up as “online” in the configuration section. But things and items receive no updates afterwards.
Here is the log for adding a gateway manually with wired Ethernet connected:
2018-02-12 20:05:51.819 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Having 1 Item Discovery listeners
2018-02-12 20:05:51.832 [DEBUG] [org.openhab.binding.mihome ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=311, service.bundleid=202, service.scope=singleton} - org.openhab.binding.mihome
2018-02-12 20:05:51.850 [DEBUG] [org.openhab.binding.mihome ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=312, service.bundleid=202, service.scope=singleton} - org.openhab.binding.mihome
2018-02-12 20:05:51.876 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Init socket on Port: 9898
2018-02-12 20:05:51.881 [DEBUG] [e.internal.socket.XiaomiBridgeSocket] - Setup socket
2018-02-12 20:05:51.884 [DEBUG] [e.internal.socket.XiaomiBridgeSocket] - Initialized socket to null:-1 on 0.0.0.0/0.0.0.0:9898
2018-02-12 20:05:51.889 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - There are 1 open sockets: {9898=java.net.MulticastSocket@1e364cf}
2018-02-12 20:05:52.895 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Triggered discovery
2018-02-12 20:05:52.899 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "get_id_list"}
2018-02-12 20:05:52.909 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
2018-02-12 20:05:52.918 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001dbb7a0"}
2018-02-12 20:05:52.922 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001aad1ee"}
2018-02-12 20:05:52.925 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d000123df02"}
2018-02-12 20:05:52.928 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001b14454"}
2018-02-12 20:05:52.931 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001dbcc8c"}
2018-02-12 20:05:52.935 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001ab403e"}
2018-02-12 20:05:52.938 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001d6f8ab"}
2018-02-12 20:05:52.941 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d00016d8e28"}
2018-02-12 20:05:52.947 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d000123df47"}
2018-02-12 20:05:52.950 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001e46332"}
2018-02-12 20:05:52.954 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read", "sid": "158d0001de92cf"}
2018-02-12 20:05:52.964 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:74f76698: {"cmd": "read"}
2018-02-12 20:05:52.968 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
2018-02-12 20:05:52.978 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Device 158d0001dbb7a0 honored read request
2018-02-12 20:05:52.984 [DEBUG] [discovery.XiaomiItemDiscoveryService] - Detected Xiaomi smart device - sid: 158d0001dbb7a0 model: sensor_magnet.aq2
2018-02-12 20:05:52.991 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'mihome:sensor_magnet_aq2:158d0001dbb7a0' to inbox.
2018-02-12 20:05:52.994 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
2018-02-12 20:05:52.997 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Device 158d0001aad1ee honored read request
2018-02-12 20:05:53.004 [DEBUG] [discovery.XiaomiItemDiscoveryService] - Detected Xiaomi smart device - sid: 158d0001aad1ee model: sensor_magnet.aq2
2018-02-12 20:05:53.011 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'mihome:sensor_magnet_aq2:158d0001aad1ee' to inbox.
2018-02-12 20:05:53.024 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
Adding the gateway manually works the same way with Ethernet connected or disconnected. With the Ethernet unplugged it shows an error in the log, but works just the same.
Here is the same log for adding the gateway with the Ethernet disconnected. Note the “socket error”
2018-02-12 21:21:55.360 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Having 1 Item Discovery listeners
2018-02-12 21:21:55.365 [DEBUG] [org.openhab.binding.mihome ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=307, service.bundleid=202, service.scope=singleton} - org.openhab.binding.mihome
2018-02-12 21:21:55.379 [DEBUG] [org.openhab.binding.mihome ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=308, service.bundleid=202, service.scope=singleton} - org.openhab.binding.mihome
2018-02-12 21:21:55.411 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Init socket on Port: 9898
2018-02-12 21:21:55.415 [DEBUG] [e.internal.socket.XiaomiBridgeSocket] - Setup socket
2018-02-12 21:21:55.418 [ERROR] [e.internal.socket.XiaomiBridgeSocket] - Setup socket error
java.net.SocketException: No such device
at java.net.PlainDatagramSocketImpl.join(Native Method) ~[?:?]
at java.net.AbstractPlainDatagramSocketImpl.join(AbstractPlainDatagramSocketImpl.java:178) [?:?]
at java.net.MulticastSocket.joinGroup(MulticastSocket.java:323) [?:?]
at org.openhab.binding.mihome.internal.socket.XiaomiBridgeSocket.setupSocket(XiaomiBridgeSocket.java:47) [202:org.openhab.binding.mihome:2.2.0]
at org.openhab.binding.mihome.internal.socket.XiaomiSocket.intialize(XiaomiSocket.java:71) [202:org.openhab.binding.mihome:2.2.0]
at org.openhab.binding.mihome.handler.XiaomiBridgeHandler.initialize(XiaomiBridgeHandler.java:101) [202:org.openhab.binding.mihome:2.2.0]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [109:org.eclipse.smarthome.core:0.10.0.b1]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [109:org.eclipse.smarthome.core:0.10.0.b1]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
2018-02-12 21:21:55.422 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - There are 1 open sockets: {9898=java.net.MulticastSocket@1d5a774}
2018-02-12 21:21:56.430 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Triggered discovery
2018-02-12 21:21:56.436 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "get_id_list"}
2018-02-12 21:21:56.845 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
2018-02-12 21:21:56.857 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001dbb7a0"}
2018-02-12 21:21:56.864 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001aad1ee"}
2018-02-12 21:21:56.867 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d000123df02"}
2018-02-12 21:21:56.871 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001b14454"}
2018-02-12 21:21:56.875 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001dbcc8c"}
2018-02-12 21:21:56.879 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001ab403e"}
2018-02-12 21:21:56.882 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001d6f8ab"}
2018-02-12 21:21:56.886 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d00016d8e28"}
2018-02-12 21:21:56.889 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d000123df47"}
2018-02-12 21:21:56.893 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001e46332"}
2018-02-12 21:21:56.896 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read", "sid": "158d0001de92cf"}
2018-02-12 21:21:56.900 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Send to bridge mihome:bridge:f9d9e331: {"cmd": "read"}
2018-02-12 21:21:56.904 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
2018-02-12 21:21:56.909 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Device 158d0001dbb7a0 honored read request
2018-02-12 21:21:56.921 [DEBUG] [discovery.XiaomiItemDiscoveryService] - Detected Xiaomi smart device - sid: 158d0001dbb7a0 model: sensor_magnet.aq2
2018-02-12 21:21:56.970 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'mihome:sensor_magnet_aq2:158d0001dbb7a0' to inbox.
2018-02-12 21:21:56.978 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
2018-02-12 21:21:56.983 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Device 158d0001aad1ee honored read request
2018-02-12 21:21:56.987 [DEBUG] [discovery.XiaomiItemDiscoveryService] - Detected Xiaomi smart device - sid: 158d0001aad1ee model: sensor_magnet.aq2
2018-02-12 21:21:56.994 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'mihome:sensor_magnet_aq2:158d0001aad1ee' to inbox.
2018-02-12 21:21:56.999 [DEBUG] [.mihome.internal.socket.XiaomiSocket] - Received Datagram from 192.168.188.21:9898 on Port 9898
2018-02-12 21:21:57.001 [DEBUG] [g.mihome.handler.XiaomiBridgeHandler] - Device 158d000123df02 honored read request
This is followed by more similar lines for each device attached to this particular gateway.
But there are no further debug messages from the binding. Total silence, no interaction between the binding and the gateway, and no heartbeats.
With the previous setup (RPi and gateways connected to a router) the logs showed gateway heartbets coming in every ten seconds.
To confirm that the RPi actually receives the gateway heartbeats I checked with tcpdump. Tcpdump shows the 10s heartbeats of the two gateways (and additional traffic if I trigger a switch, cube or window contact):
20:15:53.761206 IP 192.168.188.22.54321 > 120.92.96.242.8053: UDP, length 32
20:15:54.292927 IP 192.168.188.21.4321 > 224.0.0.50.9898: UDP, length 137
20:15:54.293722 IP 192.168.188.22.9898 > 192.168.188.21.4321: UDP, length 79
20:15:54.983528 IP 192.168.188.22.4321 > 224.0.0.50.9898: UDP, length 137
20:15:54.983856 IP 192.168.188.21.9898 > 192.168.188.22.4321: UDP, length 79
20:15:55.757146 IP 192.168.188.22.54321 > 120.92.96.242.8053: UDP, length 32
20:15:57.753925 IP 192.168.188.22.54321 > 120.92.96.242.8053: UDP, length 32
20:15:59.753133 IP 192.168.188.22.49153 > 192.168.188.1.53: 0+ A? ott.io.mi.com. (31)
20:15:59.753612 IP 192.168.188.1.53 > 192.168.188.22.49153: 0 6/0/0 A 58.83.160.36, A 58.83.160.14, A 42.62.94.185, A 120.92.96.88, A 124.243.204.138, A 120.92.96.87 (127)
20:16:04.272325 IP 192.168.188.21.4321 > 224.0.0.50.9898: UDP, length 137
20:16:04.273887 IP 192.168.188.22.9898 > 192.168.188.21.4321: UDP, length 79
20:16:04.963219 IP 192.168.188.22.4321 > 224.0.0.50.9898: UDP, length 137
20:16:04.964161 IP 192.168.188.21.9898 > 192.168.188.22.4321: UDP, length 79
So RPi receives the heartbeats, but OH / binding doesn’t process them.
I am no network or linux expert, but to me it seems this is an issue with the binding or OH itself. Maybe its just missing a configuration to tell the binding which interface to use or so.
Any idea??
EDIT: I did another test: My laptop and both gateways connected to the RPi’s hotspot. OH running on the laptop can discover the gateways and receive heartbeats & data, but OH on RPi can’t.