HTTP Error 409 (Conflict) when Subiquity receives two successive POST queries to /refresh

[Olivier Gayot]

In multiple private reports, we are seeing an issue when attempting a refresh of the installer. It looks to be happening on 24.04 as well as on 23.10 so not specific to a given release.

2024-04-05 13:39:10,842 DEBUG root:30 start: subiquity/Refresh/GET:
2024-04-05 13:39:10,843 DEBUG root:30 finish: subiquity/Refresh/GET: SUCCESS: 200 {"availability": "AVAILABLE", "current_snap_version": "0+git.046d4c30", "new_...
2024-04-05 13:39:12,190 DEBUG root:30 start: subiquity/Refresh/POST:
2024-04-05 13:39:12,191 DEBUG root:30 start: subiquity/Refresh/POST/start_update:
2024-04-05 13:39:13,546 DEBUG root:30 start: subiquity/Refresh/POST:
2024-04-05 13:39:13,546 DEBUG root:30 start: subiquity/Refresh/POST/start_update:
2024-04-05 13:39:13,579 DEBUG urllib3.connectionpool:453 http://localhost:None "POST /v2/snaps/ubuntu-desktop-bootstrap HTTP/1.1" 202 81
2024-04-05 13:39:13,581 DEBUG root:30 finish: subiquity/Refresh/POST/start_update: SUCCESS: change id: 4
2024-04-05 13:39:13,582 DEBUG root:30 finish: subiquity/Refresh/POST: SUCCESS: 200 "4"
2024-04-05 13:39:13,586 DEBUG root:30 start: subiquity/Refresh/progress_GET:
2024-04-05 13:39:13,615 DEBUG urllib3.connectionpool:453 http://localhost:None "GET /v2/changes/4 HTTP/1.1" 200 None
2024-04-05 13:39:13,621 DEBUG root:30 finish: subiquity/Refresh/progress_GET: SUCCESS: 200 {"id": "4", "kind": "refresh-snap", "summary": "Refresh \"ubuntu-desktop-boot...
2024-04-05 13:39:14,263 DEBUG urllib3.connectionpool:453 http://localhost:None "POST /v2/snaps/ubuntu-desktop-bootstrap HTTP/1.1" 409 259
2024-04-05 13:39:14,264 ERROR root:30 finish: subiquity/Refresh/POST/start_update: FAIL: 409 Client Error: Conflict for url: http+unix://%2Frun%2Fsnapd.socket/v2/snaps/ubuntu-desktop-bootstrap
2024-04-05 13:39:14,266 DEBUG root:30 finish: subiquity/Refresh/POST: SUCCESS: 500 Traceback (most recent call last):
  File "/snap/ubuntu-desktop-bootstrap/75/...
2024-04-05 13:39:14,266 DEBUG subiquity.server.server:473 request to /refresh crashed
Traceback (most recent call last):
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquity/common/api/server.py", line 164, in handler
    result = await implementation(**args)
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquity/server/controllers/refresh.py", line 237, in POST
    return await self.start_update(context=context)
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquitycore/context.py", line 149, in decorated_async
    return await meth(self, **kw)
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquity/server/controllers/refresh.py", line 217, in start_update
    change_id = await self.app.snapdapi.v2.snaps[self.snap_name].POST(
  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 300, in make_request
    content = await async_snapd.post(path[1:], json, **params)
  File "/snap/ubuntu-desktop-bootstrap/75/bin/subiquity/subiquitycore/snapd.py", line 233, in post
    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: 409 Client Error: Conflict for url: http+unix://%2Frun%2Fsnapd.socket/v2/snaps/ubuntu-desktop-bootstrap
2024-04-05 13:39:14,266 DEBUG subiquity.common.errorreport:398 generating crash report
2024-04-05 13:39:14,271 INFO subiquity.common.errorreport:424 saving crash report 'request to /refresh crashed with HTTPError' to /var/crash/1712324354.266916752.server_request_fail.crash

[Olivier Gayot (ogayot)]

In all the reports, there is a duplicate call to POST /refresh, which is likely what causes the second snapd call to return 409:

2024-03-17 13:38:50,609 DEBUG urllib3.connectionpool:452 http://localhost:None "POST /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 202 81
2024-03-17 13:38:50,612 DEBUG root:30 finish: subiquity/Refresh/POST/start_update: SUCCESS: change id: 4
2024-03-17 13:38:50,613 DEBUG root:30 finish: subiquity/Refresh/POST: SUCCESS: 200 "4"
2024-03-17 13:38:50,619 DEBUG root:30 start: subiquity/Refresh/progress_GET:
2024-03-17 13:38:50,737 DEBUG urllib3.connectionpool:452 http://localhost:None "GET /v2/changes/4 HTTP/1.1" 200 None
2024-03-17 13:38:50,759 DEBUG root:30 finish: subiquity/Refresh/progress_GET: SUCCESS: 200 {"id": "4", "kind": "refresh-snap", "summary": "Refresh \"ubuntu-desktop-inst...
2024-03-17 13:38:51,766 DEBUG root:30 start: subiquity/Refresh/progress_GET:
2024-03-17 13:38:51,782 DEBUG urllib3.connectionpool:452 http://localhost:None "POST /v2/snaps/ubuntu-desktop-installer HTTP/1.1" 409 259
2024-03-17 13:38:51,785 ERROR root:30 finish: subiquity/Refresh/POST/start_update: FAIL: 409 Client Error: Conflict for url: http+unix://%2Frun%2Fsnapd.socket/v2/snaps/ubuntu-desktop-installer

[Olivier Gayot (ogayot)]

This is easy to reproduce by double clicking on the refresh button instead of single clicking.

[Dennis Loose (dloose)]

Thanks for investigating this Olivier!
Should be fixed by: https://github.com/canonical/ubuntu-desktop-provision/pull/659