search

nibi79 / worxlandroid

openHAB Binding for Worx Landroid
60 stars 20 forks source link

Recurring errors in log #42

Closed mbremer99 closed 4 years ago

mbremer99 commented 4 years ago

Hello,

when using this binding (great work BTW!) I get recurring errors. (seems to be about decryption)

Here are the details of my setup and the errors

Standard parameters are used for the mower

Refresh status interval 60
Polling interval 300

I don't see a pattern or frequency for the occurence of errors:

2020-06-08 03:58:41.670 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:03:26.804 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 04:03:41.670 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:08:41.670 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:11:28.191 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 04:13:41.671 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:18:29.396 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 04:18:41.671 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:23:41.671 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:25:30.694 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 04:28:41.672 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:33:41.672 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:35:32.586 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 04:38:41.680 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:43:41.673 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:48:41.673 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:53:41.673 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 04:55:36.549 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 04:57:36.766 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 04:58:41.675 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:03:41.707 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:08:39.765 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:08:41.721 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:10:40.105 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:13:40.622 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:13:41.677 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:15:40.846 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:18:41.685 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:22:42.034 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:23:41.677 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:28:41.682 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:33:41.678 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:33:44.180 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:36:44.627 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:38:41.678 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:39:45.073 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:41:45.397 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:43:41.679 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:48:41.679 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:53:41.679 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 05:55:47.977 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 05:58:41.679 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:03:41.680 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:08:41.680 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:08:51.056 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:10:51.294 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:13:41.680 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:13:51.716 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:16:52.460 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:18:41.681 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:23:41.681 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:26:54.701 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:28:41.681 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:29:55.128 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:31:55.324 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:33:41.682 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:34:55.694 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:37:56.134 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:38:41.683 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:39:56.336 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:43:41.682 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:45:57.434 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:48:41.684 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:48:57.820 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:53:41.683 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 06:55:59.312 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:57:59.486 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 06:58:41.683 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:03:41.684 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:08:41.684 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:13:41.684 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:18:41.685 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:22:11.605 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:22:41.691 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:23:29.958 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:23:41.690 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:24:29.961 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:28:41.686 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:29:29.962 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:32:07.967 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 07:33:41.687 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:34:29.962 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:38:41.686 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:39:29.962 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:43:41.687 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:44:29.963 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:48:41.688 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:49:29.963 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:53:41.687 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:54:29.963 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:58:41.688 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 07:59:29.963 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:03:41.720 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:04:29.964 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:08:41.690 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:09:29.964 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:10:18.074 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 08:13:41.689 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:14:18.721 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 08:14:29.965 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:16:18.819 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 08:18:41.692 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:19:29.965 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:22:19.734 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 08:23:41.691 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:24:29.968 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:28:20.590 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 08:28:41.690 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:29:29.967 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:31:20.899 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
2020-06-08 08:33:41.691 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:34:29.967 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:35:21.734 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error

Here are some detailed logs:

first log - works:

2020-06-08 08:24:29.968 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:25:53.797 [INFO ] [.worxlandroid.internal.mqtt.AWSTopic] - onMessage: {"cfg":[...]}
2020-06-08 08:25:53.804 [INFO ] [id.internal.WorxLandroidMowerHandler] - HOME | StatusCode: 1 - Home
2020-06-08 08:25:53.805 [INFO ] [id.internal.WorxLandroidMowerHandler] - NO_ERROR | ErrorCode: 0 - No error

next log - error:

2020-06-08 08:28:20.590 [ERROR] [id.internal.WorxLandroidMowerHandler] - RefreshStatusRunnable [123_Landroid_serial_number_321]: Unknown error
org.openhab.binding.worxlandroid.internal.webapi.WebApiException: java.io.EOFException: HttpConnectionOverHTTP@6b10c496::DecryptedEndPoint@1a45fab4{api.worxlandroid.com/54.194.27.98:443<->/192.168.178.16:60884,OPEN,fill=-,flush=-,to=60002/0}
    at org.openhab.binding.worxlandroid.internal.webapi.request.WebApiRequest.callWebApi(WebApiRequest.java:122) ~[bundleFile:?]
    at org.openhab.binding.worxlandroid.internal.webapi.request.WebApiRequest.callWebApiGet(WebApiRequest.java:79) ~[bundleFile:?]
    at org.openhab.binding.worxlandroid.internal.webapi.request.ProductItemsRequest.call(ProductItemsRequest.java:46) ~[bundleFile:?]
    at org.openhab.binding.worxlandroid.internal.webapi.WorxLandroidWebApiImpl.retrieveUserDevices(WorxLandroidWebApiImpl.java:101) ~[bundleFile:?]
    at org.openhab.binding.worxlandroid.internal.WorxLandroidMowerHandler$1.run(WorxLandroidMowerHandler.java:104) [bundleFile:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_231]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_231]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_231]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_231]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_231]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_231]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_231]
Caused by: java.util.concurrent.ExecutionException: java.io.EOFException: HttpConnectionOverHTTP@6b10c496::DecryptedEndPoint@1a45fab4{api.worxlandroid.com/54.194.27.98:443<->/192.168.178.16:60884,OPEN,fill=-,flush=-,to=60002/0}
    at org.eclipse.jetty.client.util.FutureResponseListener.getResult(FutureResponseListener.java:118) ~[bundleFile:9.4.20.v20190813]
    at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:101) ~[bundleFile:9.4.20.v20190813]
    at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:685) ~[bundleFile:9.4.20.v20190813]
    at org.openhab.binding.worxlandroid.internal.webapi.request.WebApiRequest.callWebApi(WebApiRequest.java:92) ~[bundleFile:?]
    ... 11 more
Caused by: java.io.EOFException: HttpConnectionOverHTTP@6b10c496::DecryptedEndPoint@1a45fab4{api.worxlandroid.com/54.194.27.98:443<->/192.168.178.16:60884,OPEN,fill=-,flush=-,to=60002/0}
    at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.earlyEOF(HttpReceiverOverHTTP.java:335) ~[?:?]
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1526) ~[?:?]
    at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.shutdown(HttpReceiverOverHTTP.java:209) ~[?:?]
    at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:147) ~[?:?]
    at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:73) ~[?:?]
    at org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:133) ~[?:?]
    at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:154) ~[?:?]
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[?:?]
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) ~[?:?]
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:426) ~[?:?]
    at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:320) ~[?:?]
    at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:158) ~[?:?]
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) ~[?:?]
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) ~[?:?]
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) ~[?:?]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) ~[?:?]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) ~[?:?]
    ... 1 more

next log - sucess again:

2020-06-08 08:28:41.690 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess
2020-06-08 08:28:43.163 [INFO ] [.worxlandroid.internal.mqtt.AWSTopic] - onMessage: {"cfg":[...]}
2020-06-08 08:28:43.170 [INFO ] [id.internal.WorxLandroidMowerHandler] - HOME | StatusCode: 1 - Home
2020-06-08 08:28:43.171 [INFO ] [id.internal.WorxLandroidMowerHandler] - NO_ERROR | ErrorCode: 0 - No error
2020-06-08 08:29:29.967 [INFO ] [orxlandroid.internal.mqtt.AWSMessage] - onSuccess

Do you have an idea where it is going wrong?

Rgds, Markus

nibi79 commented 4 years ago

hi,

please set the 'refreshStatusInterval' to 300. Then the error shouldn't occur anymore . After that gradually decrease the interval until the error reappears.

mbremer99 commented 4 years ago

Hello,

OK that solved it - easy fix! Changed it to 300. After that apart from one HTTP 502 error no issues anymore for several hours now. Will try to decrease the value sometime in the next few days.

Rgds, Markus