Contribution - LG ThinQ Binding

djal · May 4, 2022, 7:36am

Hi @nemer,
thank you very much for new release, I had to immediatelly test it

Now the binding works much better with my WM, no more exceptions in the log, except those DEBUG level exceptions regarding disconnected status, but they’ll disappear when I change the log level for the binding:

2022-05-04 08:24:09.052 [DEBUG] [ices.LGThinQAbstractApiClientService] - LG API report error processing the request -> resultCode=[0106], message=[Device Not Response]
2022-05-04 08:24:09.053 [DEBUG] [nternal.handler.LGThinQWasherHandler] - Monitor stopped. Device is unavailable/disconnected
org.openhab.binding.lgthinq.internal.errors.LGThinqDeviceV1OfflineException: Device is offline. No data available
        at org.openhab.binding.lgthinq.lgservices.LGThinQAbstractApiClientService.handleV1GenericErrorResult(LGThinQAbstractApiClientService.java:284) ~[?:?]
...

Here are some remarks I noticed during washing:

it is interesting, that it reports the remaining time changes even in initial state when I changed the temperature and spinning speed,
the power channel seems to be not working. It changed to ON when I turned on the WM, but at the end it remained ON even when the WM turned off automatically (this is not critical, as there is same information in the WasherState channel)
the statuses are reported as numbers and they are not translated to strings like with my dryer, but that is easy to solve with the mapping in item’s state description metadata

And here are the events generated from the binding during the shortest possible program my washer supports (I linked all the remaining channels during washing in 8:32 to see what is filled and what is not):

2022-05-04 08:22:12.995 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lgthinq:201:lgthinqgatewaybridge:d62951d0-48cb-11ec-a3bd-7440be1b160a' changed from UNINITIALIZED (DISABLED) to INITIALIZING
2022-05-04 08:22:13.036 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lgthinq:201:lgthinqgatewaybridge:d62951d0-48cb-11ec-a3bd-7440be1b160a' changed from INITIALIZING to ONLINE
2022-05-04 08:22:23.974 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from POWEROFF to
2022-05-04 08:22:23.980 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lgthinq:201:lgthinqgatewaybridge:d62951d0-48cb-11ec-a3bd-7440be1b160a' changed from ONLINE to OFFLINE: Device is disconnected.
2022-05-04 08:22:23.984 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from  to POWEROFF
2022-05-04 08:24:22.724 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaPower' changed from OFF to ON
2022-05-04 08:24:22.726 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from POWEROFF to 1
2022-05-04 08:24:22.729 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lgthinq:201:lgthinqgatewaybridge:d62951d0-48cb-11ec-a3bd-7440be1b160a' changed from OFFLINE: Device is disconnected. to ONLINE
2022-05-04 08:26:26.037 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:00 to 00:14
2022-05-04 08:26:36.311 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:14 to 00:17
2022-05-04 08:26:46.574 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:17 to 00:20
2022-05-04 08:26:56.834 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from 1 to 6
2022-05-04 08:27:38.153 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:20 to 00:19
...
2022-05-04 08:32:35.849 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:15 to 00:14
2022-05-04 08:32:46.935 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPracka_WasherCourse' changed from NULL to 12
2022-05-04 08:32:46.940 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPracka_WasherSmartCourse' changed from NULL to 0
2022-05-04 08:32:46.954 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPracka_TemperatureLevel' changed from NULL to 4
2022-05-04 08:32:46.959 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPracka_WasherDoorLock' changed from NULL to
2022-05-04 08:32:46.970 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPracka_WasherDownloadedCourse' changed from NULL to
2022-05-04 08:33:37.659 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:14 to 00:13
2022-05-04 08:34:39.389 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:13 to 00:12
2022-05-04 08:35:40.961 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from 6 to 7
2022-05-04 08:35:40.965 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPracka_TemperatureLevel' changed from 4 to 0
2022-05-04 08:35:40.967 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:12 to 00:11
...
2022-05-04 08:41:50.574 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:08 to 00:07
2022-05-04 08:42:31.642 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from 7 to 2
2022-05-04 08:42:52.159 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from 2 to 7
2022-05-04 08:43:23.246 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:07 to 00:06
2022-05-04 08:44:35.072 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from 7 to 8
2022-05-04 08:44:35.078 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:06 to 00:05
2022-05-04 08:46:17.640 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:05 to 00:04
2022-05-04 08:47:19.219 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:04 to 00:03
2022-05-04 08:50:04.046 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:03 to 00:02
2022-05-04 08:51:05.664 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:02 to 00:01
2022-05-04 08:51:15.944 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from 8 to 10
2022-05-04 08:51:15.954 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaRemainingTime' changed from 00:01 to 00:00
2022-05-04 08:51:46.733 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPrackaWasherState' changed from 10 to 0
2022-05-04 08:53:37.638 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lgthinq:201:lgthinqgatewaybridge:d62951d0-48cb-11ec-a3bd-7440be1b160a' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Exhausted trying to get monitor data for the device:d62951d0-48cb-11ec-a3bd-7440be1b160a

If you want me to test something else regarding this binding, just let me know.

Thanks once more, is there a way how I could support you somehow? You have done really nice work here.

Regards
Dusan

nemer · May 4, 2022, 10:15am

Good to see its working better right now. But I can do it better! . Lets focus on all this issue to understand the circumstances.

power on/off. Can you run a cycle until the end, and when the WM goes off automatically, get the datatrace file in the sequence and post here ?
the status numbers - i think i can handle this easily. But you can help me post a screenshot of the channel’s
logs - its normals some errors reports that is not error at this moment. Its help me to troubleshoot. It will be cleaned in the end.

Another thing, the datatrace file is the data collected from the lg api and changes every pooling period (almost 10 seconds). If you see some strage behavior, you can collect a sequence of this file and send those here to analise.

Btw, thanks for the event log. Its help a lot also.

Regards

djal · May 4, 2022, 11:49am

Ok, I’m going to do the next test with washing cycle later today.

Here is the screenshot of channels for WM:

nemer · May 4, 2022, 11:55am

OK, but expand, the Channel that you reported is showing statuses in numbers, not translated to labels

Marty · May 4, 2022, 12:23pm

Im using the same WM channel ( uri:state) and for me it returns a string not a number.
My WM is currently running and this channel reports back the string : “Running”.

Edit: Value changes according to the WM state, showing the same info as the app.

2022-05-04 14:52:03.461 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGThinQ_WASHER_STATE' changed from RUNNING to RINSING

djal · May 4, 2022, 12:44pm

Ahh I’m sorry, it is like @Marty wrote. I was confused by values from the events.log. In items the values looks correct.

I also tried the power off channel when WM was in Initial state and I turned it off maually.
Here is how the values in datatrace has been changing:

initial state:

{"deviceId":"d62951d0-48cb-11ec-a3bd-7440be1b160a","deviceState":"E","format":"B64","returnCode":"0000","returnData":"AQA2ADYIAAMFBAEAAAAAAAAAAgAAOgBkAAACAA==","stateCode":"S","workId":"n-d62951d0-48cb-11ec-a3bd-7440be1b160a"}

when turned off:

{"deviceId":"d62951d0-48cb-11ec-a3bd-7440be1b160a","deviceState":"E","format":"B64","returnCode":"0000","returnData":"AAA2ADYIAAAAAAAAAAAAAAAAAgEAOgBkAAACAA==","stateCode":"S","workId":"n-d62951d0-48cb-11ec-a3bd-7440be1b160a"}

when it stopped responding and changed thing to OFFLINE (COMMUNICATION_ERROR): Exhausted trying to get monitor data for the device:d62951d0-48cb-11ec-a3bd-7440be1b160a

{"deviceId":"d62951d0-48cb-11ec-a3bd-7440be1b160a","deviceState":"E","format":"B64","returnCode":"0100","returnData":"AAA2ADYIAAAAAAAAAAAAAAAAAgEAOgBkAAACAA==","stateCode":"F","workId":"n-d62951d0-48cb-11ec-a3bd-7440be1b160a"}

All channels get their initial values, but the Power channel still stays ON.

Pogo · May 4, 2022, 2:11pm

Works for me much better now.
But while the WM is off there are error messages in logs:

[ERROR] [nternal.handler.LGThinQWasherHandler] - Error updating thing Pralka/9022e280-c5aa-11e7-90e0-b4e62a7907f6 from LG API. Thing goes OFFLINE until next retry.
org.openhab.binding.lgthinq.internal.errors.LGThinqApiException: Exhausted trying to get monitor data for the device:9022e280-c5aa-11e7-90e0-b4e62a7907f6
	at org.openhab.binding.lgthinq.internal.handler.LGThinQAbstractDeviceHandler.getSnapshotDeviceAdapter(LGThinQAbstractDeviceHandler.java:366) ~[?:?]
	at org.openhab.binding.lgthinq.internal.handler.LGThinQAbstractDeviceHandler.updateThingStateFromLG(LGThinQAbstractDeviceHandler.java:243) ~[?:?]
	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) [?:?]

[INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lgthinq:201:b489249103:9022e280-c5aa-11e7-90e0-b4e62a7907f6' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Exhausted trying to get monitor data for the device:9022e280-c5aa-11e7-90e0-b4e62a7907f6

Maybe it should be hidden by some try-catch block?

nemer · May 4, 2022, 2:14pm

Can you send me more lines from this log ? (ex: 10 lines above)

Pogo · May 4, 2022, 2:27pm

2022-05-04 16:17:31.474 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'lgthinq:201:b489249103:9022e280-c5aa-11e7-90e0-b4e62a7907f6' changed from OFFLINE (COMMUNICATION_ERROR): Exhausted trying to get monitor data for the device:9022e280-c5aa-11e7-90e0-b4e62a7907f6 to ONLINE
2022-05-04 16:17:31.474 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPralka_WasherState' changed from 0 to 1
2022-05-04 16:17:31.474 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPralka_WasherCourse' changed from 11 to 0
2022-05-04 16:17:31.474 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPralka_RemainingTime' changed from 00:28 to 00:00

2022-05-04 16:18:43.068 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'LGPralka_WasherState' changed from 1 to 0

2022-05-04 16:20:25.344 [WARN ] [ices.LGThinQAbstractApiClientService] - Monitor for device 9022e280-c5aa-11e7-90e0-b4e62a7907f6 has expired. Please, refresh the monitor.

2022-05-04 16:20:43.368 [ERROR] [nternal.handler.LGThinQWasherHandler] - Error updating thing Pralka/9022e280-c5aa-11e7-90e0-b4e62a7907f6 from LG API. Thing goes OFFLINE until next retry.
org.openhab.binding.lgthinq.internal.errors.LGThinqApiException: Exhausted trying to get monitor data for the device:9022e280-c5aa-11e7-90e0-b4e62a7907f6
	at org.openhab.binding.lgthinq.internal.handler.LGThinQAbstractDeviceHandler.getSnapshotDeviceAdapter(LGThinQAbstractDeviceHandler.java:366) ~[?:?]
	at org.openhab.binding.lgthinq.internal.handler.LGThinQAbstractDeviceHandler.updateThingStateFromLG(LGThinQAbstractDeviceHandler.java:243) ~[?:?]
	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) [?:?]

First 4 are on turning ON (including COMMUNICATION_ERROR).
Next are on turning OFF… Looked good on state change, but then there were those errors.
After that 2 times more the same error and than silence.

I don’t know how it works on newer WMs, but mine is fully off when it’s off, with absolutely no connection do wifi.

I removed all irrelevant lines (changes in humidity, temperature, light etc.)

djal · May 4, 2022, 3:00pm

@nemer My first complete washing cycle finished so here is the data I collected during whole cycle.

Datatrace collected by tail -f command and then filtered duplicated rows
2022-05-04-djal-washer-datatrace.txt (20.0 KB)

LG related lines from events.log (there is no change for power item as it was ON before the washing started and remained ON after WM finished)
2022-05-04-djal-washer-events.log (12.7 KB)

LG related lines from openhab.log (there are also few ERROR messages as @Pogo mentioned)
2022-05-04-djal-washer.log (14.0 KB)

nemer · May 4, 2022, 4:11pm

Since your are not in debug mode, I can’t precisely determine if it’s a problem or not.

For V1 devices, the polling for device status update is a kind of “boring” process. It needs to start a monitor calling a specific endpoint, and then, ask for the status update by polling through this monitor.
What happen is, after some time that I can’t determine, this monitor expires. And when it happens, the monitor must be restarted ( “Monitor for device 9022e280-c5aa-11e7-90e0-b4e62a7907f6 has expired. Please, refresh the monitor…” message). The Binding automatically restart the monitor, but when the monitor is started, it takes some time to start to receive data. Because this, there is a logic that keep retrying for a while until data is available, but when the LG API is getting lazy to delivery the monitoring data for the new monitor, the Error message “Exhausted trying to get monitor data for the device…” is logged. It’s not necessarially an error. It’s just because the binding is trying to get data for this device from LG API, but there is no data available for now. Thus, the binding put the Thing as “Offline” because it doesn’t know about its state, but will retry again after 10s.
Normally, this error message can occur when the monitor has been just created but can’t be so frequent.
I will review this messages, but let me know if this error happen with frequency, i.e, almost all the time.

Pogo · May 4, 2022, 4:36pm

The error happened 20 minutes later and than nothing… it’s already over 2h later.

nemer · May 4, 2022, 5:55pm

The logs sounds good for me. The errors reported are expected based on your debug log info.
I will try to simulate the “ON behavior” and let you know soon.

Thanks for the files !

tizen · May 5, 2022, 3:44pm

Thanks! with new version channels are updated correctly. Let me do more testing.

Few things I observed. If AC is off , Current Room temperature is not updated one. It updates only when I opened the App. Second, sometime channels updates are with slight delay.

Will observe this more and will share update here.

Here is the cap file of Dishwasher. If possible, you can add support for dishwasher in this binding.

thinq-cdda5d3e-1933-1141-85ae-402f86e92503-cap.json (18.8 KB)

Thanks for all the help. I have few automation on AC , with this binding hoping to make them more smart especially now I can control Fan seed too.

Thanks!

Amin

nemer · May 6, 2022, 9:39pm

Actually, the delay between pollings was hardcoded in 10s. I’m planning to parameterize this period in the next releases.
About the temperature… I will take a look in this issue.

I’m implementing right now the support to Fridge. In the sequence, I can go forward to the Dishwasher. Thanks for the cap file !

tizen · May 10, 2022, 6:18pm

Hi,

Did more testing, current temperature is not updating even if AC is on. It only updates when i open LG app.

Because of this this setting is not useful to do any sort of automation based on current room temperature.

Regards,

Amin

nemer · May 14, 2022, 10:06am

Hi, @tizen.

I have 6 ar conditioner in my house (v1 & v2). I can’t simulate your scenario. Maybe you have a kind of different model or maybe it’s related with a bug that a fixed last week. The binding was configured to zero precision of the current temperature that resulted in a lost of decimal precision (i.e. if temperature was 25.5, 25.6, 26.7, … it was reporting 27 C).

If it your case, you can download my last version in my personal repository. If not, I would appreciate if you send me *-datatrace.json file (but for that, you have to put your OH in debug mode - previous posts shows how to do it).

Cheers and have a nice weekend !

Nemer.

tizen · May 14, 2022, 2:13pm

Hi @nemer ,

Thanks for the reply. noticed the decimal portion issue. The temp difference I m seeing is not related to decimal issue

Here are steps to reproduce the issue:

If for example, AC is on and indoor temp is 24.
Now I turn off AC for few hours.
The binding still shows indoor temp as 24 after 2 hours. But actually indoor temp has changed.
or
if AC in ON and the indoor temp at the start of the AC was 30
AC is running for sometime , The indoor temp is reduced but binding is not showing updated temp. I have to open the app to update it.

I feel indoor temp changes are not published by AC. I was seeing same behavior in Thinq-MQTT-Proxy, when I was using it to control the AC.

Will try to get the data- trace .

Regards,

Amin

Marty · May 14, 2022, 2:40pm

If you experenced the same issue with the MQTT-Proxy this would be an issue between your AC(s) and the LG cloud rather then an issue with this binding. Apperanlty in you case the relevant info is not updated regularly but only when you open the app.

If the LG cloud service has outdated info, the ThinQ binding will reflect this.

For me AC ambient temperatures are updated frequently thru out the day, regardless of them running. I never open the app.

tizen · May 14, 2022, 3:13pm

Thanks @Marty for the reply. might be issue with LG cloud not pushing the data. let me still check I have configured all correctly. As you and nemer are not facing this issue.