Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[netatmo] Things linked to the bridge "netatmo:home" doesn't work after OH 4.x #15928

Closed
Matt2cv opened this issue Nov 19, 2023 · 23 comments · Fixed by #16026
Closed

[netatmo] Things linked to the bridge "netatmo:home" doesn't work after OH 4.x #15928

Matt2cv opened this issue Nov 19, 2023 · 23 comments · Fixed by #16026
Assignees
Labels
bug An unexpected problem or unintended behavior of an add-on

Comments

@Matt2cv
Copy link

Matt2cv commented Nov 19, 2023

Expected Behavior

I was in version 3.4 of OH. I had configured the Netatmo binding. The relays, thermostat, people linked to the Welcome camera, everything worked. When I upgraded to 4.0, the relay and thermostat went to UNKNOWN status. The camera part works for the moment.

Current Behavior

When I activate the netatmo account, everything goes well

2023-11-19 19:04:09.196 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Initializing Netatmo API bridge handler.
2023-11-19 19:04:09.204 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Connecting to Netatmo API.
2023-11-19 19:04:09.255 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:home:e9dd9122ce:5971b81c69f74006578b4b92
2023-11-19 19:04:09.269 [DEBUG] [.netatmo.internal.action.RoomActions] - Netatmo RoomActions service created
2023-11-19 19:04:09.319 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:plug:e9dd9122ce:5971b81c69f74006578b4b92:70ee500a54c0
2023-11-19 19:04:09.327 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:53d496838fd842719e71cebee9d648e3
2023-11-19 19:04:09.360 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:1135ceb2a84d4249b6c66594242f7c68
2023-11-19 19:04:09.361 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:c6f72f80adfe4d53943da716a86fd815
2023-11-19 19:04:09.384 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:thermostat:e9dd9122ce:5971b81c69f74006578b4b92:70ee500a54c0:0400000a3946
2023-11-19 19:04:09.430 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:room:e9dd9122ce:5971b81c69f74006578b4b92:42498674
2023-11-19 19:04:09.443 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:welcome:e9dd9122ce:5971b81c69f74006578b4b92:70ee5080de84
2023-11-19 19:04:09.463 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:be22c1ce76a248ef83df5a700f8c2810
2023-11-19 19:04:09.469 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:0d6f7eaf7a1b4d9c878ad8665aaccbbe
2023-11-19 19:04:09.995 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json['update']['state']
2023-11-19 19:04:11.260 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=5971b81c69f74006578b4b92
2023-11-19 19:04:11.264 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer 5664244767e48246a48b4925|8f827bb581695709993c3756072456fa
2023-11-19 19:04:11.429 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"body":{"homes"....

Same thing when I activate the "netatmo:home" thing, everything is OK

2023-11-19 19:06:52.450 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:home:e9dd9122ce:5971b81c69f74006578b4b92
2023-11-19 19:06:52.474 [DEBUG] [.netatmo.internal.action.RoomActions] - Netatmo RoomActions service created
2023-11-19 19:06:52.498 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:plug:e9dd9122ce:5971b81c69f74006578b4b92:70ee500a54c0
2023-11-19 19:06:52.500 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:c6f72f80adfe4d53943da716a86fd815
2023-11-19 19:06:52.503 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:53d496838fd842719e71cebee9d648e3
2023-11-19 19:06:52.524 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:1135ceb2a84d4249b6c66594242f7c68
2023-11-19 19:06:52.564 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:room:e9dd9122ce:5971b81c69f74006578b4b92:42498674
2023-11-19 19:06:52.570 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:0d6f7eaf7a1b4d9c878ad8665aaccbbe
2023-11-19 19:06:52.602 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:thermostat:e9dd9122ce:5971b81c69f74006578b4b92:70ee500a54c0:0400000a3946
2023-11-19 19:06:52.605 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:welcome:e9dd9122ce:5971b81c69f74006578b4b92:70ee5080de84
2023-11-19 19:06:52.608 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:person:e9dd9122ce:5971b81c69f74006578b4b92:be22c1ce76a248ef83df5a700f8c2810
2023-11-19 19:06:54.454 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=5971b81c69f74006578b4b92
2023-11-19 19:06:54.458 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer 5664244767e48246a48b4925|8f827bb581695709993c3756072456fa
2023-11-19 19:06:54.601 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"body":{"homes"

When I activate the "netatmo:plug" thing, the relay, it tells me that it can connect

2023-11-19 19:10:58.522 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:plug:e9dd9122ce:5971b81c69f74006578b4b92:70ee500a54c0
2023-11-19 19:10:58.557 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:thermostat:e9dd9122ce:5971b81c69f74006578b4b92:70ee500a54c0:0400000a3946
2023-11-19 19:11:00.529 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/getevents?home_id=5971b81c69f74006578b4b92
2023-11-19 19:11:00.533 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer 5664244767e48246a48b4925|8f827bb581695709993c3756072456fa
2023-11-19 19:11:00.685 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"body":{"home":...

But, it remains at UNKNOWN

Steps to Reproduce (for Bugs)

To test, if the problem was coming from, I created a new token, and then, in Docker, I created 2 containers:

  • OH 4.1 M3
  • OH 3.4.5

The 2 installations are clean with only the Netatmo binding to install
I first tried setting up the 4.1 container. Same problem as on my OH 4.0, the "netatmo:plug" things linked to the "netatmo:home" bridge go UNKNOW.
Then, I configured the 3.4.5 container with the same token as the 4.1, and everything continued, the "netatmo:plug" things went ONLINE.
In addition, in version 3.4.5, OH sees 17 things after scanning compared to 7 in version 4.1

Your Environment

My main OH 4.0.4 works on a dedicated machine under armbian bullseyes. The installed java is openjdk 17.0.8 2023-07-18 LTS
My OHs under Docker run on a Debian VM. The java for OH 3.4 is openjdk 11.0.20 2023-07-18 and for OH 4.1 openjdk version "17.0.9" 2023-10-17

@Matt2cv Matt2cv added the bug An unexpected problem or unintended behavior of an add-on label Nov 19, 2023
@simone-giudici
Copy link

I have the same problem with the same devices.
The Welcome Camera, even if it appears ONLINE, the channels values are not updating.
The Thermostat appears as UNKNOWN with no information in the logs despect the log verbosity.

After trying to discover what was going on, I disabled and re-enabled multiple times both the Bridge and the Things, I started receiving MAXIMUM_USAGE_REACHED error from Netatmo API.

I guess there some memory-leaks because after disabling all the Bridges and the Things, I still have these logs (after several minutes):

2023-12-01 21:22:09.580 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler of thing netatmo:account:netatmo_account tried checking if channel monitoring#request-count is linked although the handler was already disposed.
2023-12-01 21:22:09.631 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler tried updating the thing status although the handler was already disposed.
2023-12-01 21:22:09.631 [WARN ] [andler.capability.SecurityCapability] - Error retrieving last events for home '<<HOME_ID>>' : Rest call failed: statusCode=MAXIMUM_USAGE_REACHED, message=Application usage reached
2023-12-01 21:22:09.939 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler of thing netatmo:account:netatmo_account tried checking if channel monitoring#request-count is linked although the handler was already disposed.
2023-12-01 21:22:09.985 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler tried updating the thing status although the handler was already disposed.
2023-12-01 21:22:09.985 [WARN ] [andler.capability.SecurityCapability] - Error retrieving last events for home '<<HOME_ID>>' : Rest call failed: statusCode=MAXIMUM_USAGE_REACHED, message=Application usage reached

I am using docker.

@clinique
Copy link
Contributor

clinique commented Dec 3, 2023

I guess there some memory-leaks because after disabling all the Bridges and the Things, I still have these logs (after several minutes):

2023-12-01 21:22:09.580 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler of thing netatmo:account:netatmo_account tried checking if channel monitoring#request-count is linked although the handler was already disposed.
2023-12-01 21:22:09.631 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler tried updating the thing status although the handler was already disposed.
2023-12-01 21:22:09.631 [WARN ] [andler.capability.SecurityCapability] - Error retrieving last events for home '<<HOME_ID>>' : Rest call failed: statusCode=MAXIMUM_USAGE_REACHED, message=Application usage reached
2023-12-01 21:22:09.939 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler of thing netatmo:account:netatmo_account tried checking if channel monitoring#request-count is linked although the handler was already disposed.
2023-12-01 21:22:09.985 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler tried updating the thing status although the handler was already disposed.
2023-12-01 21:22:09.985 [WARN ] [andler.capability.SecurityCapability] - Error retrieving last events for home '<<HOME_ID>>' : Rest call failed: statusCode=MAXIMUM_USAGE_REACHED, message=Application usage reached

I am using docker.

I observed this from time to time on my prod environment but I currently fail reproducing it in dev. I know the problem exists and would love fix it...

@lolodomo
Copy link
Contributor

lolodomo commented Dec 3, 2023

Can you please update the issue title because of course the netatmo generally works in OH 4.x.

@Matt2cv
Copy link
Author

Matt2cv commented Dec 4, 2023

Can you please update the issue title because of course the netatmo generally works in OH 4.x.

But, in my case, after the upgrade to 4.0 from 3.5, the binding Netatmo Energy doesn't work. It works on fresh install of OH 3.5 and it doesn't work on fresh install of OH 4.1

@lolodomo
Copy link
Contributor

lolodomo commented Dec 4, 2023

If the problem concerns the thermostat, please mention it.

The binding is working well for me, so there is no general problem but rather a problem with particular devices, I guess.

@simone-giudici
Copy link

If the problem concerns the thermostat, please mention it.

The binding is working well for me, so there is no general problem but rather a problem with particular devices, I guess.

The problem, in my case, is not related to the thermostat, but to all the things/bridges linked to "Home".
I don't know if it is something related to home configuration (Netatmo-side), I have Thermostat and Welcome Camera configured in the same room.

I did the following steps in a clean environment:

  • Download the latest stable version 4.0.4 (for Windows)
  • Installed the binding Netatmo from the marketplace
  • Added the "Account Bridge"
  • Opened the URL for the authorization -> granted the authorization
    • "Account Bridge" status: ONLINE
  • Added "Home Bridge" (linked to the account bridge)
    • "Home Bridge" status: ONLINE
  • Added "Room Thing" (linked to Home Bridge)
    • "Room Thing" status: UNKNWOWN
  • Added "Plug Bridge" (linked to Home Bridge)
    • "Plug Thing" status: UNKNOWN

These are the logs of the previous steps:

2023-12-04 20:50:12.919 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Initializing Netatmo API bridge handler.
2023-12-04 20:50:12.924 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Authorization failed, restarting authorization flow
2023-12-04 20:50:12.937 [INFO ] [etatmo.internal.servlet.GrantServlet] - Registered Netatmo servlet at '/netatmo/connect/656e2bcd1bdde7877e0dea8a'
2023-12-04 20:50:31.005 [DEBUG] [etatmo.internal.servlet.GrantServlet] - Netatmo auth callback servlet received GET request /netatmo/connect/656e2bcd1bdde7877e0dea8a.
2023-12-04 20:50:45.179 [DEBUG] [etatmo.internal.servlet.GrantServlet] - Netatmo auth callback servlet received GET request /netatmo/connect/656e2bcd1bdde7877e0dea8a.
2023-12-04 20:50:45.498 [DEBUG] [etatmo.internal.servlet.GrantServlet] - Stopping Netatmo Servlet /netatmo/connect/656e2bcd1bdde7877e0dea8a
2023-12-04 20:50:45.504 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Connecting to Netatmo API.
2023-12-04 20:51:12.331 [DEBUG] [tatmo.internal.handler.DeviceHandler] - Initializing handler for bridge netatmo:home:9249beead7:b347bfdb87
2023-12-04 20:51:14.336 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=59c3f400a467a38a298be451 
2023-12-04 20:51:14.338 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer <<ACCESS_TOKEN>>
2023-12-04 20:51:14.548 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"body":{"homes":[{"id":"59c3f400a467a38a298be451","name":"casa","altitude":354,"coordinates":[8.828007,45.730064], ...
2023-12-04 20:51:14.568 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homestatus?home_id=59c3f400a467a38a298be451 
2023-12-04 20:51:14.569 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer <<ACCESS_TOKEN>>
2023-12-04 20:51:14.652 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"status":"ok","time_server":1701719475,"body":{"home":{"id":"59c3f400a467a38a298be451","rooms":[{"id":"3889586685", ...
2023-12-04 20:51:14.671 [DEBUG] [handler.capability.RefreshCapability] - Module refreshed, next one in 180 s
2023-12-04 20:51:27.260 [DEBUG] [.netatmo.internal.action.RoomActions] - Netatmo RoomActions service created
2023-12-04 20:51:27.276 [DEBUG] [tatmo.internal.handler.ModuleHandler] - Initializing handler for thing netatmo:room:b347bfdb87:3155eadc04
2023-12-04 20:51:29.279 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homesdata?home_id=59c3f400a467a38a298be451 
2023-12-04 20:51:29.280 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer <<ACCESS_TOKEN>>
2023-12-04 20:51:29.529 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"body":{"homes":[{"id":"59c3f400a467a38a298be451","name":"casa","altitude":354,"coordinates":[8.828007,45.730064], ...
2023-12-04 20:51:29.537 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/homestatus?home_id=59c3f400a467a38a298be451 
2023-12-04 20:51:29.538 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer <<ACCESS_TOKEN>>
2023-12-04 20:51:29.817 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"status":"ok","time_server":1701719490,"body":{"home":{"id":"59c3f400a467a38a298be451","rooms":[{"id":"3889586685", ...
2023-12-04 20:51:29.818 [TRACE] [mo.internal.handler.ApiBridgeHandler] - executeUri GET  https://api.netatmo.com/api/getevents?home_id=59c3f400a467a38a298be451 
2023-12-04 20:51:29.819 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -with headers : Accept-Encoding: gzip, User-Agent: Jetty/9.4.50.v20221201, Authorization: Bearer <<ACCESS_TOKEN>> 
2023-12-04 20:51:29.936 [TRACE] [mo.internal.handler.ApiBridgeHandler] -  -returned : code [200 OK] body {"body":{"home":{"id":"59c3f400a467a38a298be451","events":[{"id":"6567928036b8d7ba72f85673","type":"disconnection", ...

The responses are correct and performed without problems, but the "Room" and "Plug" are still stuck on UNKNOWN status:

image

Items linked to "Home" channels are working fine, but things linked to "Room" or "Plug" channels are not working.

Furthermore I notice that if I save the "Home Bridge" (even if I do not change any properties) the status of the bridge is stuck in UNKNOWN. The only way to unlock it is to disable and re-enable it:

image

@simone-giudici
Copy link

simone-giudici commented Dec 5, 2023

I think I found that the problem is related to the deserialization of /api/homesdata and /api/homestatus responses.

The configuration of Gson with custom desrialization of HomeData and HomeStatus does not consider the scenario where both NATherm1 and NACamera are defined:

.registerTypeAdapter(HomeStatus.class,
        (JsonDeserializer<HomeStatus>) (json, type, context) -> context.deserialize(json,
                json.getAsJsonObject().has("persons") ? NAHomeStatus.Security.class
                        : NAHomeStatus.Energy.class))
.registerTypeAdapter(HomeData.class,
        (JsonDeserializer<HomeData>) (json, type, context) -> context.deserialize(json,
                json.getAsJsonObject().has("therm_mode") ? HomeData.Energy.class
                        : HomeData.Security.class))

In my scenario, where I have both Security and Energy, I have the following JSON for homesdata endpoints:

/api/homesdata

{
  "body": {
    "homes": [
      {
        ...
        "rooms": [
          ...
        ],
        "modules": [
          {
            "type": "NACamera",
            ...
          },
          {
            "type": "NAPlug",
            ...
          },
          {
            "type": "NATherm1",
            ...
          }
        ],
        "temperature_control_mode": "heating",
        "therm_mode": "schedule",
        "therm_setpoint_default_duration": 180,
        "persons": [
          ...
        ],
        "schedules": [
          ...
        ]
      }
    ],
    "user": {}
  },
  "status": "ok",
  "time_exec": 0.050824880599975586,
  "time_server": 1701817075
}

/api/homestatus

{
  "status": "ok",
  "time_server": 1701817379,
  "body": {
    "home": {
      ...
      "rooms": [
        ...
      ],
      "modules": [
        ...
      ],
      "persons": [
        ...
      ]
    },
    "errors": [
      ...
    ]
  }
}

Based on the configuration of Gson I have the following behaviour:

  • HomeData is always deserialized using HomeData.Energy class because therm_mode is present
  • HomeStatus is always deserialized using NAHomeStatus.Security class because persons is present

I did a test forcing the usage of NAHomeStatus.Energy for deserialization of HomeStatus and the Room, Plug and Thermostat came back ONLINE with channels updated.

I thought to propose a change, but I am not a Java expert not even on the binding source code and logic.

@clinique what do you think?

@clinique
Copy link
Contributor

clinique commented Dec 6, 2023

Can you provide your things definition?
Note : your analysis seems valid and I'll have to figure how to handle this and your things definition will help.

@Matt2cv Matt2cv changed the title Binding Netatmo doesn't work after OH 4.x Things linked to the bridge "netatmo:home" doesn't work after OH 4.x Dec 6, 2023
@jlaur jlaur changed the title Things linked to the bridge "netatmo:home" doesn't work after OH 4.x [netatmo] Things linked to the bridge "netatmo:home" doesn't work after OH 4.x Dec 6, 2023
@simone-giudici
Copy link

Here it is:

netatmo:account:netatmo_account (Type=Bridge, Status=ONLINE, Label=Netatmo Account, Bridge=null)
netatmo:home:netatmo_account:netatmo_home (Type=Bridge, Status=ONLINE, Label=Home, Bridge=netatmo:account:netatmo_account)
netatmo:room:netatmo_home:netatmo_room (Type=Thing, Status=UNKNOWN, Label=Room, Bridge=netatmo:home:netatmo_account:netatmo_home)
netatmo:welcome:netatmo_home:netatmo_welcome (Type=Bridge, Status=UNKNOWN, Label=Videocamera da Interno Smart, Bridge=netatmo:home:netatmo_account:netatmo_home)
netatmo:person:netatmo_home:netatmo_person_me (Type=Thing, Status=ONLINE, Label=Me, Bridge=netatmo:home:netatmo_account:netatmo_home)
netatmo:plug:netatmo_home:netatmo_plug (Type=Bridge, Status=UNKNOWN, Label=Plug, Bridge=netatmo:home:netatmo_account:netatmo_home)
netatmo:thermostat:netatmo_plug:netatmo_thermostat (Type=Thing, Status=OFFLINE (BRIDGE_OFFLINE), Label=Thermostat, Bridge=netatmo:plug:netatmo_home:netatmo_plug)

@wzbfyb
Copy link
Contributor

wzbfyb commented Dec 7, 2023

same here, my homes data:

{ "body": { "homes": [ { "id": "xxx", "name": "Mein Zuhause", "altitude": 189, "coordinates": [ x.3662, x.2049 ], "country": "AT", "timezone": "Europe/Vienna", "rooms": [ { "id": "2848277719", "name": "Küche", "type": "kitchen", "module_ids": [ "04:00:00:10:2a:72" ] }, { "id": "4013475661", "name": "Wohnzimmer", "type": "livingroom", "module_ids": [ "09:00:00:15:03:5f" ] }, { "id": "3993864841", "name": "Schlafzimmer", "type": "bedroom", "module_ids": [ "09:00:00:06:f6:ea" ] }, { "id": "533285641", "name": "Bad", "type": "bathroom", "module_ids": [ "09:00:00:12:ee:ed" ] } ], "modules": [ { "id": "70:ee:50:10:29:c8", "type": "NAPlug", "name": "Relais", "setup_date": 1575012650, "modules_bridged": [ "04:00:00:10:2a:72", "09:00:00:06:f6:ea", "09:00:00:12:ee:ed", "09:00:00:15:03:5f" ] }, { "id": "04:00:00:10:2a:72", "type": "NATherm1", "name": "Raumthermostat", "setup_date": 1575012650, "room_id": "2848277719", "bridge": "70:ee:50:10:29:c8" }, { "id": "09:00:00:06:f6:ea", "type": "NRV", "name": "Erker", "setup_date": 1576226957, "room_id": "3993864841", "bridge": "70:ee:50:10:29:c8" }, { "id": "09:00:00:12:ee:ed", "type": "NRV", "name": "Handtuchwärmer", "setup_date": 1577608773, "room_id": "533285641", "bridge": "70:ee:50:10:29:c8" }, { "id": "09:00:00:15:03:5f", "type": "NRV", "name": "Wohnzimmer", "setup_date": 1611736337, "room_id": "4013475661", "bridge": "70:ee:50:10:29:c8" } ], "temperature_control_mode": "heating", "therm_mode": "schedule", "therm_setpoint_default_duration": 180, "schedules": [ { "timetable": [ { "zone_id": 1, "m_offset": 0 }, { "zone_id": 1524, "m_offset": 360 }, { "zone_id": 0, "m_offset": 480 }, { "zone_id": 1, "m_offset": 1260 }, { "zone_id": 1524, "m_offset": 1800 }, { "zone_id": 0, "m_offset": 1920 }, { "zone_id": 1, "m_offset": 2700 }, { "zone_id": 1524, "m_offset": 3240 }, { "zone_id": 0, "m_offset": 3360 }, { "zone_id": 1, "m_offset": 4140 }, { "zone_id": 1524, "m_offset": 4680 }, { "zone_id": 0, "m_offset": 4800 }, { "zone_id": 1, "m_offset": 5580 }, { "zone_id": 1524, "m_offset": 6120 }, { "zone_id": 0, "m_offset": 6240 }, { "zone_id": 1, "m_offset": 7020 }, { "zone_id": 0, "m_offset": 7560 }, { "zone_id": 1, "m_offset": 8460 }, { "zone_id": 0, "m_offset": 9000 }, { "zone_id": 1, "m_offset": 9900 } ], "zones": [ { "name": "Nacht", "id": 1, "type": 1, "rooms_temp": [ { "room_id": "533285641", "temp": 16 }, { "room_id": "2848277719", "temp": 18 }, { "room_id": "3993864841", "temp": 19 }, { "room_id": "4013475661", "temp": 16 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 16 }, { "id": "2848277719", "therm_setpoint_temperature": 18 }, { "id": "3993864841", "therm_setpoint_temperature": 19 }, { "id": "4013475661", "therm_setpoint_temperature": 16 } ] }, { "name": "", "id": 4, "type": 5, "rooms_temp": [ { "room_id": "2848277719", "temp": 16 }, { "room_id": "3993864841", "temp": 16 }, { "room_id": "533285641", "temp": 16 }, { "room_id": "4013475661", "temp": 16 } ], "rooms": [ { "id": "2848277719", "therm_setpoint_temperature": 16 }, { "id": "3993864841", "therm_setpoint_temperature": 16 }, { "id": "533285641", "therm_setpoint_temperature": 16 }, { "id": "4013475661", "therm_setpoint_temperature": 16 } ] }, { "name": "Komfort +", "id": 3, "type": 8, "rooms_temp": [ { "room_id": "533285641", "temp": 22 }, { "room_id": "2848277719", "temp": 22 }, { "room_id": "3993864841", "temp": 22 }, { "room_id": "4013475661", "temp": 22 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 22 }, { "id": "2848277719", "therm_setpoint_temperature": 22 }, { "id": "3993864841", "therm_setpoint_temperature": 22 }, { "id": "4013475661", "therm_setpoint_temperature": 22 } ] }, { "name": "Komfort", "id": 0, "type": 0, "rooms_temp": [ { "room_id": "533285641", "temp": 20 }, { "room_id": "2848277719", "temp": 20 }, { "room_id": "3993864841", "temp": 20 }, { "room_id": "4013475661", "temp": 20 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 20 }, { "id": "2848277719", "therm_setpoint_temperature": 20 }, { "id": "3993864841", "therm_setpoint_temperature": 20 }, { "id": "4013475661", "therm_setpoint_temperature": 20 } ] }, { "name": "Wintermorgen", "id": 1524, "type": 4, "rooms_temp": [ { "room_id": "533285641", "temp": 22 }, { "room_id": "2848277719", "temp": 21 }, { "room_id": "3993864841", "temp": 21 }, { "room_id": "4013475661", "temp": 20.5 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 22 }, { "id": "2848277719", "therm_setpoint_temperature": 21 }, { "id": "3993864841", "therm_setpoint_temperature": 21 }, { "id": "4013475661", "therm_setpoint_temperature": 20.5 } ] } ], "name": "Winter", "default": false, "away_temp": 15, "hg_temp": 7, "id": "5de0c92a462461ca1a22df8e", "type": "therm" }, { "timetable": [ { "zone_id": 1, "m_offset": 0 }, { "zone_id": 4, "m_offset": 360 }, { "zone_id": 1, "m_offset": 1260 }, { "zone_id": 4, "m_offset": 1800 }, { "zone_id": 1, "m_offset": 2700 }, { "zone_id": 4, "m_offset": 3240 }, { "zone_id": 1, "m_offset": 4140 }, { "zone_id": 4, "m_offset": 4680 }, { "zone_id": 1, "m_offset": 5580 }, { "zone_id": 4, "m_offset": 6120 }, { "zone_id": 1, "m_offset": 7020 }, { "zone_id": 4, "m_offset": 7560 }, { "zone_id": 1, "m_offset": 8460 }, { "zone_id": 4, "m_offset": 9000 }, { "zone_id": 1, "m_offset": 9900 } ], "zones": [ { "name": "Komfort", "id": 0, "type": 0, "rooms_temp": [ { "room_id": "533285641", "temp": 20 }, { "room_id": "2848277719", "temp": 20 }, { "room_id": "3993864841", "temp": 19 }, { "room_id": "4013475661", "temp": 19 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 20 }, { "id": "2848277719", "therm_setpoint_temperature": 20 }, { "id": "3993864841", "therm_setpoint_temperature": 19 }, { "id": "4013475661", "therm_setpoint_temperature": 19 } ] }, { "name": "Nacht", "id": 1, "type": 1, "rooms_temp": [ { "room_id": "533285641", "temp": 16 }, { "room_id": "2848277719", "temp": 16 }, { "room_id": "3993864841", "temp": 19.5 }, { "room_id": "4013475661", "temp": 16 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 16 }, { "id": "2848277719", "therm_setpoint_temperature": 16 }, { "id": "3993864841", "therm_setpoint_temperature": 19.5 }, { "id": "4013475661", "therm_setpoint_temperature": 16 } ] }, { "name": "Komfort+", "id": 3, "type": 8, "rooms_temp": [ { "room_id": "533285641", "temp": 21 }, { "room_id": "2848277719", "temp": 21 }, { "room_id": "3993864841", "temp": 21 }, { "room_id": "4013475661", "temp": 19 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 21 }, { "id": "2848277719", "therm_setpoint_temperature": 21 }, { "id": "3993864841", "therm_setpoint_temperature": 21 }, { "id": "4013475661", "therm_setpoint_temperature": 19 } ] }, { "name": "", "id": 4, "type": 5, "rooms_temp": [ { "room_id": "2848277719", "temp": 16 }, { "room_id": "3993864841", "temp": 16 }, { "room_id": "533285641", "temp": 16 }, { "room_id": "4013475661", "temp": 16 } ], "rooms": [ { "id": "2848277719", "therm_setpoint_temperature": 16 }, { "id": "3993864841", "therm_setpoint_temperature": 16 }, { "id": "533285641", "therm_setpoint_temperature": 16 }, { "id": "4013475661", "therm_setpoint_temperature": 16 } ] } ], "name": "sommer Daheim", "default": false, "away_temp": 12, "hg_temp": 7, "id": "5e97ea6e7e201155f11bd376", "type": "therm" }, { "timetable": [ { "zone_id": 1, "m_offset": 0 }, { "zone_id": 0, "m_offset": 360 }, { "zone_id": 1, "m_offset": 1320 }, { "zone_id": 0, "m_offset": 1800 }, { "zone_id": 1, "m_offset": 2760 }, { "zone_id": 0, "m_offset": 3240 }, { "zone_id": 1, "m_offset": 4200 }, { "zone_id": 0, "m_offset": 4680 }, { "zone_id": 1, "m_offset": 5640 }, { "zone_id": 0, "m_offset": 6120 }, { "zone_id": 1, "m_offset": 7080 }, { "zone_id": 0, "m_offset": 7560 }, { "zone_id": 1, "m_offset": 8520 }, { "zone_id": 0, "m_offset": 9000 }, { "zone_id": 1, "m_offset": 9960 } ], "zones": [ { "name": "Night", "id": 1, "type": 1, "rooms_temp": [ { "room_id": "2848277719", "temp": 17.5 }, { "room_id": "3993864841", "temp": 18.5 }, { "room_id": "533285641", "temp": 17.5 }, { "room_id": "4013475661", "temp": 16 } ], "rooms": [ { "id": "2848277719", "therm_setpoint_temperature": 17.5 }, { "id": "3993864841", "therm_setpoint_temperature": 18.5 }, { "id": "533285641", "therm_setpoint_temperature": 17.5 }, { "id": "4013475661", "therm_setpoint_temperature": 16 } ] }, { "name": "Comfort+", "id": 3, "type": 8, "rooms_temp": [ { "room_id": "2848277719", "temp": 20.5 }, { "room_id": "3993864841", "temp": 18.5 }, { "room_id": "533285641", "temp": 22.5 }, { "room_id": "4013475661", "temp": 19 } ], "rooms": [ { "id": "2848277719", "therm_setpoint_temperature": 20.5 }, { "id": "3993864841", "therm_setpoint_temperature": 18.5 }, { "id": "533285641", "therm_setpoint_temperature": 22.5 }, { "id": "4013475661", "therm_setpoint_temperature": 19 } ] }, { "name": "Eco", "id": 4, "type": 5, "rooms_temp": [ { "room_id": "2848277719", "temp": 16 }, { "room_id": "3993864841", "temp": 16 }, { "room_id": "533285641", "temp": 16 }, { "room_id": "4013475661", "temp": 16 } ], "rooms": [ { "id": "2848277719", "therm_setpoint_temperature": 16 }, { "id": "3993864841", "therm_setpoint_temperature": 16 }, { "id": "533285641", "therm_setpoint_temperature": 16 }, { "id": "4013475661", "therm_setpoint_temperature": 16 } ] }, { "name": "Komfort", "id": 0, "type": 0, "rooms_temp": [ { "room_id": "533285641", "temp": 20.5 }, { "room_id": "2848277719", "temp": 20.5 }, { "room_id": "3993864841", "temp": 20.5 }, { "room_id": "4013475661", "temp": 20.5 } ], "rooms": [ { "id": "533285641", "therm_setpoint_temperature": 20.5 }, { "id": "2848277719", "therm_setpoint_temperature": 20.5 }, { "id": "3993864841", "therm_setpoint_temperature": 20.5 }, { "id": "4013475661", "therm_setpoint_temperature": 20.5 } ] } ], "name": "Übergangszeit", "default": false, "away_temp": 12, "hg_temp": 7, "id": "5f6d754464947713820c6da4", "type": "therm", "selected": true } ] } ], "user": { "email": "bernhard.kreuz@mailbox.org", "language": "de-DE", "locale": "de-AT", "feel_like_algorithm": 0, "unit_pressure": 0, "unit_system": 0, "unit_wind": 0, "id": "5db2afe3dfd1ec000b3df692" } }, "status": "ok", "time_exec": 0.04825115203857422, "time_server": 1701982244 }

@clinique clinique self-assigned this Dec 9, 2023
@clinique
Copy link
Contributor

clinique commented Dec 9, 2023

@simone-giudici , can you please test this

@simone-giudici
Copy link

I tried to install the binding in a clean 4.1.0-SNAPSHOT environment, but it does not work:

2023-12-10 21:54:14.371 [WARN ] [ore.thing.internal.ThingRegistryImpl] - Cannot create thing. No binding found that supports creating a thing of type 'netatmo:account'.

Maybe I am doing something wrong.

@clinique
Copy link
Contributor

@simone-giudici : you may need to grand your bridge on this new environment. On my side it works in dev.

@simone-giudici
Copy link

Sorry, but I don't know what you mean with "grant your bridge".
I can not even going to the servlet to grant the authorization.

The openHAB version on which I did the test is:
openHAB 4.1.0
Build # 3764

Adding netatmo_account bridge with the .jar you provide:

netatmo_from_jar

2023-12-11 20:28:36.863 [DEBUG] [ore.thing.internal.ThingRegistryImpl] - Creating thing for type 'netatmo:account'.
2023-12-11 20:28:36.863 [WARN ] [ore.thing.internal.ThingRegistryImpl] - Cannot create thing. No binding found that supports creating a thing of type 'netatmo:account'.
2023-12-11 20:28:36.865 [DEBUG] [e.model.rule.jvmmodel.RulesRefresher] - Thing "netatmo:account:7b28784f6d" added => rules are going to be refreshed
2023-12-11 20:28:36.866 [DEBUG] [core.thing.internal.ThingManagerImpl] - Thing 'netatmo:account:7b28784f6d' is tracked by ThingManager.
2023-12-11 20:28:36.866 [DEBUG] [core.thing.internal.ThingManagerImpl] - Not registering a handler at this point since no handler factory for thing 'netatmo:account:7b28784f6d' found.
2023-12-11 20:28:36.867 [DEBUG] [core.thing.internal.ThingManagerImpl] - Not registering a handler at this point. No handler factory for thing 'netatmo:account:7b28784f6d' found.
2023-12-11 20:28:36.867 [DEBUG] [mon.registry.AbstractManagedProvider] - Added new element netatmo:account:7b28784f6d to ManagedThingProvider.
2023-12-11 20:28:39.004 [DEBUG] [openhab.core.io.rest.sse.SseResource] - Sending alive event to SSE connections
2023-12-11 20:28:39.183 [DEBUG] [nfig.core.status.ConfigStatusService] - There is no config status provider for entity netatmo:account:7b28784f6d available.
2023-12-11 20:28:39.184 [DEBUG] [onfig.core.ConfigDescriptionRegistry] - No config description found for 'thing:netatmo:account:7b28784f6d', using alias 'netatmo:api_bridge' instead

Adding netatmo_account bridge with the binding installed through the "Add-on Store" (expected behaviour):

netatmo_from_market

2023-12-11 20:50:36.986 [DEBUG] [ore.thing.internal.ThingRegistryImpl] - Creating thing for type 'netatmo:account'.
2023-12-11 20:50:36.987 [DEBUG] [e.model.rule.jvmmodel.RulesRefresher] - Thing "netatmo:account:66d2c0b898" added => rules are going to be refreshed
2023-12-11 20:50:36.987 [DEBUG] [core.thing.internal.ThingManagerImpl] - Thing 'netatmo:account:66d2c0b898' is tracked by ThingManager.
2023-12-11 20:50:36.988 [DEBUG] [core.thing.internal.ThingManagerImpl] - Config description URI for 'netatmo:request-count' not found, assuming 'netatmo:account:66d2c0b898:monitoring#request-count' is normalized
2023-12-11 20:50:36.988 [DEBUG] [core.thing.internal.ThingManagerImpl] - Calling 'NetatmoHandlerFactory.registerHandler()' for thing 'netatmo:account:66d2c0b898'.
2023-12-11 20:50:36.989 [DEBUG] [nternal.DiscoveryServiceRegistryImpl] - bundle org.openhab.core.config.discovery:4.1.0.202312100308 (166)[org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl(117)] : dm DiscoveryService tracking 7 MultipleDynamic added {org.openhab.core.config.discovery.DiscoveryService}={service.id=518, service.bundleid=252, service.scope=singleton} (enter)
2023-12-11 20:50:36.989 [DEBUG] [nternal.DiscoveryServiceRegistryImpl] - bundle org.openhab.core.config.discovery:4.1.0.202312100308 (166)[org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl(117)] : dm DiscoveryService tracking 7 MultipleDynamic already active, binding {org.openhab.core.config.discovery.DiscoveryService}={service.id=518, service.bundleid=252, service.scope=singleton}
2023-12-11 20:50:36.989 [DEBUG] [nternal.DiscoveryServiceRegistryImpl] - bundle org.openhab.core.config.discovery:4.1.0.202312100308 (166)[org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl(117)] : invoking bind: addDiscoveryService: parameters [org.openhab.binding.netatmo.internal.discovery.NetatmoDiscoveryService]
2023-12-11 20:50:36.990 [DEBUG] [nternal.DiscoveryServiceRegistryImpl] - bundle org.openhab.core.config.discovery:4.1.0.202312100308 (166)[org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl(117)] : invoked bind: addDiscoveryService
2023-12-11 20:50:36.990 [DEBUG] [nternal.DiscoveryServiceRegistryImpl] - bundle org.openhab.core.config.discovery:4.1.0.202312100308 (166)[org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl(117)] : dm DiscoveryService tracking 7 MultipleDynamic added {org.openhab.core.config.discovery.DiscoveryService}={service.id=518, service.bundleid=252, service.scope=singleton} (exit)
2023-12-11 20:50:36.990 [DEBUG] [core.thing.internal.ThingManagerImpl] - Config description URI for 'netatmo:request-count' not found, assuming 'netatmo:account:66d2c0b898:monitoring#request-count' can be initialized
2023-12-11 20:50:36.991 [DEBUG] [core.thing.internal.ThingManagerImpl] - Calling initialize handler for thing 'netatmo:account:66d2c0b898' at 'org.openhab.binding.netatmo.internal.handler.ApiBridgeHandler@7e17ba23'.
2023-12-11 20:50:36.991 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandler" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@74f3e820[org.openhab.core.thing:4.1.0.202312100306(id=216)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2023-12-11 20:50:36.992 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ThingStatusInfo" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@74f3e820[org.openhab.core.thing:4.1.0.202312100306(id=216)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2023-12-11 20:50:36.992 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.binding.ThingHandlerCallback" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@74f3e820[org.openhab.core.thing:4.1.0.202312100306(id=216)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2023-12-11 20:50:36.992 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.Thing" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@74f3e820[org.openhab.core.thing:4.1.0.202312100306(id=216)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2023-12-11 20:50:36.992 [DEBUG] [.internal.common.CombinedClassLoader] - Loaded class "org.openhab.core.thing.ChannelUID" by classloader "org.eclipse.osgi.internal.loader.EquinoxClassLoader@74f3e820[org.openhab.core.thing:4.1.0.202312100306(id=216)]" for "[interface org.openhab.core.thing.binding.ThingHandler]"
2023-12-11 20:50:36.995 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Initializing Netatmo API bridge handler.
2023-12-11 20:50:36.996 [DEBUG] [mon.registry.AbstractManagedProvider] - Added new element netatmo:account:66d2c0b898 to ManagedThingProvider.
2023-12-11 20:50:36.998 [DEBUG] [mo.internal.handler.ApiBridgeHandler] - Authorization failed, restarting authorization flow
2023-12-11 20:50:37.001 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 81 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (enter)
2023-12-11 20:50:37.002 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 81 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (exit)
2023-12-11 20:50:37.002 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 82 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[https://0.0.0.0:8443/, http://0.0.0.0:8080/], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (enter)
2023-12-11 20:50:37.003 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 82 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[https://0.0.0.0:8443/, http://0.0.0.0:8080/], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (exit)
2023-12-11 20:50:37.004 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 83 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (enter)
2023-12-11 20:50:37.004 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 83 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (exit)
2023-12-11 20:50:37.004 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 84 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[https://0.0.0.0:8443/, http://0.0.0.0:8080/], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (enter)
2023-12-11 20:50:37.004 [DEBUG] [rest.internal.resources.RootResource] - bundle org.openhab.core.io.rest:4.1.0.202312100303 (179)[org.openhab.core.io.rest.internal.resources.RootResource(150)] : dm $000 tracking 84 SingleStatic modified {org.osgi.service.jaxrs.runtime.JaxrsServiceRuntime}={service.id=161, osgi.jaxrs.endpoint=[https://0.0.0.0:8443/, http://0.0.0.0:8080/], service.bundleid=64, service.scope=singleton, service.ranking=-2147483648, service.changecount=37, service.pid=org.apache.aries.jax.rs.whiteboard.default} (exit)
2023-12-11 20:50:37.005 [INFO ] [etatmo.internal.servlet.GrantServlet] - Registered Netatmo servlet at '/netatmo/connect/656e27416b669e04d507cef6'

@clinique
Copy link
Contributor

Do you have some other binding installed alongside ? I made a test on a clean environment and faced the same issue than you. I had the Zigbee binding installed - removed it and then everything worked. Very weird.

@simone-giudici
Copy link

simone-giudici commented Dec 11, 2023

I did it on a clean environment, just downloaded from openHAB site.

@clinique
Copy link
Contributor

I guess there some memory-leaks because after disabling all the Bridges and the Things, I still have these logs (after several minutes):

2023-12-01 21:22:09.580 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler of thing netatmo:account:netatmo_account tried checking if channel monitoring#request-count is linked although the handler was already disposed.
2023-12-01 21:22:09.631 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler tried updating the thing status although the handler was already disposed.
2023-12-01 21:22:09.631 [WARN ] [andler.capability.SecurityCapability] - Error retrieving last events for home '<<HOME_ID>>' : Rest call failed: statusCode=MAXIMUM_USAGE_REACHED, message=Application usage reached
2023-12-01 21:22:09.939 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler of thing netatmo:account:netatmo_account tried checking if channel monitoring#request-count is linked although the handler was already disposed.
2023-12-01 21:22:09.985 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ApiBridgeHandler tried updating the thing status although the handler was already disposed.
2023-12-01 21:22:09.985 [WARN ] [andler.capability.SecurityCapability] - Error retrieving last events for home '<<HOME_ID>>' : Rest call failed: statusCode=MAXIMUM_USAGE_REACHED, message=Application usage reached

I am using docker.

I observed this from time to time on my prod environment but I currently fail reproducing it in dev. I know the problem exists and would love fix it...

By the way, working on it, I think I identified two culprits of this. Will create a dedicated PR.

@clinique
Copy link
Contributor

@simone-giudici : can you please try this new one

@simone-giudici
Copy link

I tried also this new one without success.
I also tried to checkout your branch and build it by myself but the error is still the same.

As the binding installed from the marketplace starts, I looked at the logs to try to figure out the differences and I found that it seems to be something related to OSGi dependency resolution.

What I saw is that the marketplace binding, before starting the activation of NetatmoHandlerFactory it resolves OAuthFactoryImpl which makes sense because OAuthFactory is a dependency of the binding.

But when I install the binding from the .jar file, it starts immediately with NetatmoHandlerFactory and then it finish with the message:

2023-12-15 23:17:52.764 [DEBUG] [tatmo.internal.NetatmoHandlerFactory] - bundle org.openhab.binding.netatmo:4.1.0.202312152139 (254)[org.openhab.binding.netatmo.internal.NetatmoHandlerFactory(361)] : Not all dependencies satisfied, cannot activate

openhab-jar.log
openhab-marketplace.log

As the logs are very long, I attached them as a file.

@clinique
Copy link
Contributor

This seems to be core related. I don't understand why it impacts this PR as no modification is done on NetatmoHandlerFactory here, nor on pom.xml file. @lolodomo : would you have a bright idea ?
Looks like the binding starts too early.

@simone-giudici
Copy link

I agree with you. I tried to build the binding from the main branch and the error is still the same.
I don't know if it could be something related to my environment or whatever, because the installation from the marketplace is working fine.

Anyway, I cherry-picked your commit in version 4.0.3 (my productive environment) and at first look it seems working.
The things are now online, but I notice that after a while, they are not updating the items and the following exception is in the log file:

2023-12-12 05:01:20.462 [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) ~[?:?]

Could it be related to a missing initialization of rooms in the HomeStatus class?
Previously, in the nested class Energy, the field was initialized.

Sorry for the delay in my answers but near Christmas I am always busy 😄

@clinique
Copy link
Contributor

You should try to cherrypick this PR #15866, it solves this issue.

@simone-giudici
Copy link

I cherrypick partially #15866 because some changes are not compatible.
It is online for some days and it seems it is working fine 👍
No errors on the log and the items are updating correctly.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug An unexpected problem or unintended behavior of an add-on
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants