Closed kaikreuzer closed 7 years ago
I just tried it yesterday with a fresh openHAB 2 installation and I did not see any messages like this.
But it seems that your CCU has got a quite old firmware. According to the log it is running 2.3.11. Current version ist 2.25.15.
Thanks @MHerbst - this was also what I just tried and I can confirm that with the latest firmware, the connection succeeds. Nonetheless, I think an NPE should be avoided in any case.
I agree, @kaikreuzer
I don't think it has something todo with the firmware, it was a problem loading the property file homematic/standard-datapoints.properties.
see: source
Same NPEs on startup for me as well. And my ccu2 is on firmware 2.25.15.
Can you attach the stacktrace output here? Would help us to see whether it has the same cause.
To solve the problem it may help to uninstall the Homematic binding and install it new.
I tried to reproduce it, but can't right now :-/ . I will add the trace as soon as I see it again. I've still have a lot of them, but all coming from the harmony plugin...
I will open a separate ticket with the stack-trace for it.
@dhermanns this exception has already been fixed in the snapshot builds
Thanks for your great work. That explains why the exception seems to be vanished ;-) .
@gerrieg I don't think that it is completley solved. If method getResourceAsStream (line 69) fails for some reason, the returned InputStream object will be null and. Then the next line will throw a NPE. An easy solution would be to catch the NPE in the catch-Statement in line 87.
This should never happen, but i can change it.
You are right. I can only think that this happens if something with the add-on installation fails or is too slow. But the exception Kai posted pointed exactly to this line. Therefore you will be on the safe side if you catch it :-).
I also get an NPE.
I added/removed the Homematic Add-on several times and did some reboots as the CCU2 things never showed up as being ONLINE in paperui. Now the CCU2 things do not show up at all anymore.
Seems like there is some rubbish left behind.
2017-03-25 09:54:41.280 [INFO ] [ternal.communicator.HomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.27.7,address=NEQ1532944,wired=false,hmip=true,cuxd=false]
2017-03-25 09:54:41.282 [INFO ] [ternal.communicator.HomematicGateway] - Used Homematic transfer modes: RF:BIN_RPC, HMIP:XML_RPC
2017-03-25 09:54:41.750 [ERROR] [very.HomematicDeviceDiscoveryService] -
java.lang.NullPointerException
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:201)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:193)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.loadDeviceNames(CcuGateway.java:125)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.getDeviceDescriptions(AbstractHomematicGateway.java:421)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.loadAllDeviceMetadata(AbstractHomematicGateway.java:358)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.discovery.HomematicDeviceDiscoveryService$1.run(HomematicDeviceDiscoveryService.java:108)[205:org.openhab.binding.homematic:2.0.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
2017-03-25 09:55:15.640 [ERROR] [very.HomematicDeviceDiscoveryService] -
java.lang.NullPointerException
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.createGatewayDevice(AbstractHomematicGateway.java:655)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.getDeviceDescriptions(AbstractHomematicGateway.java:420)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.loadAllDeviceMetadata(AbstractHomematicGateway.java:358)[205:org.openhab.binding.homematic:2.0.0]
at org.openhab.binding.homematic.discovery.HomematicDeviceDiscoveryService$1.run(HomematicDeviceDiscoveryService.java:108)[205:org.openhab.binding.homematic:2.0.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
continues with
2017-03-25 09:59:41.404 [INFO ] [ternal.communicator.HomematicGateway] - No event since 300 seconds from gateway 'ccu2', restarting RPC server
2017-03-25 10:00:41.649 [INFO ] [ternal.communicator.HomematicGateway] - No event since 360 seconds from gateway 'ccu2', restarting RPC server
This seems to be a different problem. Mabe related to the new CCU firmware. You could try it with the latest OH Snapshot (https://openhab.ci.cloudbees.com/job/openHAB-Distribution/) because there have been several modifications in the binding since the release version.
unstable renders an different exception, but same behaviour
2017-03-25 10:53:45.896 [INFO ] [ternal.communicator.HomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.27.7,address=NEQ1532944,wired=false,hmip=true,cuxd=false,group=true]
2017-03-25 10:54:11.588 [ERROR] [very.HomematicDeviceDiscoveryService] -
java.io.IOException
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScript(CcuGateway.java:255)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:225)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:213)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.loadDeviceNames(CcuGateway.java:126)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.getDeviceDescriptions(AbstractHomematicGateway.java:446)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.loadAllDeviceMetadata(AbstractHomematicGateway.java:373)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.discovery.HomematicDeviceDiscoveryService$1.run(HomematicDeviceDiscoveryService.java:108)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
Caused by: java.util.concurrent.TimeoutException
at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:109)[69:org.eclipse.jetty.client:9.2.19.v20160908]
at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:655)[69:org.eclipse.jetty.client:9.2.19.v20160908]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScript(CcuGateway.java:245)[215:org.openhab.binding.homematic:2.1.0.201703240758]
... 13 more
2017-03-25 10:54:43.564 [ERROR] [very.HomematicDeviceDiscoveryService] -
java.io.IOException
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScript(CcuGateway.java:255)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:225)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:213)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.loadDeviceNames(CcuGateway.java:126)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.getDeviceDescriptions(AbstractHomematicGateway.java:446)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.loadAllDeviceMetadata(AbstractHomematicGateway.java:373)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at org.openhab.binding.homematic.discovery.HomematicDeviceDiscoveryService$1.run(HomematicDeviceDiscoveryService.java:108)[215:org.openhab.binding.homematic:2.1.0.201703240758]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
Caused by: java.util.concurrent.TimeoutException
at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:109)[69:org.eclipse.jetty.client:9.2.19.v20160908]
at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:655)[69:org.eclipse.jetty.client:9.2.19.v20160908]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScript(CcuGateway.java:245)[215:org.openhab.binding.homematic:2.1.0.201703240758]
... 13 more
(should I add a new GH issue, as its not related to this?)
@ooswald In the new 2.27.7 firmware, eq-3 changed some security things. The binding can not connect to the CCU on port 8181. Check the firewall settings in the CCU and set the Remote HomeMatic-Script API and/or HomeMatic XML-RPC API to full access.
that fixed it, thanks @gerrieg - the UI could be more informative
Fixed it for me too, thanks @gerrieg. Should have read the release notes from EQ3. Maybe a hint in the paperUI will be helpful for other users.
[HMCCU2-1336] Sicherheitsrelevante Erweiterungen: (Security-Related Extensions)
- Firewall bei Systemstart starten (Start the firewall at system startup)...
Having the same problem with openHAB 2.2.0-1 and piVCCU version: 2.31.25-23 on a Raspberry Pi 3 Model B Rev 1.2. HomeMatic-Script API and/or HomeMatic XML-RPC API in the CCU is set to full access.
`2018-03-03 18:16:30.572 [hingStatusInfoChangedEvent] - 'homematic:GATEWAY-EXTRAS-30851B87:30851b87:GWE00000000' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2018-03-03 18:16:30.601 [hingStatusInfoChangedEvent] - 'homematic:HM-RCV-50:30851b87:BidCoS-RF' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2018-03-03 18:16:30.655 [hingStatusInfoChangedEvent] - 'homematic:bridge:30851b87' changed from UNINITIALIZED to INITIALIZING
==> /var/log/openhab2/openhab.log <==
2018-03-03 18:16:31.229 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'WIRED' on gateway '30851b87' not available, disabling support
2018-03-03 18:16:31.243 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'HMIP' on gateway '30851b87' not available, disabling support
2018-03-03 18:16:31.249 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'CUXD' on gateway '30851b87' not available, disabling support
2018-03-03 18:16:31.256 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'GROUP' on gateway '30851b87' not available, disabling support
2018-03-03 18:16:31.386 [INFO ] [ommunicator.AbstractHomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.31.25,address=OEQ0610287,wired=false,hmip=false,cuxd=false,group=false]
2018-03-03 18:16:31.647 [ERROR] [very.HomematicDeviceDiscoveryService] - html
java.io.IOException: html
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScript(CcuGateway.java:228) [207:org.openhab.binding.homematic:2.2.0]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:198) [207:org.openhab.binding.homematic:2.2.0]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScriptByName(CcuGateway.java:186) [207:org.openhab.binding.homematic:2.2.0]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.loadDeviceNames(CcuGateway.java:111) [207:org.openhab.binding.homematic:2.2.0]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.getDeviceDescriptions(AbstractHomematicGateway.java:423) [207:org.openhab.binding.homematic:2.2.0]
at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.loadAllDeviceMetadata(AbstractHomematicGateway.java:343) [207:org.openhab.binding.homematic:2.2.0]
at org.openhab.binding.homematic.internal.discovery.HomematicDeviceDiscoveryService$1.run(HomematicDeviceDiscoveryService.java:104) [207:org.openhab.binding.homematic:2.2.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
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) [?:?]
Caused by: com.thoughtworks.xstream.mapper.CannotResolveClassException: html
at com.thoughtworks.xstream.mapper.DefaultMapper.realClass(DefaultMapper.java:79) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.DynamicProxyMapper.realClass(DynamicProxyMapper.java:55) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.PackageAliasingMapper.realClass(PackageAliasingMapper.java:88) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.ClassAliasingMapper.realClass(ClassAliasingMapper.java:79) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.ArrayMapper.realClass(ArrayMapper.java:74) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.SecurityMapper.realClass(SecurityMapper.java:71) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.MapperWrapper.realClass(MapperWrapper.java:30) ~[?:?]
at com.thoughtworks.xstream.mapper.CachingMapper.realClass(CachingMapper.java:47) ~[?:?]
at com.thoughtworks.xstream.core.util.HierarchicalStreams.readClassType(HierarchicalStreams.java:29) ~[?:?]
at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:133) ~[?:?]
at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32) ~[?:?]
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1185) ~[?:?]
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1169) ~[?:?]
at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1040) ~[?:?]
at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1031) ~[?:?]
at org.openhab.binding.homematic.internal.communicator.CcuGateway.sendScript(CcuGateway.java:226) ~[?:?]
... 13 more
==> /var/log/openhab2/events.log <==
2018-03-03 18:16:31.813 [hingStatusInfoChangedEvent] - 'homematic:bridge:30851b87' changed from INITIALIZING to ONLINE
2018-03-03 18:16:31.842 [hingStatusInfoChangedEvent] - 'homematic:GATEWAY-EXTRAS-30851B87:30851b87:GWE00000000' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2018-03-03 18:16:31.854 [hingStatusInfoChangedEvent] - 'homematic:HM-RCV-50:30851b87:BidCoS-RF' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2018-03-03 18:16:31.880 [hingStatusInfoChangedEvent] - 'homematic:HM-RCV-50:30851b87:BidCoS-RF' changed from INITIALIZING to OFFLINE (CONFIGURATION_ERROR): Device with address 'BidCoS-RF' not found on gateway '30851b87'
2018-03-03 18:16:31.884 [hingStatusInfoChangedEvent] - 'homematic:GATEWAY-EXTRAS-30851B87:30851b87:GWE00000000' changed from INITIALIZING to OFFLINE (CONFIGURATION_ERROR): Device with address 'GWE00000000' not found on gateway '30851b87'`
I think your problem has nothing to do with this issue. It has probably the same cause as #2543 (where you already added a comment).
After adding a CCU2 as a Homematic bridge, I found this in my log:
@gerrieg Is this anything known?