Comment 9 for bug 2056160

Revision history for this message
Olivier Gayot (ogayot) wrote (last edit ):

From my observations, there are two separate aspects to this.

First, subiquity waits for cloud-init (it takes ~30 seconds to complete in my runs). I'm not sure if there is any way to reduce this delay.

Perhaps more importantly tough, after Subiquity reports {"state": "WAITING"}, it still takes 30 more seconds until the loading animation is shown.

It looks like the UI is blocking (without a visible animation) until Subiquity sends a response to /refresh ; which times out after 30 seconds when the network is down:

24-04-05 12:24:15,379 DEBUG root:30 start: subiquity/Refresh/check_for_update:
2024-04-05 12:24:15,380 DEBUG subiquitycore.utils:119 arun_command called: ['/usr/sbin/realm', 'discover']
2024-04-05 12:24:15,396 DEBUG root:30 start: subiquity/OEM/load_metapackages_list:
2024-04-05 12:24:15,396 DEBUG root:30 start: subiquity/OEM/load_metapackages_list/wait_confirmation:
2024-04-05 12:24:15,396 DEBUG root:30 start: subiquity/Install/install:
2024-04-05 12:24:15,397 DEBUG root:30 start: subiquity/Filesystem/_probe:
2024-04-05 12:24:15,397 DEBUG root:30 start: subiquity/Filesystem/_probe/probe_once: restricted=False
2024-04-05 12:24:15,398 DEBUG asyncio:54 Using selector: EpollSelector
2024-04-05 12:24:15,400 INFO root:30 start: subiquity/Meta/status_GET:
2024-04-05 12:24:15,401 INFO root:30 finish: subiquity/Meta/status_GET: SUCCESS: 200 {"state": "WAITING", "confirming_tty": "", "error": null, "nonreportable_erro...
2024-04-05 12:24:15,425 INFO root:30 start: subiquity/Meta/client_variant_POST:
2024-04-05 12:24:15,426 INFO root:30 finish: subiquity/Meta/client_variant_POST: SUCCESS: 200 null
2024-04-05 12:24:15,426 DEBUG root:30 start: subiquity/Refresh/GET:
2024-04-05 12:24:15,445 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/snaps/ubuntu-desktop-bootstrap HTTP/1.1" 200 1348
2024-04-05 12:24:15,461 DEBUG root:30 finish: subiquity/Refresh/configure_snapd/get_details: SUCCESS: current version of snap is: '0+git.046d4c30'
2024-04-05 12:24:15,462 DEBUG subiquity.server.controllers.refresh:139 snap tracking , not resetting based on .disk/info
2024-04-05 12:24:15,462 DEBUG root:30 finish: subiquity/Refresh/configure_snapd: SUCCESS:
[...]

2024-04-05 12:24:48,179 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/find?select=refresh HTTP/1.1" 500 234
2024-04-05 12:24:48,182 ERROR subiquity.server.controllers.refresh:197 checking for snap update failed
Traceback (most recent call last):
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquity/server/controllers/refresh.py", line 195, in check_for_update
    result = await self.app.snapdapi.v2.find.GET(select="refresh")
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquity/common/api/client.py", line 47, in impl
    async with make_request(
  File "/snap/ubuntu-desktop-bootstrap/75/usr/lib/python3.10/contextlib.py", line 199, in __aenter__
    return await anext(self.gen)
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquity/server/snapdapi.py", line 298, in make_request
    content = await async_snapd.get(path[1:], **params)
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquitycore/snapd.py", line 226, in get
    response.raise_for_status()
  File "/snap/ubuntu-desktop-bootstrap/75/usr/lib/python3/dist-packages/requests/models.py", line 943, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
requests.exceptions.HTTPError: 500 Server Error: Internal Server Error for url: http+unix://%2Frun%2Fsnapd.socket/v2/find?select=refresh
2024-04-05 12:24:48,187 DEBUG root:30 finish: subiquity/Refresh/check_for_update: SUCCESS: checking for snap update failed
2024-04-05 12:24:48,188 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "UNKNOWN", "current_snap_version": "0+git.046d4c30", "new_sn...

I think this call should be made a non-blocking call (non-blocking from the UI standpoint that is)