Skip to content
This repository has been archived by the owner on Jan 5, 2024. It is now read-only.

Stopped working since recent LM Linea Mini firmware upgrade #44

Closed
valsily opened this issue Jul 7, 2023 · 116 comments
Closed

Stopped working since recent LM Linea Mini firmware upgrade #44

valsily opened this issue Jul 7, 2023 · 116 comments

Comments

@valsily
Copy link

valsily commented Jul 7, 2023

Hi,

First of all, thank you so much for making such a great integration. It has worked great with my Linea Mini until this morning. I saw an firmware update in the La Marzocco Home app and decided to proceed with it, which appears to be a bad idea now.

The upgrade went smoothly and successfully completed. But the machine became unreachable from my home assistant since then.

I had tried to restart both the espresso machine and Home Assistant server but still no luck.

Just wondering if there is any way to fix this? Or is anyone running into such issues recently?

Thanks in advance

image
@valsily valsily changed the title Stopped working since recent LM firmware upgrade Stopped working since recent LM Linea Mini firmware upgrade Jul 7, 2023
@KonstantinSuvorov97
Copy link

KonstantinSuvorov97 commented Jul 7, 2023 via email

@mrvautin
Copy link

mrvautin commented Jul 7, 2023

@valsily you will need to use this repo in HA for now which supports the new API for Micra and Mini's. https://github.com/zweckj/lamarzocco

@orxelm
Copy link

orxelm commented Jul 9, 2023

@mrvautin why are you saying that? Did @rccoleman stopped supporting the project?

@mrvautin
Copy link

mrvautin commented Jul 9, 2023

@orxelm no just the support is not merged into the main repo yet. Still working on it. I should have said "use this repo for now".

@gmathur
Copy link

gmathur commented Jul 9, 2023

Actually my GS3 integration also stopped working since the latest upgrade.

Gateway v3.1-RC4
Machine firmware 1.40

Happy to help provide whatever other debug info you may need.

@zweckj
Copy link
Contributor

zweckj commented Jul 9, 2023

@gmathur you can test pre-release v0.12.0-beta.1 on my fork, which should theoretically also support the GS3

@rccoleman
Copy link
Owner

BTW, here's their blog entry indicating that all machines must update to the new gateway by Sept 10: https://home.lamarzoccousa.com/important-firmware-update/

@rccoleman rccoleman pinned this issue Jul 9, 2023
@gmathur
Copy link

gmathur commented Jul 10, 2023

@gmathur you can test pre-release v0.12.0-beta.1 on my fork, which should theoretically also support the GS3

Ill give it a whirl today and respond back.

@gmathur
Copy link

gmathur commented Jul 10, 2023 •
edited
Loading

@gmathur you can test pre-release v0.12.0-beta.1 on my fork, which should theoretically also support the GS3

Tried beta1 - beta4. Seeing this issue in logs as soon as I try and configure the integration.
My best guess is some version mismatch (or missing dependencies) with lmcloud?

Logger: aiohttp.server
Source: custom_components/lamarzocco/config_flow.py:45
Integration: lamarzocco ([documentation](https://github.com/rccoleman/lamarzocco), [issues](https://github.com/rccoleman/lamarzocco/issues))
First occurred: 3:45:20 PM (2 occurrences)
Last logged: 3:45:33 PM

Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohttp/web_protocol.py", line 433, in _handle_request
    resp = await request_handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/security_filter.py", line 85, in security_filter_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/forwarded.py", line 100, in forwarded_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 28, in request_context_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 80, in ban_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 236, in auth_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 148, in handle
    result = await handler(request, **request.match_info)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/config/config_entries.py", line 181, in post
    return await super().post(request, flow_id)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/data_validator.py", line 72, in wrapper
    result = await method(view, request, data, *args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/data_entry_flow.py", line 110, in post
    result = await self._flow_mgr.async_configure(flow_id, data)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 297, in async_configure
    result = await self._async_handle_step(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 393, in _async_handle_step
    result: FlowResult = await getattr(flow, method)(user_input)
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/lamarzocco/config_flow.py", line 86, in async_step_user
    return await self._try_create_entry(data)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/lamarzocco/config_flow.py", line 67, in _try_create_entry
    machine_info = await validate_input(self.hass, data)
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/lamarzocco/config_flow.py", line 45, in validate_input
    lm = await LaMarzoccoClient.create(hass=hass, data=data)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: LMCloud.create() got an unexpected keyword argument 'hass'

Trying with master, I hit a different error:

Logger: aiohttp.server
Source: custom_components/lamarzocco/interface.py:97
Integration: La Marzocco ([documentation](https://github.com/rccoleman/lamarzocco), [issues](https://github.com/rccoleman/lamarzocco/issues))
First occurred: 4:23:52 PM (1 occurrences)
Last logged: 4:23:52 PM

Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohttp/web_protocol.py", line 433, in _handle_request
    resp = await request_handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/security_filter.py", line 85, in security_filter_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/forwarded.py", line 100, in forwarded_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 28, in request_context_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 80, in ban_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 236, in auth_middleware
    return await handler(request)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 148, in handle
    result = await handler(request, **request.match_info)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/config/config_entries.py", line 181, in post
    return await super().post(request, flow_id)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/http/data_validator.py", line 72, in wrapper
    result = await method(view, request, data, *args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/data_entry_flow.py", line 110, in post
    result = await self._flow_mgr.async_configure(flow_id, data)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 297, in async_configure
    result = await self._async_handle_step(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 393, in _async_handle_step
    result: FlowResult = await getattr(flow, method)(user_input)
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/lamarzocco/config_flow.py", line 87, in async_step_user
    return await self._try_create_entry(data)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/lamarzocco/config_flow.py", line 68, in _try_create_entry
    machine_info = await validate_input(self.hass, data)
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/lamarzocco/config_flow.py", line 44, in validate_input
    lm = await LaMarzocco.create(hass=hass, data=data)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/lamarzocco/api.py", line 39, in create
    await self.init_lm_client(hass=hass, config=config_entry.data if config_entry else data)
  File "/config/custom_components/lamarzocco/interface.py", line 97, in init_lm_client
    self._lm_direct = LMDirect.__init__(config)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: LMDirect.__init__() missing 1 required positional argument: 'machine_info'

@zweckj
Copy link
Contributor

zweckj commented Jul 11, 2023

apologies, the flow for setting up the integration from scratch was untested. beta.5 should fix this issue.

@gmathur
Copy link

gmathur commented Jul 11, 2023

That totally did the trick - everything is up and running. You rock!

Thanks so much for doing this!

@mrvautin
Copy link

mrvautin commented Jul 13, 2023 •
edited
Loading

Is @zweckj or anyone else experiencing the main entity being out of sync with the machine?

Mine is showing on but the machine is off (in standby):

image

The official app is correctly showing the machine as off:

image

Toggling the entity off and on fixes it but just wondering if there is an issue.

@zweckj
Copy link
Contributor

zweckj commented Jul 13, 2023

@mrvautin are you on the latest pre-release? (0.12.0-beta.5)

@mrvautin
Copy link

@mrvautin are you on the latest pre-release? (0.12.0-beta.5)

Yes. I'm on that release.

The issue seems to stem from the machine going into standby after a period of time and Home Assistant not getting the update.

Is there anything I can check do give you proper info?

@zweckj
Copy link
Contributor

zweckj commented Jul 13, 2023 •
edited
Loading

Does it the other way for you - bringing the machine out of StandBy with the paddle? I just tested that and that appears to be working fine. Also turning the machine off through the official app reflects in HA for me. Would be good if you could test those things as well (always keep in mind it can take up to 30 seconds for the state to update)

@mrvautin
Copy link

@zweckj it doesn't work. I toggled the entity off, moved the paddle and home assistant is still showing as off. The LM app is correctly updated from the paddle. There is nothing in the logs indicating any issues.

@zweckj
Copy link
Contributor

zweckj commented Jul 13, 2023

@mrvautin interesting. Turn debug logging on please, it should log the entire status object whenever it gets refreshed (every 30 seconds). If that indeed seems wrong, also reload the integration once

@mrvautin
Copy link

@zweckj it's really weird, my HA has debug turned on and I can see debug logs however not the full output every 30 secs. I might need to remove and re-install entirely.

2023-07-13 16:20:55.391 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Manually updated La Marzocco API coordinator data
2023-07-13 16:20:55.393 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Manually updated La Marzocco API coordinator data
2023-07-13 16:21:15.359 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Manually updated La Marzocco API coordinator data
2023-07-13 16:21:15.360 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Manually updated La Marzocco API coordinator data
2023-07-13 16:21:35.351 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Manually updated La Marzocco API coordinator data
2023-07-13 16:21:35.352 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Manually updated La Marzocco API coordinator data

@zweckj
Copy link
Contributor

zweckj commented Jul 13, 2023

@mrvautin yes that's weird. Seems like the update coordinator is not running properly for you.
There should be an Update coordinator: Updating data every 30 seconds followed by the data.

@mrvautin
Copy link

mrvautin commented Jul 13, 2023 •
edited
Loading

@zweckj I've totally removed and reinstalled. I had debugging turned on in the config which didn't seem to work. When I clicked on debugging through the integration it works as I'd expect.

image

I had Websockets enabled. When I turned it off the main entity works perfectly now. Seems to be related to the websocket code but still nothing in the logs to indicate why or what.

@zweckj
Copy link
Contributor

zweckj commented Jul 13, 2023

I had Websockets enabled. When I turned it off the main entity works perfectly now. Seems to be related to the websocket code but still nothing in the logs to indicate why or what.

yeah that can be, sorry should have made that clearer that that is a VERY beta functionality

@zweckj
Copy link
Contributor

zweckj commented Jul 13, 2023

@mrvautin I think I found the issues. Could you please test beta.6 and report back?

@mrvautin
Copy link

mrvautin commented Jul 13, 2023 •
edited
Loading

@mrvautin I think I found the issues. Could you please test beta.6 and report back?

Thanks @zweckj. I will have a test. Also note there is a new machine update for me this morning in the LM app. V3.1-RC6.

@zweckj
Copy link
Contributor

zweckj commented Jul 14, 2023

[...] there is a new machine update for me this morning in the LM app. V3.1-RC6.

appears to be a bugfix release, but please report if anything breaks

@edwardsa
Copy link

Thanks for all the hard work on this. My machine is on gateway V3.1-RC6 and I am using the latest beta release (0.12.0-beta.6) and am seeing the following error after configuring

2023-07-15 11:42:45.886 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Update coordinator: Updating data
2023-07-15 11:42:48.714 DEBUG (MainThread) [custom_components.lamarzocco.lm_client] Model name: Linea Mini
2023-07-15 11:42:49.156 ERROR (MainThread) [custom_components.lamarzocco.coordinator] 'NoneType' object is not subscriptable
2023-07-15 11:42:49.158 DEBUG (MainThread) [custom_components.lamarzocco.coordinator] Finished fetching La Marzocco API coordinator data in 3.273 seconds (success: False)

The result is an endless "retrying setup" loop - and the entities are never created. I have retried numerous times over the past 12 hours without any success. Any ideas on what the cause is, or how I can get you more details.

@edwardsa
Copy link

The result is an endless "retrying setup" loop - and the entities are never created. I have retried numerous times over the past 12 hours without any success. Any ideas on what the cause is, or how I can get you more details.

Ok - this is crazy. So immediately after posting this it just started working. I wonder if their cloud endpoint had some sort of outage? I also wonder if we could detect that and log in such a case so it is easier to identify if it happens again.

@gmathur
Copy link

gmathur commented Jul 15, 2023 •
edited
Loading

Upgraded to the RC6 gateway and beta6 integration. But integration stopped working for me - Start/stop wasn't working as an example.

Going back to beta5 (with the updated gateway) fixed it for me.

@zweckj
Copy link
Contributor

zweckj commented Jul 15, 2023 •
edited
Loading

I also wonder if we could detect that and log in such a case so it is easier to identify if it happens again.

I am normally logging anything that is not a success status code very visibly as a warning, so they'd need to have returned a success without the information I'm looking for...

Upgraded to the RC6 gateway and beta6 integration. But integration stopped working

@gmathur that is weird, I didn't touch anything except WebSocket code in beta.6 (which is working flawlessly for me). Can you maybe try beta.6 again later and turn on debug logging?

@zweckj
Copy link
Contributor

zweckj commented Aug 18, 2023

I was able to test this again with my La Marzocco app while not connected to WiFi. It did not cause HA to get more datapoints, which implies that the handshake is still local (or perhaps local followed by cloud, but I hope not). As mentioned above, I'll try to MITM this over the weekend.

what happens if you do the same test, but with WiFi on and Bluetooth off (the app will complain quite a bit, but should still function)?

@mtwo
Copy link

mtwo commented Aug 18, 2023

Just tested two things:

  • Disabling Bluetooth still worked fine, in fact the app never complained and it behaved normally. Perhaps the connection to the GS3 behaves differently than the Linea Mini or Micra.
  • Blocking my phone from the internet via firewall caused the app to hang upon opening, probably because it tries to log in to La Marzocco before connecting to the machine.

@rccoleman
Copy link
Owner

rccoleman commented Aug 22, 2023 •
edited
Loading

I just grabbed a mitm trace and saw some interesting transactions. Here's a pic:

image

First, you can see that it tries to connect to my machine and fails with the same 403 error that the integration gets. It then does a GET https://gw-lmz.lamarzocco.io/v1/home/machines/GS013432/token-request, which returns this:

{
    "data": {
        "commandId": "78c69d29-f764-4edd-b8bf-1a35e299b47a"
    },
    "status": true
}

It then makes a request to the cloud "commands" endpoint with that commandid and returns a bunch of stuff that I don't understand, but makes lots of references to tokens (command seems to be TokenGet)

Later, it =makes a request to POST https://gw-lmz.lamarzocco.io/v1/home/machines/GS013432/clock with the current date and time:

{
    "date": "Mon Aug 21 2023 17:54:32 GMT-0700 (Pacific Daylight Time)"
}

and gets back another commandid. It makes another request to the cloud "commands" endpoint with that commandid and gets back some stuff that looks similar to the first call (command this time is TimeStampUpdate).

After it does those things, the next call to the machine's local API succeeds. I haven't looked closely at what the localapi part of lmcloud does, but I suspect the magic is in those API calls somewhere. I saved the flows so that I can go back and review them later, but I suspect that you'd see something similar with your machines. Does that command sequence reflect what's currently done in the integration?

@zweckj
Copy link
Contributor

zweckj commented Aug 22, 2023 •
edited
Loading

Does that command sequence reflect what's currently done in the integration?

Not at all 😅I saw some of those commands as well, but ignored them entirely, because I didn't need them. I just get the token from the cms endpoint and call the /config and /stream endpoints with that directly without any other logic.
What would be interesting is, what happens if you'd block the machine from accessing the internet in the firewall (not the app). Does it ever resolve that 403?
I'm currently blocked to do any tests on my end, because my machine disconnected from my WiFi and it doesn't want to activate Bluetooth again to reconnect...

@rccoleman
Copy link
Owner

I'll run some more experiments when I get some time, including simulating the GetToken and TimeStampUpdate commands and see if it helps. My machine falls into the broken state quite frequently now, so it makes me think that something may have changed on the LM side. It wasn't an issue when I first updated to the new gateway, but now it's broken more often than not.

@rccoleman
Copy link
Owner

BTW, hopefully you can get your machine to connect again :). I'm curious if you would see the same type of transactions for your machine, even if it's able to initially connect, or if it's a reaction to the failure. It's also possible that LM treats the Micra (designed as a home machine) and GS3 (more prosumer, could be in a cafe) differently.

@zweckj
Copy link
Contributor

zweckj commented Aug 22, 2023 •
edited
Loading

BTW, hopefully you can get your machine to connect again :).

I do hope so, thanks! Currently in contact with LM's IoT support in Italy...

I'm curious if you would see the same type of transactions for your machine, even if it's able to initially connect, or if it's a reaction to the failure.

Me too.

It's also possible that LM treats the Micra (designed as a home machine) and GS3 (more prosumer, could be in a cafe) differently.

Something is definitely different about the GS3. I've heard zero complaints from Micra/Mini owners in that direction.

@rccoleman
Copy link
Owner

rccoleman commented Aug 22, 2023 •
edited
Loading

My initial testing shows that doing these two things fixes the connection issue:

image

I didn't even have to do anything with the response. I just used Postman to send the first one, got the commandid from the response (which was different from the initial trace), then made a separate request to the "commands" endpoint. The connection errors stopped and I suddenly got the correct current temperature in the integration.

@zweckj
Copy link
Contributor

zweckj commented Aug 23, 2023

Wondering what they're doing this for. I'll add it to lmcloud. The question is, how often does this call need to be made?

@rccoleman
Copy link
Owner

rccoleman commented Aug 23, 2023 •
edited
Loading

Wondering what they're doing this for. I'll add it to lmcloud. The question is, how often does this call need to be made?

I would say 'when it fails', but I'll check if the app just does it unconditionally or if it's triggered by a connection failure. My guess is that when the app starts they spawn a thread that keeps trying to connect locally and another that does the cloud connection. From the app, it seems like it just keeps trying the local api while the app is open to see if it's working (in case you come into range, restart the machine, etc). They're probably not expecting the app to stay running continuously, as the integration does.

I understand that tying the cloud and localapi pieces together to trigger a new token request on a local failure probably isn't ideal. I don't see anything in the responses about token expiration, but maybe you would if these calls work for your machine.

@zweckj
Copy link
Contributor

zweckj commented Aug 23, 2023

I understand that tying the cloud and localapi pieces together to trigger a new token request on a local failure probably isn't ideal.

don't worry they are tied together in the main class anyways.

I don't see anything in the responses about token expiration, but maybe you would if these calls work for your machine.

yeah that might take a while... LM sends me an entirely new IoT board to swap out the current one...
I published 0.12.2-alpha.1. But it's best guess development as I can't test it at all. Maybe we're lucky though and it works (and I didn't make the usual silly coding mistake)... Give it a try please and let me know.

@rccoleman
Copy link
Owner

rccoleman commented Aug 23, 2023 •
edited
Loading

Will do. Does your machine need to be online to make those calls to the cloud API in Postman (or equivalent)?

Results look positive so far. I got exactly one of these, but it seemed to recover and start providing valid data:

2023-08-23 10:35:24.100 WARNING (MainThread) [lmcloud.lmcloud] Could not connect to local API although initialized

BTW, I still always get this on shutdown. I keep meaning to look into it, but never do:

2023-08-23 10:42:47.000 WARNING (MainThread) [homeassistant.core] Task <Task pending name='Task-19363' coro=<LMLocalAPI.websocket_connect() running at /usr/local/lib/python3.11/site-packages/lmcloud/lmlocalapi.py:77> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[set.remove()]> was still running after stage 2 shutdown; Integrations should cancel non-critical tasks when receiving the stop event to prevent delaying shutdown

@zweckj
Copy link
Contributor

zweckj commented Aug 23, 2023 •
edited
Loading

Will do. Does your machine need to be online to make those calls to the cloud API in Postman (or equivalent)?

I don't know. I removed my machine from the app, now I don't have anything in my LM account anymore, so I can't do anything...

Results look positive so far. I got exactly one of these, but it seemed to recover and start providing valid data:


2023-08-23 10:35:24.100 WARNING (MainThread) [lmcloud.lmcloud] Could not connect to local API although initialized

I probably need to wait a bit before trying the local call again and it's currently only reconnecting on the next iteration.

BTW, I still always get this on shutdown. I keep meaning to look into it, but never do:


2023-08-23 10:42:47.000 WARNING (MainThread) [homeassistant.core] Task <Task pending name='Task-19363' coro=<LMLocalAPI.websocket_connect() running at /usr/local/lib/python3.11/site-packages/lmcloud/lmlocalapi.py:77> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[set.remove()]> was still running after stage 2 shutdown; Integrations should cancel non-critical tasks when receiving the stop event to prevent delaying shutdown

I believe those are coming from the WebSocket task still running in the background. I tried a couple of things to terminate it cleanly, but never figured it out.

@rccoleman
Copy link
Owner

rccoleman commented Aug 25, 2023 •
edited
Loading

I haven't had the integration drop offline since the latest integration release, so I'm hopeful it's fixed. @mtwo how about you?

After thinking more about what's going on and looking back at the Wireshark trace, it looks like maybe the app making the token-request call initiates a message from the cloud back to the machine to tell it that it's okay to accept local connections. From above:

4425	35.314158	192.168.1.150	192.168.1.215	HTTP	358	GET /api/v1/config HTTP/1.1 
4426	35.315477	192.168.1.150	192.168.1.215	TCP	60	[TCP Dup ACK 4424#1] 63380 → 8081 [ACK] Seq=305 Ack=1 Win=65535 Len=0
4429	35.338316	192.168.1.215	192.168.1.150	TCP	123	8081 → 63380 [PSH, ACK] Seq=1 Ack=305 Win=5440 Len=69 [TCP segment of a reassembled PDU]
4430	35.338962	192.168.1.215	192.168.1.150	TCP	56	8081 → 63380 [PSH, ACK] Seq=70 Ack=305 Win=5440 Len=2 [TCP segment of a reassembled PDU]
4431	35.339280	192.168.1.215	192.168.1.150	HTTP	68	HTTP/1.1 403 Forbidden  (text/html)
4432	35.341501	192.168.1.150	192.168.1.215	TCP	60	63380 → 8081 [ACK] Seq=305 Ack=86 Win=65535 Len=0
4482	35.834681	52.29.238.7	192.168.1.215	TLSv1.2	486	Application Data
4483	35.853165	192.168.1.215	52.29.238.7	TLSv1.2	87	Application Data
4502	36.058643	52.29.238.7	192.168.1.215	TCP	60	8883 → 62496 [ACK] Seq=6341 Ack=6057 Win=64800 Len=0
4508	36.130601	192.168.1.215	52.29.238.7	TLSv1.2	289	Application Data
4523	36.293125	52.29.238.7	192.168.1.215	TCP	60	8883 → 62496 [ACK] Seq=6341 Ack=6292 Win=64800 Len=0
5808	43.908247	192.168.1.215	52.29.238.7	TLSv1.2	85	Application Data
5961	44.078771	52.29.238.7	192.168.1.215	TCP	60	8883 → 62496 [ACK] Seq=6341 Ack=6323 Win=64800 Len=0
5962	44.078800	52.29.238.7	192.168.1.215	TLSv1.2	85	Application Data
5970	44.087327	192.168.1.150	192.168.1.215	TCP	78	49524 → 8081 [SYN] Seq=0 Win=65535 Len=0 MSS=1460 WS=64 TSval=1134347859 TSecr=0 SACK_PERM
5992	44.124784	192.168.1.215	192.168.1.150	TCP	58	8081 → 49524 [SYN, ACK] Seq=0 Ack=1 Win=5744 Len=0 MSS=1440
5993	44.128774	192.168.1.150	192.168.1.215	TCP	60	49524 → 8081 [ACK] Seq=1 Ack=1 Win=65535 Len=0
5994	44.130509	192.168.1.150	192.168.1.215	HTTP	350	GET /api/v1/streaming HTTP/1.1 
6002	44.146410	192.168.1.215	192.168.1.150	HTTP	183	HTTP/1.1 101 Switching Protocols

Unfortunately, I don't know how one would mitm the communication between the machine and the cloud to see what it's saying. The fact that the incoming transaction seems otherwise unsolicited makes me think that it's related to the unseen (in that trace) connection from the app to the LM gateway.

It all seems very complicated. Reviewing the token/command transaction, it's clear that it's publishing to an MQTT topic in the background, and now I see that the incoming connection is coming from 8883, which is the secure MQTT broker connection. So, the machine is subscribed to a topic, and requesting a token via the endpoint publishes a message to the topic that the machine receives and unlocks the local API. Phew.

@zweckj
Copy link
Contributor

zweckj commented Aug 25, 2023

That would mean though that your machine needs internet access to function properly, wouldn’t it. Terrible design, but so be at. I'm still wondering why they'd only make it like this for the GS3 though, what’s their reasoning for the required internet access.

@rccoleman
Copy link
Owner

To use the app, yeah. I'm sure they have their reasons, and equally sure that we'd probably disagree.

@zweckj
Copy link
Contributor

zweckj commented Aug 27, 2023

@rccoleman in the new beta I added a 3 second delay before the next retry after the first 403. Was that enough to get rid of the warning?

@rccoleman
Copy link
Owner

Looks good, I don't see a 403 anymore. It's weirdly not seeing my BT proxy anymore, though, and it did before. I can see it setting up the adapter in the log, along with lmcloud:

2023-08-27 08:50:09.029 INFO (MainThread) [aioesphomeapi.reconnect_logic] Successfully connected to olimex-bluetooth-proxy-3e57a8 @ 192.168.1.104
2023-08-27 08:50:09.079 INFO (MainThread) [homeassistant.setup] Setting up bluetooth_adapters
2023-08-27 08:50:09.080 INFO (MainThread) [homeassistant.setup] Setup of domain bluetooth_adapters took 0.0 seconds
2023-08-27 08:50:09.129 INFO (SyncWorker_6) [homeassistant.util.package] Attempting install of lmcloud==0.3.35

But then it goes on to say:

2023-08-27 08:50:27.737 WARNING (MainThread) [lmcloud.lmcloud] Could not find bluetooth device. Bluetooth commands will not be available and commands will all be sent through cloud.

The ESPHome BT Proxy logs look okay.

@zweckj
Copy link
Contributor

zweckj commented Aug 27, 2023

Consistently? Or does it go away if you restart the integration without restarting HA? Is the machine discoverable with a BLE scanner app? Or does it only become available again some time after integration start up?

@rccoleman
Copy link
Owner

Nevermind, it was consistent, but I removed the iBeacon tracker integration and reconfigured it after discovery and the LM integration sees it again. 🤷

@mtwo
Copy link

mtwo commented Sep 1, 2023

Confirmed that this seems to be working for me with the latest updates, though I'm still perplexed why La Mazocco implemented this in the first place

@orxelm
Copy link

orxelm commented Sep 15, 2023

@rccoleman can you please share a status?

@zweckj
Copy link
Contributor

zweckj commented Sep 15, 2023

@rccoleman can you please share a status?

We won't be merging back to this repo, so you will need to use my fork.

@tron786
Copy link

tron786 commented Sep 24, 2023

So I added the integration. It works for a few seconds then becomes unavailable.
When I restart HA then it works for a few seconds again

Please advise

@zweckj
Copy link
Contributor

zweckj commented Sep 24, 2023

So I added the integration. It works for a few seconds then becomes unavailable.

When I restart HA then it works for a few seconds again

Please advise

You need to check your logs/enable debug logging if that doesn't give you enough information.

@orxelm
Copy link

orxelm commented Sep 27, 2023 •
edited
Loading

The integration suddenly stopped working for me..
I see these in the logs:

Logger: lmcloud.lmcloud
Source: custom_components/lamarzocco/coordinator.py:63 
Integration: La Marzocco ([documentation](https://github.com/rccoleman/lamarzocco), [issues](https://github.com/rccoleman/lamarzocco/issues)) 
First occurred: September 26, 2023 at 5:03:01 PM (2294 occurrences)
Last logged: 12:50:51 PM

Could not connect to local API although initialized

Logger: lmcloud.lmcloud
Source: custom_components/lamarzocco/lm_client.py:75 
Integration: La Marzocco ([documentation](https://github.com/rccoleman/lamarzocco), [issues](https://github.com/rccoleman/lamarzocco/issues)) 
First occurred: September 26, 2023 at 5:03:01 PM (2 occurrences) 
Last logged: 10:55:45 AM

Could not find bluetooth device. Bluetooth commands will not be available and commands will all be sent through cloud.

EDIT: nvm, ignore it for now. Looks like something is wrong with my machine

@valsily
Copy link
Author

valsily commented Oct 15, 2023 •
edited
Loading

Hi,

Just to report that my Linea Mini has been working with the fork from @zweckj for a few days and I have not noticed anything unusual so far. Sorry for not reporting earlier to the issue I submitted myself. I was relocating recently and didn't find the chance to test it until now.

My iPhone just received the latest La Marzocco Home app update, which now shows a prompt for another combination of updates:

Bluetooth gateway: V3.1-RC6 -> V3.2-RC9
Firmware: 2.10 -> 2.12

Just wondering if anyone has tried this update yet?

image

@mrvautin
Copy link

@valsily I've updated my machine to the latest version pictured and everything appears to be working correctly. No issues so far.

@rccoleman
Copy link
Owner

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

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests