I’m having an issue pairing my Hue bridge with OpenHab. After turning on debug logging and restarting OpenHab, I wait for the Hue binding initialization message to appear and the pairing count down to appear. I then press the connect button on the bridge, at which point I see the following messages appearing in the logs.
2015-10-01 18:22:18.877 [DEBUG] [.o.b.hue.internal.HueActivator] - Hue binding has been started.
2015-10-01 18:22:18.955 [DEBUG] [.b.e.internal.EnoceanActivator] - enocean binding has been started.
2015-10-01 18:22:19.873 [INFO ] [.h.internal.hardware.HueBridge] - Hue bridge not paired.
2015-10-01 18:22:19.876 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 100 seconds...
2015-10-01 18:22:19.879 [INFO ] [.e.internal.bus.EnoceanBinding] - Connecting to Enocean [serialPort='/dev/ttyUSB0' ].
2015-10-01 18:22:19.879 [INFO ] [.service.AbstractActiveService] - Hue Refresh Service has been started
2015-10-01 18:22:19.880 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-01 18:22:20.131 [DEBUG] [.e.internal.bus.EnoceanBinding] - Updating item state for items [TF_Temperature, ContactTestItem, Emmetts_Room_Temp, SF_TF_Stairs_Switch, Demo_Switch]
2015-10-01 18:22:20.167 [INFO ] [.z.internal.ZWaveActiveBinding] - Update config, port = /dev/ttyAMA0
2015-10-01 18:22:20.178 [INFO ] [.service.AbstractActiveService] - ZWave Refresh Service has been started
2015-10-01 18:22:20.228 [INFO ] [b.z.i.protocol.ZWaveController] - Starting Z-Wave controller
2015-10-01 18:22:20.230 [INFO ] [b.z.i.protocol.ZWaveController] - Z-Wave timeout is set to 5000ms. Soft reset is false.
2015-10-01 18:22:20.232 [INFO ] [b.z.i.protocol.ZWaveController] - Connecting to serial port /dev/ttyAMA0
2015-10-01 18:22:20.264 [INFO ] [b.z.i.protocol.ZWaveController] - Serial port is initialized
2015-10-01 18:22:20.795 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
2015-10-01 18:22:20.813 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-01 18:22:20.841 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
2015-10-01 18:22:20.907 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 99 seconds...
if I press the button again a similar message appears
2015-10-01 18:22:30.691 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 90 seconds...
2015-10-01 18:22:30.844 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-01 18:22:30.894 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
2015-10-01 18:22:30.895 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-01 18:22:30.903 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
2015-10-01 18:22:31.705 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 89 seconds...
The json reference made me think that possibly the Hue was on an old version of the it’s software so I checked that it’s up to date…and it is. I’m running OpenHab v1.7
I’m stumped, anyone have any ideas? This just seems to work for so many people that I can’t figure out what I’ve done wrong.
Hi,
difficult to see what went wrong here.
I have created a pull request with improved logging output.
If it gets accepted, you can take the hue binding from the latest nightly build, set logging to trace and try it again. This should help to identify the problem.
Here’s some logging with the 1.8 binding and trace logging: (If you want the entire log let me know)
2015-10-06 21:51:08.021 [DEBUG] [.o.b.hue.internal.HueActivator] - Hue binding has been started.
2015-10-06 21:51:09.231 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-06 21:51:09.237 [INFO ] [.h.internal.hardware.HueBridge] - Hue bridge not paired.
2015-10-06 21:51:09.244 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 100 seconds...
2015-10-06 21:51:09.247 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-06 21:51:09.269 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-06 21:51:10.274 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 99 seconds...
2015-10-06 21:51:10.328 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
org.codehaus.jackson.map.JsonMappingException: Can not deserialize instance of java.util.LinkedHashMap out of START_ARRAY token
at [Source: java.io.StringReader@47b68d; line: 1, column: 1]
at org.codehaus.jackson.map.JsonMappingException.from(JsonMappingException.java:163) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:219) ~[na:na]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:212) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:246) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:33) ~[na:na]
at org.codehaus.jackson.map.ObjectMapper._readMapAndClose(ObjectMapper.java:2723) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1854) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.openhab.binding.hue.internal.data.HueSettings.<init>(HueSettings.java:52) ~[bundlefile:na]
at org.openhab.binding.hue.internal.hardware.HueBridge.getSettings(HueBridge.java:83) [bundlefile:na]
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:98) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-10-06 21:51:10.331 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-06 21:51:10.336 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
The error you’ve seen in the log is caused by the hue binding trying to read the settings even though openHAB is not authorized/paired. This happens every 10 seconds as the hue data refresh is enabled:
2015-10-01 18:22:30.844 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
Now the strange thing is, there errors should go away once you press the pairing button on the bridge. The logs should show either “Hue bridge successfully paired!” on INFO level.
Could you download the latest nightly build of the hue binding again (as I made another pull request yesterday which should remove some invalid logging) and then test it again with pressing the button on the Hue bridge? Would be great if you could share the logs again and point out at which timestamp you pressed the button.
If this doesn’t help, I will improve the logging of the hue binding during the pairing process.
@dominicdesu, correct, Openhab has never successfully paired with the Hue bridge, therefore I do expect that at a TRACE logging level some errors will show up. However, after pressing the button on the Hue bridge the same errors continue, no “Hue bridge successfully paired!” message is displayed, and I continue to be prompted to press the connect button.
As requested I downloaded the 1.8 nightly build, deployed the 1.8 hue binding to the Addons folder and restarted OpenHAB. At approximately 22:37:34 I pressed the connect button. That’s the only occurrence of me pressing the connect button in this log. I then shutdown OpenHAB.
2015-10-08 22:37:24.033 [DEBUG] [.o.b.hue.internal.HueActivator] - Hue binding has been started.
2015-10-08 22:37:25.196 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-08 22:37:25.202 [INFO ] [.h.internal.hardware.HueBridge] - Hue bridge not paired.
2015-10-08 22:37:25.208 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 100 seconds...
2015-10-08 22:37:25.209 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-08 22:37:25.232 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-08 22:37:26.134 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
org.codehaus.jackson.map.JsonMappingException: Can not deserialize instance of java.util.LinkedHashMap out of START_ARRAY token
at [Source: java.io.StringReader@259812; line: 1, column: 1]
at org.codehaus.jackson.map.JsonMappingException.from(JsonMappingException.java:163) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:219) ~[na:na]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:212) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:246) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:33) ~[na:na]
at org.codehaus.jackson.map.ObjectMapper._readMapAndClose(ObjectMapper.java:2723) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1854) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.openhab.binding.hue.internal.data.HueSettings.<init>(HueSettings.java:52) ~[bundlefile:na]
at org.openhab.binding.hue.internal.hardware.HueBridge.getSettings(HueBridge.java:83) [bundlefile:na]
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:98) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-10-08 22:37:26.158 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-08 22:37:26.165 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
2015-10-08 22:37:26.241 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 99 seconds...
2015-10-08 22:37:27.255 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 98 seconds...
2015-10-08 22:37:28.267 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 97 seconds...
2015-10-08 22:37:28.573 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class SWITCH_ALL
2015-10-08 22:37:28.801 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 2: Is currently marked as failed by the controller!
2015-10-08 22:37:29.282 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 96 seconds...
2015-10-08 22:37:30.295 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 95 seconds...
2015-10-08 22:37:31.320 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 94 seconds...
2015-10-08 22:37:32.336 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 93 seconds...
2015-10-08 22:37:32.977 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 2: Node is DEAD. Dropping message.
2015-10-08 22:37:33.351 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 92 seconds...
2015-10-08 22:37:34.367 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 91 seconds...
2015-10-08 22:37:35.382 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 90 seconds...
2015-10-08 22:37:36.166 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-08 22:37:36.248 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-08 22:37:36.277 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
org.codehaus.jackson.map.JsonMappingException: Can not deserialize instance of java.util.LinkedHashMap out of START_ARRAY token
at [Source: java.io.StringReader@da0f8; line: 1, column: 1]
at org.codehaus.jackson.map.JsonMappingException.from(JsonMappingException.java:163) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:219) ~[na:na]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:212) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:246) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:33) ~[na:na]
at org.codehaus.jackson.map.ObjectMapper._readMapAndClose(ObjectMapper.java:2723) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1854) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.openhab.binding.hue.internal.data.HueSettings.<init>(HueSettings.java:52) ~[bundlefile:na]
at org.openhab.binding.hue.internal.hardware.HueBridge.getSettings(HueBridge.java:83) [bundlefile:na]
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:98) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-10-08 22:37:36.279 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-08 22:37:36.284 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
2015-10-08 22:37:36.410 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 89 seconds...
2015-10-08 22:37:37.425 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 88 seconds...
2015-10-08 22:37:38.011 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 2: Node is DEAD. Dropping message.
2015-10-08 22:37:38.438 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 87 seconds...
2015-10-08 22:37:39.452 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 86 seconds...
2015-10-08 22:37:40.472 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 85 seconds...
2015-10-08 22:37:41.492 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 84 seconds...
2015-10-08 22:37:42.507 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 83 seconds...
2015-10-08 22:37:43.522 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 82 seconds...
2015-10-08 22:37:44.538 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 81 seconds...
2015-10-08 22:37:45.553 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 80 seconds...
2015-10-08 22:37:46.286 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-08 22:37:46.306 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-08 22:37:46.352 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
org.codehaus.jackson.map.JsonMappingException: Can not deserialize instance of java.util.LinkedHashMap out of START_ARRAY token
at [Source: java.io.StringReader@18d6498; line: 1, column: 1]
at org.codehaus.jackson.map.JsonMappingException.from(JsonMappingException.java:163) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:219) ~[na:na]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:212) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:246) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:33) ~[na:na]
at org.codehaus.jackson.map.ObjectMapper._readMapAndClose(ObjectMapper.java:2723) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1854) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.openhab.binding.hue.internal.data.HueSettings.<init>(HueSettings.java:52) ~[bundlefile:na]
at org.openhab.binding.hue.internal.hardware.HueBridge.getSettings(HueBridge.java:83) [bundlefile:na]
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:98) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-10-08 22:37:46.354 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-08 22:37:46.360 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
2015-10-08 22:37:46.570 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 79 seconds...
2015-10-08 22:37:47.582 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 78 seconds...
2015-10-08 22:37:47.961 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 2: Node is DEAD. Dropping message.
2015-10-08 22:37:48.596 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 77 seconds...
2015-10-08 22:37:49.611 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 76 seconds...
2015-10-08 22:37:50.627 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 75 seconds...
2015-10-08 22:37:51.643 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 74 seconds...
2015-10-08 22:37:52.659 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 73 seconds...
2015-10-08 22:37:53.678 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 72 seconds...
2015-10-08 22:37:54.693 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 71 seconds...
2015-10-08 22:37:55.706 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 70 seconds...
2015-10-08 22:37:56.361 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-08 22:37:56.380 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-08 22:37:56.412 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
org.codehaus.jackson.map.JsonMappingException: Can not deserialize instance of java.util.LinkedHashMap out of START_ARRAY token
at [Source: java.io.StringReader@14f12ff; line: 1, column: 1]
at org.codehaus.jackson.map.JsonMappingException.from(JsonMappingException.java:163) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:219) ~[na:na]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:212) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:246) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:33) ~[na:na]
at org.codehaus.jackson.map.ObjectMapper._readMapAndClose(ObjectMapper.java:2723) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1854) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.openhab.binding.hue.internal.data.HueSettings.<init>(HueSettings.java:52) ~[bundlefile:na]
at org.openhab.binding.hue.internal.hardware.HueBridge.getSettings(HueBridge.java:83) [bundlefile:na]
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:98) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-10-08 22:37:56.414 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-08 22:37:56.420 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
2015-10-08 22:37:56.718 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 69 seconds...
2015-10-08 22:37:57.731 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 68 seconds...
2015-10-08 22:37:58.743 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 67 seconds...
2015-10-08 22:37:59.756 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 66 seconds...
2015-10-08 22:38:00.780 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 65 seconds...
2015-10-08 22:38:01.794 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 64 seconds...
2015-10-08 22:38:02.806 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 63 seconds...
2015-10-08 22:38:03.819 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 62 seconds...
2015-10-08 22:38:04.836 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 61 seconds...
2015-10-08 22:38:05.853 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 60 seconds...
2015-10-08 22:38:06.422 [DEBUG] [inding.hue.internal.HueBinding] - Start Hue data refresh
2015-10-08 22:38:06.443 [TRACE] [.h.internal.hardware.HueBridge] - Received Hue Bridge Settings: [{"error":{"type":1,"address":"/","description":"unauthorized user"}}]
2015-10-08 22:38:06.489 [ERROR] [.hue.internal.data.HueSettings] - Could not read Settings-Json from Hue Bridge.
org.codehaus.jackson.map.JsonMappingException: Can not deserialize instance of java.util.LinkedHashMap out of START_ARRAY token
at [Source: java.io.StringReader@168deda; line: 1, column: 1]
at org.codehaus.jackson.map.JsonMappingException.from(JsonMappingException.java:163) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:219) ~[na:na]
at org.codehaus.jackson.map.deser.StdDeserializationContext.mappingException(StdDeserializationContext.java:212) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:246) ~[na:na]
at org.codehaus.jackson.map.deser.std.MapDeserializer.deserialize(MapDeserializer.java:33) ~[na:na]
at org.codehaus.jackson.map.ObjectMapper._readMapAndClose(ObjectMapper.java:2723) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1854) ~[jackson-mapper-asl-1.9.2.jar:1.9.2]
at org.openhab.binding.hue.internal.data.HueSettings.<init>(HueSettings.java:52) ~[bundlefile:na]
at org.openhab.binding.hue.internal.hardware.HueBridge.getSettings(HueBridge.java:83) [bundlefile:na]
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:98) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-10-08 22:38:06.538 [ERROR] [.hue.internal.data.HueSettings] - Hue bridge settings not initialized correctly.
2015-10-08 22:38:06.546 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Hue Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.hue.internal.HueBinding.execute(HueBinding.java:104) ~[na:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]
2015-10-08 22:38:06.872 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 59 seconds...
2015-10-08 22:38:07.885 [INFO ] [.h.internal.hardware.HueBridge] - Please press the connect button on the Hue bridge. Waiting for pairing for 58 seconds...
2015-10-08 22:38:07.920 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 2: Node is DEAD. Dropping message.
Thanks again for your help on this Dominic. It’s greatly appreciated.
Dave
If you use openHAB_binding as the devicetype in step 3, and the user registration is successful, you should be able to use the hue binding with the bridge and the generated username afterwards.
I would also hope that the manual process via the browser will give some more insight in case a specific error message is returned from the bridge.
Thanks @dominicdesu, I’ll start investigating the Hue as the problem location. Thanks for the url. I’ll start using that process to debug the Hue and get back to you.
Note: I recently bought a new tablet and was able to pair the Hue app to the bridge. I can’t remember the last time I rebooted the Hue though so I’ll also give that a try.
@davet72, have you had any luck? I’m getting the exact same errors. I am also running homeseer, but trying to switch over because of remote access issues with HS, and I can easily pair to it and other devices (I even factory reset my bridge), but with HS running or not running, OpenHAB refuses to connect.
I did also try manually entering a username as suggested above, no luck
@davet72, @unbwogable Actually I was just able to reproduce this when I set a hue:secret in openhab.cfg with less than 10 characters. Could you check this is not the case for you? The secret has to be between 10 and 40 characters. (While your at it, please check if your secret contains special characters. If yes, please try it once with only aA-zZ and 0-9).
If this is not the solution, I will make a pull request which adds more logging output and show show excatly what message is returned from the bridge (or not returned) when the link button is pressed.
