iCloud Binding Communication Error

Sadly not, but it has been merged into 4.0.0.

Dear Colleagues,

my account is gettinf offline time to time asking for the 2FA code. Is it mpossible to extend it somehow
?

Same for me :slightly_frowning_face:

I did not have this problems in the last weeks. If you share your logs, we could try to find out what the reason is.

how do I collect the logs about it?

The logs are normally written to disk depending on your installation, e.g. /var/log/openhab.

The binding has been working much better lately. I noticed it went offline today. It came right back online, but I looked in the openhab.log and found this:

2023-06-03 13:12:47.366 [WARN ] [l.handler.ICloudAccountBridgeHandler] - Unable to refresh device data
java.net.http.HttpConnectTimeoutException: HTTP connect timed out
        at jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:555) ~[java.net.http:?]
        at jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:119) ~[java.net.http:?]
        at org.openhab.binding.icloud.internal.ICloudSession.request(ICloudSession.java:139) ~[?:?]
        at org.openhab.binding.icloud.internal.ICloudSession.post(ICloudSession.java:98) ~[?:?]
        at org.openhab.binding.icloud.internal.FindMyIPhoneServiceManager.refreshClient(FindMyIPhoneServiceManager.java:64) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.lambda$1(ICloudAccountBridgeHandler.java:121) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.callApiWithRetryAndExceptionHandling(ICloudAccountBridgeHandler.java:185) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.lambda$0(ICloudAccountBridgeHandler.java:116) ~[?:?]
        at org.openhab.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:101) ~[?:?]
        at org.openhab.core.cache.ExpiringCache.getValue(ExpiringCache.java:72) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.refreshData(ICloudAccountBridgeHandler.java:389) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
        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:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: java.net.http.HttpConnectTimeoutException: HTTP connect timed out
        at jdk.internal.net.http.MultiExchange.toTimeoutException(MultiExchange.java:512) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.getExceptionalCF(MultiExchange.java:459) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.lambda$responseAsyncImpl$7(MultiExchange.java:386) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930) ~[?:?]
        at java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:907) ~[?:?]
        at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
        at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) ~[?:?]
        at jdk.internal.net.http.Http1Exchange.lambda$cancelImpl$9(Http1Exchange.java:481) ~[java.net.http:?]
        ... 3 more
Caused by: java.net.ConnectException: HTTP connect timed out
        at jdk.internal.net.http.MultiExchange.toTimeoutException(MultiExchange.java:513) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.getExceptionalCF(MultiExchange.java:459) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.lambda$responseAsyncImpl$7(MultiExchange.java:386) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930) ~[?:?]
        at java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:907) ~[?:?]
        at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
        at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) ~[?:?]
        at jdk.internal.net.http.Http1Exchange.lambda$cancelImpl$9(Http1Exchange.java:481) ~[java.net.http:?]
        ... 3 more

The binding wasn’t able to connect to the iCloud API for sometime. Thats more or less normal/has many reasons: problems with your internet connection, techn problems on apple side or “between”, …

Just updated to 4.0.1 stable and icloud (was still on a Snapshot) works mostly fine again. Thanks very much.

Just “play Sound” on phone doesn’t work. Failure in Log:

2023-07-29 15:44:43.984 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.icloud.internal.handler.ICloudDeviceHandler@64a521a1': Retry finally failed.
org.openhab.binding.icloud.internal.RetryException: Retry finally failed.
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.callApiWithRetryAndExceptionHandling(ICloudAccountBridgeHandler.java:216) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.findMyDevice(ICloudAccountBridgeHandler.java:290) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudDeviceHandler.handleCommand(ICloudDeviceHandler.java:145) ~[?:?]
        at jdk.internal.reflect.GeneratedMethodAccessor287.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.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) ~[?:?]
        at jdk.proxy4807.$Proxy4954.handleCommand(Unknown Source) ~[?:?]
        at org.openhab.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:85) ~[?:?]
        at org.openhab.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) ~[?:?]
        at jdk.internal.reflect.GeneratedMethodAccessor286.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) ~[?:?]
Caused by: org.openhab.binding.icloud.internal.ICloudApiResponseException: Request https://p53-fmipweb.icloud.com:443/fmipservice/client/web/playSound failed with 500.
        at org.openhab.binding.icloud.internal.ICloudSession.request(ICloudSession.java:148) ~[?:?]
        at org.openhab.binding.icloud.internal.ICloudSession.post(ICloudSession.java:98) ~[?:?]
        at org.openhab.binding.icloud.internal.FindMyIPhoneServiceManager.playSound(FindMyIPhoneServiceManager.java:77) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.lambda$5(ICloudAccountBridgeHandler.java:294) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.callApiWithRetryAndExceptionHandling(ICloudAccountBridgeHandler.java:185) ~[?:?]
        ... 19 more

Is this function not assisted anymore?

Thanks for the hint. Same problem here. It might be a bug in the binding or an API change on Apple side. Somebody has to look into the code/debug to find out.

I’m seeing my iCloud account Thing drop offline occasionally. Often it reconnects, but sometimes it doesn’t after many hours. If I disable and re-enable the thing, it comes back on line. Here is the log from today. The reconnect after several hours is when I cycled the thing


openhabian@openhabian-spring4:/var/log/openhab $ zcat events.log.14.gz | grep -i icloud:account
2023-08-18 06:17:42.751 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from ONLINE to OFFLINE (CONFIGURATION_ERROR): Invalid credentials.
2023-08-18 06:17:42.958 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from OFFLINE (CONFIGURATION_ERROR): Invalid credentials. to OFFLINE: Wait for login
2023-08-18 11:15:33.199 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from OFFLINE: Wait for login to UNINITIALIZED
2023-08-18 11:15:33.216 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2023-08-18 11:15:33.295 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (NOT_YET_READY)
2023-08-18 11:15:34.271 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from UNINITIALIZED (NOT_YET_READY) to INITIALIZING
2023-08-18 11:15:34.283 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from INITIALIZING to UNKNOWN
2023-08-18 11:15:40.736 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'icloud:account:iCloudAccountBridgeThing' changed from UNKNOWN to ONLINE

I have made a rule to restart the binding bundle if it stays off line for 15 minutes. That seems to take care of the problem, but is a rather brute force approach. (That rule wasn’t working for the above because when I migrated to OH4 and used the release binding instead of the .jar file, I failed to take the .jar off of the bundle name in the exec command, so it wasn’t doing anything).

I can confirm the “Offline” behaviour and am still on OH 3.4.4.

After last updates, now way to get iCloud bridges configured by file online again.

After update to 4.0.2 it seems to re login

Tries to login, code is send to device
Edit the code in .things file doesn’t fit, bridge is still stuck in 2FA is needed.

Still prefer a channel the code could be send to the bridge configuration. :frowning:

That’s a pitty. I switched to non-file based configuration for the thing, especially because if found it far easier to enter a new pin in the OH UI compared to changing the thing config. It might be caused by some internal changes in 4.x. I also like the idea of the pin channel. We just need somebody to find the time to implement and test it :wink:

I wrote a telegram dialog to send new code via telegram to get it in the file.

If code would be channel I could send it there. But not to a web UI created thing

Some things I noteced to “changed” behavior:

Earlier Version
=> Textual Things File readed, Thing created
=> Login done by binding ==> Waiting 2FA
=> 2FA Code send to device
=> 2FA changed in text file
=> 2FA registered by binding, device online

Actual Version
=> Textual Things File readed, Thing created
=> Login done by binding ==> Waiting 2FA
=> 2FA Code send to device
=> 2FA changed in text file
=> Next Text file seems to be read, because changes in Name are registered by openhab. But new code ist not taken into account, so device still stucks with 2FA needed.

Work-Around (with advantages if having a lot of devices):
=> Move textual file away from config
=> Create thing in UI
=> Enter 2FA after Login
=> If device online delete thing in UI
=> move textual thing file to config again
=> As long name of thing is exactly the same like in manual thing earlier => textual thing takes the tokens and login stuff and is online directly.

The problem is that OH4 sais, that it re-reads the thing file, but it does provide the old values to the thing. I wrote a question in the dev section, to discuss this: Changes in thing config files not populated in OH4

The binding does 3 retries in case of errors. In that case here he icloud api responded, that your credentials are invalid. So in general it is a good behaviour that the binding does not blindly tries to re-authenticate with “invalid” credentials in a short sequence. It is a bit tricky to provide a bullet proof solution here… One could think of a more complex retry logic which increasing intervals, so that e.g. it is retried every few hours in such a case.

Good idea. I don’t know enough to propose a Pull Request.

I have created a rule using the exec binding to restart the iCloud binding bundle based on the expiration of a 20 minute timer that is triggered when the account thing goes offline.

Hi, thanks for care about this issue.

When bridge goes offline, I saw always same behavior with warnings in the log:


2023-09-02 02:20:25.444 [WARN ] [l.handler.ICloudAccountBridgeHandler] - Unable to refresh device data
java.net.ConnectException: null
        at jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:573) ~[java.net.http:?]
        at jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:123) ~[java.net.http:?]
        at org.openhab.binding.icloud.internal.ICloudSession.request(ICloudSession.java:139) ~[?:?]
        at org.openhab.binding.icloud.internal.ICloudSession.post(ICloudSession.java:98) ~[?:?]
        at org.openhab.binding.icloud.internal.FindMyIPhoneServiceManager.refreshClient(FindMyIPhoneServiceManager.java:64) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.lambda$1(ICloudAccountBridgeHandler.java:121) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.callApiWithRetryAndExceptionHandling(ICloudAccountBridgeHandler.java:185) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.lambda$0(ICloudAccountBridgeHandler.java:116) ~[?:?]
        at org.openhab.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:101) ~[?:?]
        at org.openhab.core.cache.ExpiringCache.getValue(ExpiringCache.java:72) ~[?:?]
        at org.openhab.binding.icloud.internal.handler.ICloudAccountBridgeHandler.refreshData(ICloudAccountBridgeHandler.java:389) ~[?:?]
        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:833) ~[?:?]
Caused by: java.net.ConnectException
        at jdk.internal.net.http.common.Utils.toConnectException(Utils.java:1055) ~[java.net.http:?]
        at jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:198) ~[java.net.http:?]
        at jdk.internal.net.http.AsyncSSLConnection.connectAsync(AsyncSSLConnection.java:56) ~[java.net.http:?]
        at jdk.internal.net.http.Http1Exchange.sendHeadersAsync(Http1Exchange.java:239) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$9(Exchange.java:472) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.checkFor407(Exchange.java:404) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$10(Exchange.java:476) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) ~[?:?]
        at java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:950) ~[?:?]
        at java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2340) ~[?:?]
        at jdk.internal.net.http.Exchange.responseAsyncImpl0(Exchange.java:476) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.responseAsyncImpl(Exchange.java:380) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.responseAsync(Exchange.java:372) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.responseAsyncImpl(MultiExchange.java:408) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.lambda$responseAsyncImpl$7(MultiExchange.java:449) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) ~[?:?]
        at java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:950) ~[?:?]
        at java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2340) ~[?:?]
        at jdk.internal.net.http.MultiExchange.responseAsyncImpl(MultiExchange.java:439) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.lambda$responseAsync0$2(MultiExchange.java:341) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) ~[?:?]
        at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
        at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) ~[?:?]
        at jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:157) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.completeAsync(CompletableFuture.java:2673) ~[?:?]
        at jdk.internal.net.http.MultiExchange.responseAsync(MultiExchange.java:294) ~[java.net.http:?]
        at jdk.internal.net.http.HttpClientImpl.sendAsync(HttpClientImpl.java:654) ~[java.net.http:?]
        at jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:552) ~[java.net.http:?]
        ... 16 more
Caused by: java.nio.channels.UnresolvedAddressException
        at sun.nio.ch.Net.checkAddress(Net.java:149) ~[?:?]
        at sun.nio.ch.Net.checkAddress(Net.java:157) ~[?:?]
        at sun.nio.ch.SocketChannelImpl.checkRemote(SocketChannelImpl.java:816) ~[?:?]
        at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:839) ~[?:?]
        at jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$0(PlainHttpConnection.java:183) ~[java.net.http:?]
        at java.security.AccessController.doPrivileged(AccessController.java:569) ~[?:?]
        at jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:185) ~[java.net.http:?]
        at jdk.internal.net.http.AsyncSSLConnection.connectAsync(AsyncSSLConnection.java:56) ~[java.net.http:?]
        at jdk.internal.net.http.Http1Exchange.sendHeadersAsync(Http1Exchange.java:239) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$9(Exchange.java:472) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.checkFor407(Exchange.java:404) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$10(Exchange.java:476) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) ~[?:?]
        at java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:950) ~[?:?]
        at java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2340) ~[?:?]
        at jdk.internal.net.http.Exchange.responseAsyncImpl0(Exchange.java:476) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.responseAsyncImpl(Exchange.java:380) ~[java.net.http:?]
        at jdk.internal.net.http.Exchange.responseAsync(Exchange.java:372) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.responseAsyncImpl(MultiExchange.java:408) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.lambda$responseAsyncImpl$7(MultiExchange.java:449) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) ~[?:?]
        at java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:950) ~[?:?]
        at java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2340) ~[?:?]
        at jdk.internal.net.http.MultiExchange.responseAsyncImpl(MultiExchange.java:439) ~[java.net.http:?]
        at jdk.internal.net.http.MultiExchange.lambda$responseAsync0$2(MultiExchange.java:341) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) ~[?:?]
        at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
        at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) ~[?:?]
        at jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:157) ~[java.net.http:?]
        at java.util.concurrent.CompletableFuture.completeAsync(CompletableFuture.java:2673) ~[?:?]
        at jdk.internal.net.http.MultiExchange.responseAsync(MultiExchange.java:294) ~[java.net.http:?]
        at jdk.internal.net.http.HttpClientImpl.sendAsync(HttpClientImpl.java:654) ~[java.net.http:?]
        at jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:552) ~[java.net.http:?]
        ... 16 more
2023-09-02 02:20:25.447 [INFO ] [tatus

Maybe the error management could be optimized? For me looks like the api had not been asked due to errors