Hello everyone,
I’m currently running the latest version of the MySensors binding on a fresh install of Openhab 2.5.1 on RaspberryPi.
At the moment I am using a serial gateway (arduino pro mini 3.3v 8MHz w/ RFM69HW) connected through the RPi GPIO with one remote MySensors node for testing. The nodes can successfully communicate with each other and the serial gateway can successfully pass its messages onto Openhab, however the received messages do not update the appropriate channels or items.
My setup uses a gateway programmed with standard MySensors GatewaySerial sketch, modified to use the RFM69HW and operate at 38.4k baud rate, with one node (childID=7) with a BMP180 which sends the temperature and pressure every 10 seconds.
My Openhab is configured with the following Things / Items / Sitemap information:
//Things file
Bridge mysensors:bridge-ser:MyGW [ serialPort="/dev/ttyAMA0", sendDelay=200, baudRate=38400, networkSanCheckEnabled=true] {
temperature N007C001 [ nodeId=7, childId=1 ]
baro N007C002 [ nodeId=7, childId=2 ]
}
//Items file
Number myTemp "Temperature" { channel="mysensors:temperature:MyGW:N007C001:temp" }
Number myBaro "Pressure" { channel="mysensors:baro:MyGW:N007C002:baro" }
DateTime myBaro_lastupdate "Last Update" { channel="mysensors:baro:MyGW:N007C002:lastupdate" }
//Sitemap
sitemap default label="490AL" {
Text item=myTemp
Text item=myBaro
Text item=myBaro_lastupdate
}
The log files give the following:
2020-02-16 14:36:41.797 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysensors.items'
2020-02-16 14:36:42.508 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
2020-02-16 14:36:43.595 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'
2020-02-16 14:36:44.006 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysensors.things'
2020-02-16 14:36:47.909 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2020-02-16 14:36:50.776 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://10.0.0.3:8080
2020-02-16 14:36:50.778 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://10.0.0.3:8443
2020-02-16 14:36:57.427 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2020-02-16 14:36:57.755 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2020-02-16 14:36:57.994 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2020-02-16 14:36:59.226 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge
==> /var/log/openhab2/events.log <==
2020-02-16 14:36:59.206 [hingStatusInfoChangedEvent] - 'mysensors:bridge-ser:MyGW' changed from UNINITIALIZED to INITIALIZING
==> /var/log/openhab2/openhab.log <==
2020-02-16 14:36:59.312 [DEBUG] [ensors.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist.
2020-02-16 14:36:59.316 [DEBUG] [ensors.factory.MySensorsCacheFactory] - Cache (given_ids) content: [0, 21, 7]
2020-02-16 14:36:59.347 [DEBUG] [col.serial.MySensorsSerialConnection] - Enabling connection watchdog
2020-02-16 14:36:59.354 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to /dev/ttyAMA0 [baudRate:38400]
2020-02-16 14:36:59.359 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.mysensors.handler.MySensorsBridgeHandler@32c9fe': bundleContext
java.lang.NoSuchFieldError: bundleContext
at org.openhab.binding.mysensors.handler.MySensorsBridgeHandler.registerDeviceDiscoveryService(MySensorsBridgeHandler.java:216) ~[?:?]
at org.openhab.binding.mysensors.handler.MySensorsBridgeHandler.initialize(MySensorsBridgeHandler.java:86) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_222]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_222]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-02-16 14:36:59.395 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'mysensors:bridge-ser:MyGW': bundleContext
java.lang.NoSuchFieldError: bundleContext
at org.openhab.binding.mysensors.handler.MySensorsBridgeHandler.registerDeviceDiscoveryService(MySensorsBridgeHandler.java:216) ~[?:?]
at org.openhab.binding.mysensors.handler.MySensorsBridgeHandler.initialize(MySensorsBridgeHandler.java:86) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_222]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_222]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-02-16 14:36:59.431 [DEBUG] [col.serial.MySensorsSerialConnection] - Serial port event listener started
2020-02-16 14:36:59.433 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port.
2020-02-16 14:36:59.458 [DEBUG] [rsAbstractConnection$MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
2020-02-16 14:36:59.472 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;2;2.3.2
2020-02-16 14:36:59.477 [DEBUG] [rsAbstractConnection$MySensorsReader] - Good,Gateway is up and running! (Ver:2.3.2)
2020-02-16 14:36:59.518 [DEBUG] [ensors.factory.MySensorsCacheFactory] - Writing on cache given_ids, content: [0,21,7]
2020-02-16 14:36:59.524 [INFO ] [col.serial.MySensorsSerialConnection] - Successfully connected to MySensors Bridge.
==> /var/log/openhab2/events.log <==
2020-02-16 14:36:59.396 [hingStatusInfoChangedEvent] - 'mysensors:bridge-ser:MyGW' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR): bundleContext
2020-02-16 14:36:59.407 [hingStatusInfoChangedEvent] - 'mysensors:temperature:MyGW:N007C001' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2020-02-16 14:36:59.411 [hingStatusInfoChangedEvent] - 'mysensors:baro:MyGW:N007C002' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2020-02-16 14:36:59.501 [hingStatusInfoChangedEvent] - 'mysensors:bridge-ser:MyGW' changed from UNINITIALIZED (HANDLER_INITIALIZING_ERROR): bundleContext to ONLINE
==> /var/log/openhab2/openhab.log <==
2020-02-16 14:37:04.755 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9036793 TSF:MSG:READ,7-7-0,s=1,c=1,t=0,pt=7,l=5,sg=0:23.5
2020-02-16 14:37:04.760 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;1;1;0;0;23.5
2020-02-16 14:37:04.763 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:37:04.766 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 1 not present in node 7
2020-02-16 14:37:04.973 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9037010 TSF:MSG:READ,7-7-0,s=2,c=1,t=4,pt=7,l=5,sg=0:100770.0
2020-02-16 14:37:04.977 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;2;1;0;4;100770.0
2020-02-16 14:37:04.979 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:37:04.980 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 2 not present in node 7
2020-02-16 14:37:14.957 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9046990 TSF:MSG:READ,7-7-0,s=1,c=1,t=0,pt=7,l=5,sg=0:23.5
2020-02-16 14:37:14.962 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;1;1;0;0;23.5
2020-02-16 14:37:14.964 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:37:14.968 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 1 not present in node 7
2020-02-16 14:37:15.010 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9047042 TSF:MSG:READ,7-7-0,s=2,c=1,t=4,pt=7,l=5,sg=0:100767.0
2020-02-16 14:37:15.015 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;2;1;0;4;100767.0
2020-02-16 14:37:15.017 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:37:15.020 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 2 not present in node 7
// ...this repeated until sensor node was manually restarted...
2020-02-16 14:38:44.864 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9136855 TSF:MSG:READ,7-7-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
2020-02-16 14:38:44.872 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9136873 TSF:MSG:BC
2020-02-16 14:38:44.883 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9136881 TSF:MSG:FPAR REQ,ID=7
2020-02-16 14:38:44.894 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9136893 TSF:PNG:SEND,TO=0
2020-02-16 14:38:44.903 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9136904 TSF:CKU:OK
2020-02-16 14:38:44.911 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9136912 TSF:MSG:GWL OK
2020-02-16 14:38:45.734 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9137721 TSF:MSG:SEND,0-0-7-7,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
2020-02-16 14:38:46.872 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9138862 TSF:MSG:READ,7-7-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
2020-02-16 14:38:46.884 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9138880 TSF:MSG:PINGED,ID=7,HP=1
2020-02-16 14:38:47.119 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139105 TSF:MSG:SEND,0-0-7-7,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
2020-02-16 14:38:47.142 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139132 TSF:MSG:READ,7-7-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2020-02-16 14:38:47.378 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139363 TSF:MSG:SEND,0-0-7-7,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
2020-02-16 14:38:47.403 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139390 TSF:MSG:READ,7-7-0,s=255,c=0,t=17,pt=0,l=5,sg=0:2.3.2
2020-02-16 14:38:47.408 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;255;0;0;17;2.3.2
2020-02-16 14:38:47.410 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Presentation Message received
2020-02-16 14:38:47.423 [DEBUG] [ensors.factory.MySensorsCacheFactory] - Writing on cache given_ids, content: [0,21,7]
2020-02-16 14:38:47.435 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139425 TSF:MSG:READ,7-7-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
2020-02-16 14:38:47.440 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;255;3;0;6;0
2020-02-16 14:38:47.442 [DEBUG] [rs.internal.gateway.MySensorsGateway] - I_CONFIG request received from M, answering: (is imperial?)false
2020-02-16 14:38:47.446 [DEBUG] [rsAbstractConnection$MySensorsWriter] - Sending to MySensors: 7;255;3;0;6;M
2020-02-16 14:38:47.483 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139470 TSF:MSG:SEND,0-0-7-7,s=255,c=3,t=6,pt=0,l=1,sg=0,ft=0,st=OK:M
2020-02-16 14:38:47.509 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139496 TSF:MSG:READ,7-7-0,s=255,c=3,t=11,pt=0,l=10,sg=0:BMP180Node
2020-02-16 14:38:47.522 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;255;3;0;11;BMP180Node
2020-02-16 14:38:47.540 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139531 TSF:MSG:READ,7-7-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
2020-02-16 14:38:47.552 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;255;3;0;12;1.0
2020-02-16 14:38:47.615 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139603 TSF:MSG:READ,7-7-0,s=1,c=0,t=6,pt=0,l=11,sg=0:BMP180 Temp
2020-02-16 14:38:47.621 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;1;0;0;6;BMP180 Temp
2020-02-16 14:38:47.623 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Presentation Message received
2020-02-16 14:38:47.628 [DEBUG] [ensors.factory.MySensorsCacheFactory] - Writing on cache given_ids, content: [0,21,7]
2020-02-16 14:38:47.666 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139654 TSF:MSG:READ,7-7-0,s=2,c=0,t=8,pt=0,l=11,sg=0:BMP180 Baro
2020-02-16 14:38:47.672 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;2;0;0;8;BMP180 Baro
2020-02-16 14:38:47.674 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Presentation Message received
2020-02-16 14:38:47.679 [DEBUG] [ensors.factory.MySensorsCacheFactory] - Writing on cache given_ids, content: [0,21,7]
2020-02-16 14:38:47.710 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139701 TSF:MSG:READ,7-7-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
2020-02-16 14:38:47.942 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9139929 TSF:MSG:SEND,0-0-7-7,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1
2020-02-16 14:38:50.230 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9142218 TSF:MSG:READ,7-7-0,s=1,c=1,t=0,pt=7,l=5,sg=0:23.4
2020-02-16 14:38:50.234 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;1;1;0;0;23.4
2020-02-16 14:38:50.237 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:38:50.239 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 1 found in node 7
2020-02-16 14:38:50.282 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9142267 TSF:MSG:READ,7-7-0,s=2,c=1,t=4,pt=7,l=5,sg=0:100761.0
2020-02-16 14:38:50.286 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;2;1;0;4;100761.0
2020-02-16 14:38:50.289 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:38:50.291 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 2 found in node 7
2020-02-16 14:39:00.265 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9152247 TSF:MSG:READ,7-7-0,s=1,c=1,t=0,pt=7,l=5,sg=0:23.4
2020-02-16 14:39:00.269 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;1;1;0;0;23.4
2020-02-16 14:39:00.273 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:39:00.276 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 1 found in node 7
2020-02-16 14:39:00.337 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;9152317 TSF:MSG:READ,7-7-0,s=2,c=1,t=4,pt=7,l=5,sg=0:100762.0
2020-02-16 14:39:00.341 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 7;2;1;0;4;100762.0
2020-02-16 14:39:00.344 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 7 found in gateway
2020-02-16 14:39:00.346 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 2 found in node 7
// ...this repeats indefinitely...
From this I conclude that the messages are successfully received by the gateway and read by openhab. Openhab confirms it has been received but does not pass the data onto the associated channel or item. But I cannot figure out why…
I searched both the forum but could not find anyone with a similar problem… does anyone have any insight?
I have considered migrating to an arduino-less gateway (RFM69 directly into GPIO of the RPi) but I do not think this is the source of the problem (my arduino hat for the RPi was already ready from a previous project).
Any help would be appreciated.
Thanks and regards,
ThkUF