rccoleman / lamarzocco

Interact with your La Marzocco espresso machine
59 stars 5 forks source link

Machine turned on in HA but stays off #40

Closed ari-za closed 10 months ago

ari-za commented 1 year ago

Hi all

Been having an issue for a while now whereby I switch the machine on in HA however the machine does not actually switch on quite often. I have to manually turn the machine off and on again and then it works. Sometimes it works, a lot of the time it doesn't. I seem to remember it was always solid before the update.

GS3 MP. Latest version. 1.23, gateway V1.1RC8

WiFi signal- Excellent (-65 dBm)

Screenshot 2023-03-16 at 17 29 23 Screenshot 2023-03-16 at 17 29 35

Still on Standby after switching on in HA:

IMG_6050

Would be happy to do some logging if possible to help diagnose.

rccoleman commented 1 year ago

I also suggest temporarily disabling the integration and see if you can reproduce the behavior with the official app. It should be doing exactly the same thing, since I reverse engineered all the messages from the app.

Without knowing the integration version where you think it was better and when it got worse, I don't know how to identify what might have happened. I reviewed the changes since the last major update when I added support for the new features in the new firmware version and I don't see anything that would have affected the stability of on/off (which is just a simple write of a single byte).

ari-za commented 1 year ago

Thanks, as mentioned in the other thread my machine fw is the latest version for my machine (GS3 MP).

I will try exclusively with the LM app and see if it exhibits similar behavior.

I did notice when I have this issue when I turn the machine on via HA, the HA integration shows the machine is on, but it still shows off in the LM app when I load it up to check that after.

I'm talking blindly here but I suspect there might be an issue with feedback from LM integration since it writes the single byte (or attempts to), but does it/can it confirm that the write was actually successful by checking the status? Just an idea. Seems like the LM app checks as it has a spinning loading circle after you send the on request.

rccoleman commented 1 year ago

The integration polls the machine for the current state every 20s, so it will know whether it's really on or off, but it does take some time to act and the integration expects it to eventually succeed. It doesn't retry commands after a while if the state never changes, and it caches and reports the expected new state until it sees that the machine has transitioned. The only times that I've seen commands fail is when I have the official app open and the integration can't connect (which is expected, as the machine only supports one connection at a time).

I suggest reviewing your HA log for errors, and you can add this to configuration.yaml to enable more logging:

logger:
  logs:
    lmdirect: debug
ari-za commented 1 year ago

Same thing this morning. Triggered on in HA (via Homekit), shows on in HA, machine is off however. Load up LM app, also shows off. (LM was closed before this). Status does not change to off in HA despite the machine really being off, stays as "on" even past the polling period of 20.

Only when I turn it off and on again in HA then it works.

Almost like the first "turn_on" command/write fails/doesn't execute, and then triggering it off and on in HA again works every time.

Again, I don't suspect a WiFi issue because i'm using UniFi and everything seems fine, also its about 4m from the Wifi AP.

I have now connected the LM to a 2.4GHz only network, but again I don't suspect that is the issue.

I only noticed this behavior after the latest machine update (v.123 in my case) which coincided with the big v2 app release. And I guess subsequent integration update.

I did enable logging above but not sure how often it logs, it seems it was filling up my log file causing weird issues on my HA.

Will continue to monitor.

IMG_6132 IMG_6135

rccoleman commented 1 year ago

The machine responds to the write command, so you should see an error in the log if it doesn't receive an OK. So as we discussed, please see if there are logs around when you see these failed attempts to turn the machine on and see if you see the same behavior with the official app. The fact that the app shows 'off' when HA thinks it's on tells me that the write was unsuccessful and you should see something in the log.

ari-za commented 1 year ago

Ok I finally managed to enable logging and replicate the issue, so hopefully we can get to the bottom of this.

Timeline: 11:01 - restarted HA after enabling logging again

11:03am - request made to turn machine on in HA - machine does not turn on. Switch stays on in HA indefinitely

11:06am - turn HA switch off and on again and then the machine turns on this time.

subsequent off and on work without fail. seems after a certain amount of time it exhibits this behavior. e.g. early in the monrning when turning the machine on for the first time of the day.

Other notes: Confirmed in UniFi controller the wifi was connected and stable the whole time to the machine.

This happens pretty much every morning the first time I turn it on so I was able to replicate.

Where can I send you the log file privately?

rccoleman commented 1 year ago

I only need the few lines around where you try to turn on the machine and where it waits for a response, and there shouldn't be anything sensitive there.

ari-za commented 1 year ago

I can't differentiate between the requests as there seems to be other requests made by the integration. I'll post what I have around the time, you'd be able to decipher. Also I will send you the full log on HA forums via PM.

Timeline in my post above

`<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:x="urn:schemas-microsoft-com:office:excel" xmlns="http://www.w3.org/TR/REC-html40">

2023-03-20 | 11:03:10.132 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data -- | -- | -- 2023-03-20 | 11:03:10.133 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:03:10.135 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:03:10.135 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:03:10.136 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:03:10.136 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:03:10.137 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:03:10.137 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:03:10.137 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:03:10.137 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:03:10.138 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:03:10.258 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:03:10.261 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:03:10.262 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:03:11.545 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E323030393030313431390000000000000000000100000001130126000001 2023-03-20 | 11:03:11.559 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:03:11.748 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:03:11.954 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015C 2023-03-20 | 11:03:11.961 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7B00001FB800000000000004DF 2023-03-20 | 11:03:12.160 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:03:12.170 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=54414E442D425920202031313A303300 2023-03-20 | 11:03:12.175 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:03:13.182 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00030B01140317 2023-03-20 | 11:03:14.121 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:03:14.121 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:03:15.130 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:03:17.175 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00030B01140317 2023-03-20 | 11:03:18.122 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:03:19.122 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:03:21.171 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00030B01140317 2023-03-20 | 11:03:21.172 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:03:21.174 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:03:21.174 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task 2023-03-20 | 11:03:40.297 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data 2023-03-20 | 11:03:40.298 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:03:40.299 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:03:40.300 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:03:40.300 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:03:40.301 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:03:40.301 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:03:40.301 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:03:40.301 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:03:40.302 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:03:40.302 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:03:40.429 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:03:40.430 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:03:40.430 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:03:41.547 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E323030393030313431390000000000000000000100000001110126000001 2023-03-20 | 11:03:41.552 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:03:41.753 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:03:41.960 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015C 2023-03-20 | 11:03:41.966 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7B00001FB800000000000004DF 2023-03-20 | 11:03:42.171 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=54414E442D425920202031313A303300 2023-03-20 | 11:03:42.178 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:03:42.368 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:03:42.374 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:03:42.374 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:03:43.123 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:03:45.156 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00030B01140317 2023-03-20 | 11:03:46.156 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:03:47.179 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:03:49.126 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00030B01140317 2023-03-20 | 11:03:50.149 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:03:50.277 | DEBUG (MainThread) [lmdirect.connection] Sending 00000001 with 01 None 2023-03-20 | 11:03:50.559 | DEBUG (MainThread) [lmdirect.connection] Message=00000001, Data=OK 2023-03-20 | 11:03:50.559 | DEBUG (MainThread) [lmdirect.connection] Command Succeeded: 00000001: OK 2023-03-20 | 11:03:50.559 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:03:51.173 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:03:53.124 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=35030B01140317 2023-03-20 | 11:03:54.143 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:03:55.168 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:03:57.132 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00040B01140317 2023-03-20 | 11:03:58.137 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:03:59.161 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:04:01.122 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00040B01140317 2023-03-20 | 11:04:01.122 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:04:01.124 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:04:01.124 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task 2023-03-20 | 11:04:10.449 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data 2023-03-20 | 11:04:10.450 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:04:10.451 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:04:10.452 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:04:10.452 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:04:10.453 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:04:10.453 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:04:10.453 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:04:10.453 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:04:10.454 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:04:10.454 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:04:10.645 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:04:10.646 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:04:10.646 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:04:11.346 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E323030393030313431390000000000000000000100000001110126000001 2023-03-20 | 11:04:11.554 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:04:11.554 | DEBUG (MainThread) [lmdirect.connection] Element power hasn't updated yet, so use the cached value 0 2023-03-20 | 11:04:11.755 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:04:11.759 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015C 2023-03-20 | 11:04:11.960 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7B00001FB800000000000004DF 2023-03-20 | 11:04:11.967 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=54414E442D425920202031313A303400 2023-03-20 | 11:04:12.165 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:04:12.171 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:04:13.124 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00040B01140317 2023-03-20 | 11:04:14.132 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:04:14.133 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:04:15.135 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:04:17.192 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00040B01140317 2023-03-20 | 11:04:18.122 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:04:19.135 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:04:21.178 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00040B01140317 2023-03-20 | 11:04:21.179 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:04:21.183 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:04:21.183 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task 2023-03-20 | 11:04:40.663 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data 2023-03-20 | 11:04:40.663 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:04:40.664 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:04:40.664 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:04:40.665 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:04:40.665 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:04:40.665 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:04:40.665 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:04:40.666 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:04:40.666 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:04:40.666 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:04:40.743 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:04:40.743 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:04:40.744 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:04:41.554 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E323030393030313431390000000000000000000100000001110126000001 2023-03-20 | 11:04:41.562 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:04:41.563 | DEBUG (MainThread) [lmdirect.connection] Element power hasn't updated yet, so use the cached value 0 2023-03-20 | 11:04:41.760 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:04:41.965 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015C 2023-03-20 | 11:04:41.975 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7B00001FB800000000000004DF 2023-03-20 | 11:04:42.169 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=54414E442D425920202031313A303400 2023-03-20 | 11:04:42.176 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:04:42.374 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:04:42.382 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:04:42.383 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:04:43.122 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:04:45.141 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00040B01140317 2023-03-20 | 11:04:46.162 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:04:47.127 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:04:49.133 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00040B01140317 2023-03-20 | 11:04:50.158 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110128 2023-03-20 | 11:04:51.179 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:04:51.180 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:04:51.181 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:04:51.182 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task 2023-03-20 | 11:05:10.759 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data 2023-03-20 | 11:05:10.760 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:05:10.761 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:05:10.762 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:05:10.762 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:05:10.762 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:05:10.763 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:05:10.763 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:05:10.763 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:05:10.763 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:05:10.764 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:05:10.849 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:05:10.850 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:05:10.851 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:05:11.561 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E323030393030313431390000000000000000000100000001110126000001 2023-03-20 | 11:05:11.566 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:05:11.566 | DEBUG (MainThread) [lmdirect.connection] Element power hasn't updated yet, so use the cached value 0 2023-03-20 | 11:05:11.763 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:05:11.968 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015C 2023-03-20 | 11:05:11.975 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7B00001FB800000000000004DF 2023-03-20 | 11:05:12.173 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=54414E442D425920202031313A303500 2023-03-20 | 11:05:12.180 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:05:12.379 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:05:13.123 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00050B01140317 2023-03-20 | 11:05:14.128 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:05:14.129 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:05:15.146 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:05:17.123 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00050B01140317 2023-03-20 | 11:05:18.127 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:05:19.136 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:05:21.187 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00050B01140317 2023-03-20 | 11:05:21.190 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:05:21.193 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:05:21.194 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task 2023-03-20 | 11:05:40.867 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data 2023-03-20 | 11:05:40.868 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:05:40.868 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:05:40.868 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:05:40.869 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:05:40.869 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:05:40.869 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:05:40.869 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:05:40.869 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:05:40.869 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:05:40.869 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:05:40.955 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:05:40.956 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:05:40.956 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:05:41.562 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E323030393030313431390000000000000000000100000001110126000001 2023-03-20 | 11:05:41.568 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:05:41.569 | DEBUG (MainThread) [lmdirect.connection] Element power hasn't updated yet, so use the cached value 0 2023-03-20 | 11:05:41.766 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:05:41.978 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015C 2023-03-20 | 11:05:41.985 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7B00001FB800000000000004DF 2023-03-20 | 11:05:42.177 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=54414E442D425920202031313A303500 2023-03-20 | 11:05:42.191 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:05:42.323 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:05:42.387 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:05:42.388 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:05:43.124 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:05:45.148 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00050B01140317 2023-03-20 | 11:05:46.171 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:05:47.123 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:05:49.141 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=00050B01140317 2023-03-20 | 11:05:50.163 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:05:51.127 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:05:51.129 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:05:51.133 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:05:51.133 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task 2023-03-20 | 11:06:04.443 | DEBUG (MainThread) [lmdirect.connection] Sending 00000001 with 00 None 2023-03-20 | 11:06:04.444 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:06:04.510 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:06:04.512 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:06:04.512 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:06:05.329 | DEBUG (MainThread) [lmdirect.connection] Message=00000001, Data=OK 2023-03-20 | 11:06:05.329 | DEBUG (MainThread) [lmdirect.connection] Command Succeeded: 00000001: OK 2023-03-20 | 11:06:05.329 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:06:06.143 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7B00001FB800000000000004DF 2023-03-20 | 11:06:06.831 | DEBUG (MainThread) [lmdirect.connection] Sending 00000001 with 01 None 2023-03-20 | 11:06:07.169 | DEBUG (MainThread) [lmdirect.connection] Message=00000001, Data=OK 2023-03-20 | 11:06:07.170 | DEBUG (MainThread) [lmdirect.connection] Command Succeeded: 00000001: OK 2023-03-20 | 11:06:07.170 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:06:07.174 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=01003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:06:07.175 | DEBUG (MainThread) [lmdirect.connection] Element power has updated to 1, pop the cached value 2023-03-20 | 11:06:08.123 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:06:09.131 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:10.136 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:10.972 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data 2023-03-20 | 11:06:10.972 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:06:10.973 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:06:10.974 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:06:10.974 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:06:10.974 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:06:10.974 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:06:10.974 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:06:10.975 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:06:10.975 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:06:11.157 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01130128 2023-03-20 | 11:06:11.362 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E323030393030313431390100000000000000010100001501110126000001 2023-03-20 | 11:06:11.565 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=01003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:06:11.574 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:06:11.771 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015D 2023-03-20 | 11:06:11.974 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7D00001FB800000000000004DF 2023-03-20 | 11:06:12.121 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=33302E33DF4320FFFF2031313A303600 2023-03-20 | 11:06:12.180 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:06:12.321 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:06:12.321 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:06:12.383 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:06:14.127 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:15.149 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01130128 2023-03-20 | 11:06:16.181 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:06:18.124 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:19.145 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=01110126 2023-03-20 | 11:06:20.167 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:06:22.135 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:22.137 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:06:22.139 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:06:22.140 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task 2023-03-20 | 11:06:40.995 | DEBUG (MainThread) [custom_components.lamarzocco.api] Fetching data 2023-03-20 | 11:06:40.996 | DEBUG (MainThread) [lmdirect] Requesting status 2023-03-20 | 11:06:40.997 | DEBUG (MainThread) [lmdirect.connection] Sending 40000023 with None None 2023-03-20 | 11:06:40.997 | DEBUG (MainThread) [lmdirect.connection] Connecting 2023-03-20 | 11:06:40.998 | DEBUG (MainThread) [lmdirect.connection] Sending 0000001F with None None 2023-03-20 | 11:06:40.998 | DEBUG (MainThread) [lmdirect.connection] Sending 0310001D with None None 2023-03-20 | 11:06:40.999 | DEBUG (MainThread) [lmdirect.connection] Sending 0020002C with None None 2023-03-20 | 11:06:40.999 | DEBUG (MainThread) [lmdirect.connection] Sending 00500018 with None None 2023-03-20 | 11:06:40.999 | DEBUG (MainThread) [lmdirect.connection] Sending 60EF0010 with None None 2023-03-20 | 11:06:40.999 | DEBUG (MainThread) [lmdirect.connection] Sending 00E20004 with None None 2023-03-20 | 11:06:41.000 | DEBUG (MainThread) [lmdirect.connection] Sending 40600020 with None None 2023-03-20 | 11:06:41.069 | DEBUG (MainThread) [lmdirect.connection] Finished Connecting 2023-03-20 | 11:06:41.071 | DEBUG (MainThread) [lmdirect.connection] Starting read task 2023-03-20 | 11:06:41.072 | DEBUG (MainThread) [lmdirect.connection] Starting read reaper 2023-03-20 | 11:06:41.583 | DEBUG (MainThread) [lmdirect.connection] Message=40000023, Data=027B02536E32303039303031343139010000000000000001010000700123012A000001 2023-03-20 | 11:06:41.588 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=01003C026E3230039804A6000608000012180000006E00DC0096012C03E811 2023-03-20 | 11:06:41.774 | DEBUG (MainThread) [lmdirect.connection] Message=0310001D, Data=FE080C080C080C080C080C080C080C0000000000000000000000000000 2023-03-20 | 11:06:41.979 | DEBUG (MainThread) [lmdirect.connection] Message=00500018, Data=0000006B0000008600003F7D00001FB800000000000004DF 2023-03-20 | 11:06:41.994 | DEBUG (MainThread) [lmdirect.connection] Message=0020002C, Data=0000024C000000000000000000000000000000000000024C000002430000000000000000000002430000015D 2023-03-20 | 11:06:42.122 | DEBUG (MainThread) [lmdirect.connection] Message=60EF0010, Data=33322E31DF4320FFFF2031313A303600 2023-03-20 | 11:06:42.182 | DEBUG (MainThread) [lmdirect.connection] Message=00E20004, Data=00000000 2023-03-20 | 11:06:42.322 | DEBUG (MainThread) [lmdirect.connection] Message=40600020, Data=0000009803A604500050000F000F006400640070000000000001550055000001 2023-03-20 | 11:06:42.326 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:43.124 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=0127012A 2023-03-20 | 11:06:43.124 | DEBUG (MainThread) [lmdirect.connection] Received all responses 2023-03-20 | 11:06:44.130 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:06:46.176 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:47.130 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=012F012C 2023-03-20 | 11:06:48.127 | DEBUG (MainThread) [lmdirect.connection] Message=40220001, Data=01 2023-03-20 | 11:06:50.173 | DEBUG (MainThread) [lmdirect.connection] Message=03000007, Data=0A060B01140317 2023-03-20 | 11:06:51.124 | DEBUG (MainThread) [lmdirect.connection] Message=401C0004, Data=0133012E 2023-03-20 | 11:06:51.124 | DEBUG (MainThread) [lmdirect.connection] Exiting loop: [] 2023-03-20 | 11:06:51.125 | DEBUG (MainThread) [lmdirect.connection] Finished closing 2023-03-20 | 11:06:51.126 | DEBUG (MainThread) [lmdirect.connection] Finished reaping read task

`

ari-za commented 1 year ago

Now this is interesting..

Not sure if I didn’t press the physical button long enough (pretty sure I did) but when I pressed the physical power button on my machine this morning to turn it on for the first time today, it didn’t do anything. Then a subsequent push of the button turned on the machine.

On my other GS3 (non IOT model) i’m pretty sure it always turns on first time with the first push of the power button in the mornings (i.e after a long period of being on standby).

Furthermore, if I turn the machine off and on again it turns on with one push of the power button.

Not sure if you can pick up anything in the logs to do with the integration.. But this leads me to believe it might be an actual firmware issue. Would need some others to confirm this behaviour on the same fw and machine to be sure.

I will also keep testing in the mornings and furthermore try and get this on video.

Or else - if not a firmware issue perhaps this is an intentional standby mode and the integration needs to be adapted as such. But judging by the lack of bug reports by your users (not sure how many GS3 users you have) I would imagine other machines don’t have this issue. At least the GS3 AV’s.

EDIT: Is the turn on and turn off the same bytes to write? is it just a toggle? Or does it write a separate value/byte. In which case, I’m wondering how come the official LM app works properly when turning it on from this “sleep” mode. Are they writing the “On” bytes/value multiple times like a pulse and then waiting for a response. Is there any harm to writing the “on” byte more than once?

again will confirm findings tomorrow just thinking out loud..

nic-zh commented 1 year ago

Yes, after standby I need to press the power button twice on the machine, I assumed it is feature. Not 100% though if it is every time, pretty sure I woke it up through HA successfully via manually pressing "main". In the automation I had issues. (I haven't tested myself, but set the timeout to the shortest time 30 min?, try to cope without espresso while testing :) and press the button/run the automation after sleep).

ari-za commented 1 year ago

It’s definitely after x amount of time in standby it goes to “sleep” but still shows “standby” on the screen. Not sure exactly what that time is. Other times it just takes one press to turn it on. 

Not sure if this behaviour is the same on other machines/GS3 AV

rccoleman commented 1 year ago

Are you guys using the auto-standby feature? I've never used that and just manually turn off the machine (put in standby) when I'm done for the day.

ari-za commented 1 year ago

Are you guys using the auto-standby feature? I've never used that and just manually turn off the machine (put in standby) when I'm done for the day.

Good thought. I disabled it now, it was on 60mins. Not sure about @nic-zh

nic-zh commented 1 year ago

yes I also do. I'll keep it, I'm trying to conserve a tiny bit of energy, I sometimes walk out of the kitchen and forget... @rccoleman no worries about looking into it, I can live with the workaround.

rccoleman commented 1 year ago

That log was very helpful, thanks. These are the important parts:

Initial query of the machine status:

2023-03-20 | 11:03:11.559 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811

The first byte is "00", which means the machine was off.

This is the part where the integration sent the "turn on" command and the machine responded with "OK":

2023-03-20 | 11:03:50.277 | DEBUG (MainThread) [lmdirect.connection] Sending 00000001 with 01 None
2023-03-20 | 11:03:50.559 | DEBUG (MainThread) [lmdirect.connection] Message=00000001, Data=OK
2023-03-20 | 11:03:50.559 | DEBUG (MainThread) [lmdirect.connection] Command Succeeded: 00000001: OK

Later, the status is the same as the before:

2023-03-20 | 11:04:11.554 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=00003C026E3230039804A6000608000012180000006E00DC0096012C03E811
2023-03-20 | 11:04:11.554 | DEBUG (MainThread) [lmdirect.connection] Element power hasn't updated yet, so use the cached value 0

Again, note that the first byte is "00" - machine is off, and the logs note that we've told it to turn on and it hasn't turned on yet despite the successful command. It carries on like that for several status requests until:

2023-03-20 | 11:06:04.443 | DEBUG (MainThread) [lmdirect.connection] Sending 00000001 with 00 None
2023-03-20 | 11:06:05.329 | DEBUG (MainThread) [lmdirect.connection] Message=00000001, Data=OK
2023-03-20 | 11:06:05.329 | DEBUG (MainThread) [lmdirect.connection] Command Succeeded: 00000001: OK

The integration is telling the machine to turn off. And now it wants to turn it on:

2023-03-20 | 11:06:06.831 | DEBUG (MainThread) [lmdirect.connection] Sending 00000001 with 01 None
2023-03-20 | 11:06:07.169 | DEBUG (MainThread) [lmdirect.connection] Message=00000001, Data=OK
2023-03-20 | 11:06:07.170 | DEBUG (MainThread) [lmdirect.connection] Command Succeeded: 00000001: OK

FINALLY, it turns on:

2023-03-20 | 11:06:07.174 | DEBUG (MainThread) [lmdirect.connection] Message=0000001F, Data=01003C026E3230039804A6000608000012180000006E00DC0096012C03E811
2023-03-20 | 11:06:07.175 | DEBUG (MainThread) [lmdirect.connection] Element power has updated to 1, pop the cached value

So, my analysis is that the machine ignores the first attempt to turn it on, despite responding with "OK". I don't recall if the official app performs any retries if it doesn't change state as expected, but if you can repro in the official app, I would report it to La Marzocco as an issue in their firmware. And if it goes away if you disable "auto standby", mention that.

ari-za commented 1 year ago

Ok great! Glad they are helpful. Good to know we are getting somewhere. Of course we can easily do a workaround but I’m sure it’s easy enough to fix.

It very well might be related to that auto-standby feature. Makes sense.

If so, can either control auto power off through an HA automation and disable it from the machine, or fix the integration so we can retain all proper functionality.

Thanks!

rccoleman commented 1 year ago

I'm sure that the state of "auto standby" is somewhere in the status data, and there's probably a way to enable/disable it that I haven't bothered to find (since I don't use it), but I'm not inclined to do anything in the integration to work around the fact that the machine is misbehaving. I suggest reporting the issue to LM and using a script that toggles power instead of simply turning on the switch.

ari-za commented 1 year ago

I will test the LM app and see how it handles this. If that works which it seems to, perhaps you could emulate that, or otherwise as you say we can just disable that feature for proper functionality. And then maybe make a note in the readme to save people the future headache.

ari-za commented 1 year ago

@nic-zh FYI in case you or anyone else was interested, heres an HA automation which seems to work well to retain the auto-standby behaviour, and it also survives restarts of HA.

https://community.home-assistant.io/t/trigger-after-some-time-has-passed-even-after-reboot/310904/8?u=aaelex

Just change the entities to yours

I will disable the LM app auto-standby feature and use this HA automation instead. Then my switch on commands will work properly as expected

I also reported this to LM technical. Will see what they say.

EDIT: Added pic of my coffee dashboard, which also features the timer used in the automation above IMG_6213

Side note: @rccoleman - The Auto On/off always shows as on, even though the function is disabled in the LM app.

rccoleman commented 1 year ago

Just to be clear, "Auto on/off" isn't the same as "Auto standby". There was a bug in reporting the Auto on/off state recently, but I thought it was correct in the latest version. I can reproduce the issue and will take a look.

Edit: I see what's wrong. It's setting the value properly, but the integration is trying to interpret the state as a boolean, but lmdirect is populating it as a string.

ari-za commented 1 year ago

Just to be clear, "Auto on/off" isn't the same as "Auto standby". There was a bug in reporting the Auto on/off state recently, but I thought it was correct in the latest version. I can reproduce the issue and will take a look.

Edit: I see what's wrong. It's setting the value properly, but the integration is trying to interpret the state as a boolean, but lmdirect is populating it as a string.

That’s right, I’m aware. Auto On/Off is the scheduler.

Great, glad you managed to reproduce.

The auto standby automation I posted above works great as a workaround for the other Issue.

rccoleman commented 1 year ago

I just released v0.9.8 as a pre-release that should fix the auto on/off switch.

nic-zh commented 1 year ago

Thanks for your work! I've tested 0.9.8 but went back to 0.9.7. I have noticed tow things, but I can't say for sure it is related to this version or something else. So please don't take it as critique. 1) after turning on the machine (front display) and not pulling an espresso, it used to stay on indefinitely, independent of the standby settings. Only after making an espresso it goes into standby. This seems to be different now. Even without touching the machine after turning it on, it goes into standby. 2) only now I notice also the issue with the machine not turning on when using the "main switch" of the integration. Before was only in an automation, but never when manually turning the machine on with the integration. Hope this helps Thanks again!

rccoleman commented 1 year ago

Hard to see how the single change that I made to correct the auto on/off state would have any impact on either. #1 just sounds like machine behavior completely independent of the integration, and I can't (or won't) do anything about #2 when the machine responds OK to the turn on request.

nic-zh commented 1 year ago

just to correct my mistake. I needed to go back to 0.9.6. This is not meant as a request for changes, but perhaps it explains the behavior. Thanks

Thanks for your work! I've tested 0.9.8 but went back to 0.9.7. I have noticed tow things, but I can't say for sure it is related to this version or something else. So please don't take it as critique.

  1. after turning on the machine (front display) and not pulling an espresso, it used to stay on indefinitely, independent of the standby settings. Only after making an espresso it goes into standby. This seems to be different now. Even without touching the machine after turning it on, it goes into standby.
  2. only now I notice also the issue with the machine not turning on when using the "main switch" of the integration. Before was only in an automation, but never when manually turning the machine on with the integration. Hope this helps Thanks again!
rccoleman commented 10 months ago

I'm archiving this repo because this integration no longer works with current machine firmware. Please move to https://github.com/zweckj/lamarzocco.