openhab-addons: [Netatmo] Binding fail with exception

Hi, at home I have a netatmo thermometer (1st relay) and two valves (2nd relay). The first relay directly controls the boiler while the second has no pins to control the boiler so, until last winter I used a shelly 1pm to activate the boiler if one of the valves required it. Until last winter everything worked, but now the binding is struggling to work. Last winter I was using version 3.3 of openhab, now I upgraded (new installation) to version 4.0.4. When I create the Things the bridge it works, then after a few hours it no longer updates the values ​​of the items, this error appears in the logs:

2023-11-06 08:07:40.719 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: Cannot invoke "org.openhab.binding.netatmo.internal.deserialization.NAObjectMap.getOpt(String)" because "<parameter1>" is null
	at org.openhab.binding.netatmo.internal.handler.capability.EnergyCapability.lambda$7(EnergyCapability.java:94) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) ~[?:?]
	at java.util.AbstractList$RandomAccessSpliterator.forEachRemaining(AbstractList.java:720) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.EnergyCapability.updateHomeStatus(EnergyCapability.java:92) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.Capability.setNewData(Capability.java:70) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.CommonInterface.setNewData(CommonInterface.java:161) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.CommonInterface.lambda$12(CommonInterface.java:188) ~[?:?]
	at java.util.ArrayList.forEach(ArrayList.java:1511) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.CommonInterface.proceedWithUpdate(CommonInterface.java:188) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.RefreshCapability.proceedWithUpdate(RefreshCapability.java:81) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.RefreshCapability.lambda$2(RefreshCapability.java:122) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]

However, if I try to change a setpoint from openhab (without using the netatmo app) the binding restarts working again (for a few more hours) I activated the debug log for the netatmo binding but I don’t seem to see anything interesting. I noticed that often when the binding fails other queries on other Things also fail:

2023-11-06 20:05:11.934 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 60 s
2023-11-06 20:06:12.299 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 60 s
2023-11-06 20:07:03.524 [WARN ] [p.internal.http.HttpResponseListener] - Requesting 'http://192.168.1.207/settings/relay/0' (method='GET', content='null') failed: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed
2023-11-06 20:07:03.527 [WARN ] [p.internal.http.HttpResponseListener] - Requesting 'http://192.168.1.207/settings/relay/1' (method='GET', content='null') failed: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed
2023-11-06 20:07:03.561 [WARN ] [p.internal.http.HttpResponseListener] - Requesting 'http://192.168.1.215/settings/relay/1' (method='GET', content='null') failed: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed
2023-11-06 20:07:03.563 [WARN ] [p.internal.http.HttpResponseListener] - Requesting 'http://192.168.1.215/settings/relay/0' (method='GET', content='null') failed: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed
2023-11-06 20:07:03.624 [WARN ] [p.internal.http.HttpResponseListener] - Requesting 'http://192.168.1.205/settings/relay/0' (method='GET', content='null') failed: java.util.concurrent.TimeoutException: Total timeout 3000 ms elapsed
2023-11-06 20:07:22.529 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: Cannot invoke "org.openhab.binding.netatmo.internal.deserialization.NAObjectMap.getOpt(String)" because "<parameter1>" is null
	at org.openhab.binding.netatmo.internal.handler.capability.EnergyCapability.lambda$7(EnergyCapability.java:94) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) ~[?:?]
	at java.util.AbstractList$RandomAccessSpliterator.forEachRemaining(AbstractList.java:720) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.EnergyCapability.updateHomeStatus(EnergyCapability.java:92) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.Capability.setNewData(Capability.java:70) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.CommonInterface.setNewData(CommonInterface.java:161) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.CommonInterface.lambda$12(CommonInterface.java:188) ~[?:?]
	at java.util.ArrayList.forEach(ArrayList.java:1511) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.CommonInterface.proceedWithUpdate(CommonInterface.java:188) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.RefreshCapability.proceedWithUpdate(RefreshCapability.java:81) ~[?:?]
	at org.openhab.binding.netatmo.internal.handler.capability.RefreshCapability.lambda$2(RefreshCapability.java:122) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
2023-11-06 21:32:05.707 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 60 s
2023-11-06 21:32:10.701 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 60 s
2023-11-06 21:32:12.905 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 60 s

Thanks, Cristian

[OpenHab version: 4.0.4]

About this issue

  • Original URL
  • State: closed
  • Created 8 months ago
  • Comments: 25 (12 by maintainers)

Commits related to this issue

Most upvoted comments

Good news … In openhab 4.0.4 the netatmo binding was crashed, while in version 4.1 with the last jar you sent me it handled the exception. Great!!!

Ok, thanks a lot for your detailed informations. I think I understand your setup but not where the problem comes. BTW it’s located on a single line, always the same. I made a new modification. Can you try this new one ?

Ok. I increased logging to understand what is going on. Can you please : 1°/ ensure that you have removed the installed binding via the add-on store 2°/ delete previous version I gave you from the addons folder 3°/ install this one 4°/ stay at trace level and wait this error to happen

This version does not correct this issue but gives more informations on what is going on. Thanks

I upgraded to 4.1 and after a few hours everything still works. I tried disconnecting the network to check how the binding behaves and after 5 minutes it started again. I’ll try for a few days then give you another feedback. Thank you so much for your support. Cristian

2023-11-09 16:44:06.520 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 60s
2023-11-09 16:45:06.523 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=xxxxxxxxxxx 
2023-11-09 16:45:06.527 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.52.v20230823, Authorization: Bearer xxxxxxxxxxx|xxxxxxxxxxx 
2023-11-09 16:45:26.532 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Request timedout, retry counter : 3
2023-11-09 16:45:26.533 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=xxxxxxxxxxx 
2023-11-09 16:45:26.537 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.52.v20230823, Authorization: Bearer xxxxxxxxxxx|xxxxxxxxxxx 
2023-11-09 16:45:32.752 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Request timedout, retry counter : 2
2023-11-09 16:45:32.753 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=xxxxxxxxxxx 
2023-11-09 16:45:32.763 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.52.v20230823, Authorization: Bearer xxxxxxxxxxx|xxxxxxxxxxx 
2023-11-09 16:45:32.766 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Request timedout, retry counter : 1
2023-11-09 16:45:32.768 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=xxxxxxxxxxx 
2023-11-09 16:45:32.773 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.52.v20230823, Authorization: Bearer xxxxxxxxxxx|xxxxxxxxxxx 
2023-11-09 16:45:32.780 [DEBUG] [tatmo.internal.handler.DeviceHandler] - bridgeStatusChanged for bridge netatmo:home:myaccount:casa to OFFLINE (COMMUNICATION_ERROR): @text/request-time-out
2023-11-09 16:45:32.784 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:room:myaccount:casa:cucina to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.785 [DEBUG] [tatmo.internal.handler.DeviceHandler] - bridgeStatusChanged for bridge netatmo:plug:myaccount:casa:termostato_relay to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.785 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:room:myaccount:casa:bagno to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.785 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:room:myaccount:casa:bagnetto to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.785 [DEBUG] [tatmo.internal.handler.DeviceHandler] - bridgeStatusChanged for bridge netatmo:plug:myaccount:casa:valvole_relay to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.789 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:thermostat:myaccount:casa:termostato_relay:termostato to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.792 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:valve:myaccount:casa:valvole_relay:valvola_bagno to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.792 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:valve:myaccount:casa:valvole_relay:valvola_bagnetto to OFFLINE (BRIDGE_OFFLINE)
2023-11-09 16:45:32.785 [WARN ] [al.handler.capability.HomeCapability] - Error getting Home informations: java.util.concurrent.ExecutionException: "java.net.UnknownHostException: api.netatmo.com"
2023-11-09 16:45:32.796 [DEBUG] [handler.capability.RefreshCapability] - Module is not ONLINE; special refresh interval is used
2023-11-09 16:45:32.798 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 900s
2023-11-09 16:50:32.785 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Connecting to Netatmo API.
2023-11-09 16:50:32.788 [DEBUG] [tatmo.internal.handler.DeviceHandler] - bridgeStatusChanged for bridge netatmo:home:myaccount:casa to ONLINE
2023-11-09 16:50:32.794 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:room:myaccount:casa:cucina to UNKNOWN
2023-11-09 16:50:32.794 [DEBUG] [tatmo.internal.handler.DeviceHandler] - bridgeStatusChanged for bridge netatmo:plug:myaccount:casa:valvole_relay to UNKNOWN
2023-11-09 16:50:32.794 [DEBUG] [tatmo.internal.handler.DeviceHandler] - bridgeStatusChanged for bridge netatmo:plug:myaccount:casa:termostato_relay to UNKNOWN
2023-11-09 16:50:32.794 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:room:myaccount:casa:bagno to UNKNOWN
2023-11-09 16:50:32.795 [DEBUG] [tatmo.internal.handler.ModuleHandler] - bridgeStatusChanged for thing netatmo:room:myaccount:casa:bagnetto to UNKNOWN
2023-11-09 16:50:34.794 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=xxxxxxxxxxx 
2023-11-09 16:50:34.797 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.52.v20230823, Authorization: Bearer xxxxxxxxxxx|xxxxxxxxxxx 
2023-11-09 16:50:35.099 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"body":{"homes":[{................

I’ll try to upgrade to 4.1 and then I’ll let you know if the error remains

Two of your modules are in error (6 = unreachable) and this should be handled by the binding but apparently it’s not the case. I’ll have a look.