Firstly, thank you for your help, and apologies for my very naive question.
I’m very new to OpenHAB and have just completed my first installation via docker, as well as config for HTTPS and HTACCESS thanks to all the great forum posts on those topics.
Now that I have OpenHAB up and running, I wanted to try out the new Zigbee OnOff Module I bought off ebay. I added the ZigBee binding which found both my ZigBee USB dongle, and a Zigbee on/off controller module switch I installed between a light and power. I was able to get OpenHAB to bind to my zigbee switch via the Telegesis USB Device (ZigBee USB dongle) attached to my computer. What I can’t get it to do is to turn the light on or off! I’m sure I’m doing something simple wrong. When I go to the control panel, I can see the switch, and there is a toggle there which appears to have no effect on the actual light. Should it? I can connect to OpenHAB via the app on my phone and I see the switch there too, but still it doesn’t change the state of the switch.
Is there a channel that I need to add to the switch to control it’s actions? It does have a ‘Channel’ called ‘Switch’ and the blue circle is filled in, which I believe means that the channel is ‘active’. Is it that the OnOff Module I bought is defective? Are there any log files I could look at to see what is happening under the hood?
To verify that it wasn’t my OpenHAB installation, I also added a sonos speaker to OpenHAB. I’m able to control the speaker well from OpenHAB, adjusting the volume up and down, pausing a restarting the music, viewing the coverart etc.
Thanks in advance for your help.
Edit: when I use the app and turn it off,when I back up to the main screen and go back to the switch it shows as ‘on’ again. Hoping this additional info may help…
Can you please have a look in your log file and share more information
You can see the log files on two ways: (I prefere the first one)
Login to the karaf console: Open a ssh conenction and connect to port 8101 of your openhab server. Or if you run this as docker, exec the docker and connect to localhost:8101 the user is openhab. When you are logged in type the following command “log:display” to see the last messages.
Open the log files that are located under /etc/openhab/userdata/logs
Thank you very much for pointing me in the right direction!
It took me a minute to figure out how to open the console from inside a docker as the standard openhab docker image doesn’t include ssh and I didn’t want to install ssh + dependencies for just this purpose. For others’ future reference the following commands worked to access the karaf console:
Here’s the log requested; not much interesting stuff here but I captured a day’s worth of events. You can see at the end, I told openHAB to turn that switch on & off a couple times.
Also, as I was figuring out how to connect, I read in the docker documentation that I needed to chmod my USB device from rw-rw---- to rw-rw-rw- with chmod o+rw /dev/ttyUSB0. I did that, but it didn’t seem to have any effect.
00:17:00.588 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
00:51:58.714 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
02:51:58.645 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
03:21:59.579 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
07:17:00.207 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
07:51:59.614 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
09:47:00.338 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
10:16:58.913 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
10:45:52.547 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_control changed from PAUSE to PLAY
10:45:53.504 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_control changed from PLAY to PAUSE
10:45:53.637 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_control changed from PAUSE to PLAY
11:16:13.888 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_control changed from PLAY to PAUSE
11:16:34.229 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_control changed from PAUSE to PLAY
11:16:46.916 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 24 to 25
11:16:47.332 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 25 to 26
11:16:48.725 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 26 to 27
11:16:49.234 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 27 to 28
11:16:49.474 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 28 to 31
11:16:49.747 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 31 to 29
11:38:54.378 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 29 to 30
12:02:32.545 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 30 to 27
12:02:37.643 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_volume changed from 27 to 17
13:04:17.155 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_control changed from PLAY to PAUSE
13:39:00.012 [INFO ] [smarthome.event.ItemStateChangedEvent] - sonos_One_RINCON_7828CA05E05A01400_control changed from PAUSE to PLAY
14:17:00.277 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
14:52:00.845 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
16:31:58.881 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
16:42:00.670 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
16:46:59.759 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
17:21:59.716 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zigbee:coordinator_telegesis:04000E62’ has been updated.
18:09:19.250 [INFO ] [smarthome.event.InboxRemovedEvent ] - Discovery Result with UID ‘sonos:PLAY5:RINCON_949F3E51972E01400’ has been removed.
18:09:19.271 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - ‘sonos:One:RINCON_7828CA05E05A01400’ changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
18:09:19.272 [INFO ] [smarthome.event.InboxRemovedEvent ] - Discovery Result with UID ‘sonos:One:RINCON_7828CA1493A801400’ has been removed.
18:09:19.275 [INFO ] [smarthome.event.InboxRemovedEvent ] - Discovery Result with UID ‘sonos:One:RINCON_7828CA14949E01400’ has been removed.
18:09:20.237 [INFO ] [smarthome.event.InboxAddedEvent ] - Discovery Result with UID ‘sonos:One:RINCON_7828CA1493A801400’ has been added.
18:09:20.237 [INFO ] [ig.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA1493A801400’ to inbox.
18:09:20.438 [INFO ] [smarthome.event.InboxAddedEvent ] - Discovery Result with UID ‘sonos:One:RINCON_7828CA14949E01400’ has been added.
18:09:20.439 [INFO ] [ig.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA14949E01400’ to inbox.
18:09:20.610 [INFO ] [ig.discovery.internal.PersistentInbox] - Added new thing ‘sonos:PLAY5:RINCON_949F3E51972E01400’ to inbox.
18:09:20.610 [INFO ] [smarthome.event.InboxAddedEvent ] - Discovery Result with UID ‘sonos:PLAY5:RINCON_949F3E51972E01400’ has been added.
18:09:21.519 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - ‘sonos:One:RINCON_7828CA05E05A01400’ changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE
18:42:56.061 [WARN ] [n.config.VersionProperties$LazyHolder] - Failed (FileNotFoundException) to load version properties: Resource does not exists
18:43:46.880 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch’ received command ON
18:43:46.896 [INFO ] [arthome.event.ItemStatePredictedEvent] - zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch predicted to become OFF
18:49:43.215 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch’ received command ON
18:49:43.216 [INFO ] [arthome.event.ItemStatePredictedEvent] - zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch predicted to become OFF
18:52:16.290 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch’ received command OFF
18:52:16.301 [INFO ] [arthome.event.ItemStatePredictedEvent] - zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch predicted to become OFF
18:58:33.740 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch’ received command ON
18:58:33.743 [INFO ] [arthome.event.ItemStatePredictedEvent] - zigbee_device_04000E62_01124b001bb0005f_01124B001BB0005F_11_switch predicted to become OFF
I also retrieved the other log you requested (in the docker image, this was located here: /openhab/userdata/logs). This one gives a bit more of a hint of what might be going on with the error message below: “Error 0xffff setting server binding”. Reading the forums, it seems like this might be a zigbee controller device problem and that the Telegenesis USB stick I’m using is the issue? If that’s the issue, is there a recommended list of compatible USB Zigbee controller devices?
2020-11-22 15:09:13.774 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.101:8090
2020-11-22 15:09:13.780 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.101:8493
2020-11-22 15:09:16.022 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2020-11-22 15:14:46.421 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2020-11-22 15:14:46.492 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2020-11-22 15:14:46.541 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2020-11-22 17:02:15.708 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to ‘xx.0002414,-xx.67951959999999’.
2020-11-22 21:13:15.692 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2020-11-22 22:12:57.355 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to ‘xx.0002414,-xx.67951959999999’.
2020-11-22 22:12:57.625 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2020-11-22 22:12:57.665 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2020-11-22 22:13:03.923 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2020-11-22 22:13:05.037 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.101:8090
2020-11-22 22:13:05.038 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.101:8493
2020-11-22 22:13:05.327 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2020-11-22 22:22:21.423 [INFO ] [.dashboard.internal.DashboardService] - Stopped Dashboard
2020-11-22 22:22:23.441 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Stopped Home Builder
2020-11-22 22:22:23.458 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2020-11-22 22:22:23.473 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2020-11-22 22:22:23.490 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2020-11-22 22:23:00.089 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.101:8090
2020-11-22 22:23:00.089 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.101:8493
2020-11-22 22:23:00.125 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2020-11-22 22:23:00.198 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2020-11-22 22:23:00.227 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2020-11-22 22:23:05.083 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA14949E01400’ to inbox.
2020-11-22 22:23:05.171 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA1493A801400’ to inbox.
2020-11-22 22:23:05.202 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:PLAY5:RINCON_949F3E51972E01400’ to inbox.
2020-11-22 22:23:05.411 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA05E05A01400’ to inbox.
2020-11-22 22:23:10.297 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘zigbee:coordinator_telegesis:04000E62’ to inbox.
2020-11-22 22:23:13.008 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled ‘openhab-binding-zigbee’
2020-11-22 22:36:57.470 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 01124B001BB0005F: Starting ZigBee device discovery
2020-11-22 22:36:57.471 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘zigbee:device:04000E62:01124b001bb0005f’ to inbox.
2020-11-22 22:36:57.480 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 01124B001BB0005F: Starting ZigBee device discovery
2020-11-22 22:37:00.861 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 01124B001BB0005F: Starting ZigBee device discovery
2020-11-22 22:37:21.106 [ERROR] [converter.ZigBeeConverterSwitchOnoff] - 01124B001BB0005F: Error 0xffff setting server binding
2020-11-22 22:40:00.741 [ERROR] [converter.ZigBeeConverterSwitchOnoff] - 01124B001BB0005F: Error 0xffff setting server binding
2020-11-22 22:48:37.317 [ERROR] [converter.ZigBeeConverterSwitchOnoff] - 01124B001BB0005F: Error 0xffff setting server binding
2020-11-22 22:52:30.644 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 01124B001BB0005F: Starting ZigBee device discovery
2020-11-23 18:27:47.531 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA1493A801400’ to inbox.
2020-11-23 18:27:47.901 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA14949E01400’ to inbox.
2020-11-23 18:27:48.075 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:PLAY5:RINCON_949F3E51972E01400’ to inbox.
2020-11-24 18:21:18.738 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA1493A801400’ to inbox.
2020-11-24 18:21:18.783 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA14949E01400’ to inbox.
2020-11-24 18:21:19.045 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:PLAY5:RINCON_949F3E51972E01400’ to inbox.
2020-11-25 18:14:49.192 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA14949E01400’ to inbox.
2020-11-25 18:14:49.401 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA1493A801400’ to inbox.
2020-11-25 18:14:49.891 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:PLAY5:RINCON_949F3E51972E01400’ to inbox.
2020-11-26 18:09:20.237 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA1493A801400’ to inbox.
2020-11-26 18:09:20.439 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:One:RINCON_7828CA14949E01400’ to inbox.
2020-11-26 18:09:20.610 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘sonos:PLAY5:RINCON_949F3E51972E01400’ to inbox.
2020-11-26 18:42:56.061 [WARN ] [.config.VersionProperties$LazyHolder] - Failed (FileNotFoundException) to load version properties: Resource does not exists
I was able to turn on the DEBUG log level, and created the attached log file that is more comprehensive and probably useful in diagnosing the issue. openhab2.202011262238.log (126.9 KB)
What does the log show? ie what did you do - did you send commands to turn the light on, or what?
The log actually shows very little - just a single attribute poll to some device (O’m not even sure if it’s the device that has the problem as you don’t say what device ID etc this is). There don’t appear to be any commands to change the state of the device though.
I’ve been plugging away at this. The fact that the log was devoid of any instructions, even in Debug mode, was a helpful clue that told me there was something fundamentally wrong with my setup.
Ultimately, I think the issue was related to permissions on the USB controller and the fact that they were not set when the original Docker instance was spun up, but I’m not entirely sure. I did a couple troubleshooting steps:
Delete the zigbee thing and binding
re-add the binding and thing
restarted the docker container a couple times
forced docker to update the image (the image I was pulling was hard-coded in the docker start yaml to 2.4 from the last time I tried this out a year ago).
restarted the server that everything was running on.
I think it was probably the last two steps that really sorted it out because I am now able cause the zigbee switch to turn on and off in the Paper UI, and those actions are showing in the logs.
I think this issue is closed. Thanks for your help!
Ad.
