[surepetcare] - API change ➡️ HANDLER_INITIALIZING_ERROR

[pgfeller]

after the upgrade to openHAB 4.0.4 & the subsequent system restart the surepetcare does no longer start (HANDLER_INITIALIZING_ERROR).

Expected Behavior

The binding (bridge) should connect and initialize.

Current Behavior

The bridge initialization failes (HANDLER_INITIALIZING_ERROR):

HANDLER_INITIALIZING_ERROR
Text '2023-12-16T21:08:19.637892+00:00' could not be parsed at index 19

The bridge properly authenticates but is not able to parse the .json response received from the server:

2023-12-17 14:06:33.400 [DEBUG] [iscovery.SurePetcareDiscoveryService] - Stopped Sure Petcare device background discovery
2023-12-17 14:06:37.005 [DEBUG] [e.internal.SurePetcareHandlerFactory] - createHandler - create handler for org.openhab.core.thing.internal.BridgeImpl@599f1d9f
2023-12-17 14:06:37.006 [DEBUG] [iscovery.SurePetcareDiscoveryService] - Starting Sure Petcare household discovery
2023-12-17 14:06:37.006 [DEBUG] [iscovery.SurePetcareDiscoveryService] - Scheduled topology-changed job every 12 hours
2023-12-17 14:06:37.009 [DEBUG] [nal.handler.SurePetcareBridgeHandler] - Initializing Sure Petcare bridge handler.
2023-12-17 14:06:37.009 [DEBUG] [nal.handler.SurePetcareBridgeHandler] - Login to SurePetcare API with username: patrik.gfeller@***
2023-12-17 14:06:37.010 [DEBUG] [etcare.internal.SurePetcareAPIHelper] - current MAC address: ***, device id: ***
2023-12-17 14:06:37.012 [DEBUG] [e.internal.SurePetcareHandlerFactory] - createHandler - create handler for org.openhab.core.thing.internal.ThingImpl@1c535532
2023-12-17 14:06:37.013 [DEBUG] [nal.handler.SurePetcareDeviceHandler] - Created device handler for type surepetcare:flapDevice
2023-12-17 14:06:37.013 [DEBUG] [e.internal.SurePetcareHandlerFactory] - createHandler - create handler for org.openhab.core.thing.internal.ThingImpl@8685da70
2023-12-17 14:06:37.014 [DEBUG] [e.internal.SurePetcareHandlerFactory] - createHandler - create handler for org.openhab.core.thing.internal.ThingImpl@8685da8b
2023-12-17 14:06:37.579 [DEBUG] [etcare.internal.SurePetcareAPIHelper] - Login successful
2023-12-17 14:06:37.580 [DEBUG] [nal.handler.SurePetcareBridgeHandler] - Login successful, updating topology cache
2023-12-17 14:06:37.825 [DEBUG] [etcare.internal.SurePetcareAPIHelper] - API execution successful, response: ***
2023-12-17 14:07:37.006 [DEBUG] [iscovery.SurePetcareDiscoveryService] - Starting Sure Petcare discovery scan

The following exception is thrown during the initialization:

java.time.format.DateTimeParseException: Text '2023-12-16T21:08:19.637892+00:00' could not be parsed at index 19
	at java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:2052) ~[?:?]
	at java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1954) ~[?:?]
	at org.openhab.binding.surepetcare.internal.utils.GsonZonedDateTimeTypeAdapter.deserialize(GsonZonedDateTimeTypeAdapter.java:79) ~[?:?]
	at org.openhab.binding.surepetcare.internal.utils.GsonZonedDateTimeTypeAdapter.deserialize(GsonZonedDateTimeTypeAdapter.java:1) ~[?:?]
	at com.google.gson.internal.bind.TreeTypeAdapter.read(TreeTypeAdapter.java:69) ~[?:?]
	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$1.read(ReflectiveTypeAdapterFactory.java:161) ~[?:?]
	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.read(ReflectiveTypeAdapterFactory.java:266) ~[?:?]
	at com.google.gson.internal.bind.TypeAdapterRuntimeTypeWrapper.read(TypeAdapterRuntimeTypeWrapper.java:41) ~[?:?]
	at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.read(CollectionTypeAdapterFactory.java:82) ~[?:?]
	at com.google.gson.internal.bind.CollectionTypeAdapterFactory$Adapter.read(CollectionTypeAdapterFactory.java:61) ~[?:?]
	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$1.read(ReflectiveTypeAdapterFactory.java:161) ~[?:?]
	at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.read(ReflectiveTypeAdapterFactory.java:266) ~[?:?]
	at com.google.gson.Gson.fromJson(Gson.java:1058) ~[?:?]
	at com.google.gson.Gson.fromJson(Gson.java:1129) ~[?:?]
	at com.google.gson.Gson.fromJson(Gson.java:1101) ~[?:?]
	at org.openhab.binding.surepetcare.internal.SurePetcareAPIHelper.updateTopologyCache(SurePetcareAPIHelper.java:140) ~[?:?]
	at org.openhab.binding.surepetcare.internal.handler.SurePetcareBridgeHandler.initialize(SurePetcareBridgeHandler.java:81) ~[?:?]
	at jdk.internal.reflect.GeneratedMethodAccessor48.invoke(Unknown Source) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
	at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) ~[?:?]
	at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	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) ~[?:?]

The .json received seems to use a different timestamp format for $.data.households[0].updated_at:

{
    "data": {
        "devices": [],
        "households": [
            {
                "id": 0,
                "name": "***",
                "share_code": "***",
                "created_user_id": 0,
                "timezone_id": 374,
                "version": "MTE=",
                "created_at": "2021-04-24T11:41:15+00:00",
                "updated_at": "2023-12-16T21:08:19.637892+00:00",
                "invites": [],
                "users": [],
                "timezone": {
                    "id": 374,
                    "name": "(UTC+02:00) Europe/Zurich",
                    "timezone": "Europe/Zurich",
                    "utc_offset": 7200,
                    "created_at": "2017-08-03T08:35:34+00:00",
                    "updated_at": "2017-08-03T08:37:15+00:00"
                }
            }
        ],
        "pets": [],
        "photos": [],
        "tags": [],
        "user": {}
    }
}

➡️ "2023-12-16T21:08:19.637892+00:00"

Possible Solution

The format of the timestamp seems to be defined in

openhab-addons/bundles/org.openhab.binding.surepetcare/src/main/java/org/openhab/binding/surepetcare/internal/utils/GsonZonedDateTimeTypeAdapter.java

Line 38 in d498b49

private static final DateTimeFormatter ZONED_FORMATTER = DateTimeFormatter.ofPattern("yyyy-MM-dd'T'HH:mm:ssxxx");

I assume that a possible approach to solve this issue could be to make the parsing more tolerant. I do not know the options ZONED_FORMATTER provides to achieve this. Another (ugly) approach would be to try the alternate (new?) format to parse in case the default triggers an exception.

Advice what approach should be used would be appreciated.

Context

At the moment the binding can not be used in my setup. It might be that other users are not (yet) affected - as the timestamp indicates a configuration update. Therefore if no changes were made it might be the backend still uses the compatible format.

Your Environment

runtimeInfo:
  version: 4.0.4
  buildString: Release Build
locale: de-CH
systemInfo:
  configFolder: /openhab/conf
  userdataFolder: /openhab/userdata
  logFolder: /openhab/userdata/logs
  javaVersion: 17.0.7
  javaVendor: Debian
  osName: Linux
  osVersion: 6.2.0-39-generic
  osArchitecture: amd64
  availableProcessors: 4
  freeMemory: 525966832
  totalMemory: 1497366528
  startLevel: 100
addons:
  - automation-jsscripting
  - binding-androiddebugbridge
  - binding-astro
  - binding-chromecast
  - binding-comfoair
  - binding-exec
  - binding-feed
  - binding-harmonyhub
  - binding-hpprinter
  - binding-http
  - binding-icalendar
  - binding-jellyfin
  - binding-logreader
  - binding-mail
  - binding-mqtt
  - binding-network
  - binding-openweathermap
  - binding-samsungtv
  - binding-snmp
  - binding-sonos
  - binding-spotify
  - binding-surepetcare
  - binding-systeminfo
  - binding-unifi
  - binding-zwave
  - misc-openhabcloud
  - persistence-influxdb
  - persistence-mapdb
  - persistence-rrd4j
  - transformation-jinja
  - transformation-jsonpath
  - transformation-map
  - transformation-regex
  - voice-voicerss

Links

• openHAB Forum Post

[openhab-bot]

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/surepetcare-handler-initializing-error-openhab-4-0-4/152088/1

[jlaur]

@pgfeller - can you try this JAR? org.openhab.binding.surepetcare-4.1.0-SNAPSHOT.jar

[pgfeller]

@pgfeller - can you try this JAR? org.openhab.binding.surepetcare-4.1.0-SNAPSHOT.jar

@jlaur - thanks; I did a quick experiment with a 4.1.0 snapshot (clean install with no other binding or addon present). The bridge reports online - but discovery does not work:

2023-12-20 17:42:17.112 [INFO ] [org.openhab.core.Activator          ] - Starting openHAB 4.1.0 (build Build #3794)
2023-12-20 17:42:17.676 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Zurich'.
2023-12-20 17:42:17.678 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'de_CH'.
2023-12-20 17:42:26.602 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2023-12-20 17:42:28.111 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2023-12-20 17:43:30.110 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: Cannot invoke "org.openhab.binding.surepetcare.internal.handler.SurePetcareBridgeHandler.getThing()" because "this.bridgeHandler" is null
	at org.openhab.binding.surepetcare.internal.discovery.SurePetcareDiscoveryService.startScan(SurePetcareDiscoveryService.java:125) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
	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:840) [?:?]
2023-12-20 17:43:50.005 [ERROR] [nternal.DiscoveryServiceRegistryImpl] - Cannot trigger scan for thing types '[surepetcare:bridge]' on 'SurePetcareDiscoveryService'!
java.lang.NullPointerException: Cannot invoke "org.openhab.binding.surepetcare.internal.handler.SurePetcareBridgeHandler.getThing()" because "this.bridgeHandler" is null
	at org.openhab.binding.surepetcare.internal.discovery.SurePetcareDiscoveryService.startScan(SurePetcareDiscoveryService.java:125) ~[?:?]
	at org.openhab.core.config.discovery.AbstractDiscoveryService.startScan(AbstractDiscoveryService.java:195) ~[?:?]
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.startScan(DiscoveryServiceRegistryImpl.java:357) ~[?:?]
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.startScans(DiscoveryServiceRegistryImpl.java:342) ~[?:?]
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.startScan(DiscoveryServiceRegistryImpl.java:208) ~[?:?]
	at org.openhab.core.io.rest.core.internal.discovery.DiscoveryResource.scan(DiscoveryResource.java:105) ~[?:?]
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]

I'll investigate into this to provide more details later as soon as I have some free time ...

[jlaur]

but discovery does not work

That's a regression of #15411, I'll fix that also.

[jlaur]

That's a regression of #15411, I'll fix that also.

Here we go: #16088

[pgfeller]

Is the .jar available as an artifact of the CI - so I can test it; or do you need to build it manually? If a .jar is available I can test it again.

[jlaur]

Is the .jar available as an artifact of the CI - so I can test it; or do you need to build it manually? If a .jar is available I can test it again.

Sure, I have added this fix also and built a new JAR - you can use the same link (it has been replaced).

[pgfeller]

I'll test as soon as possible.