subiquity does not detect snap refresh failure

[Frank Heimes]

While working on LP 1855127 I came across the situation that the current installer start I started (19.11.1) detected at some point in time that a newer version exists (19.12.1), and it triggered the download and (according to the UI) the download was successful (download started, took some time and ended in a reasonable amount of time), but subiquity failed to automatically restarted afterwards (like it should be, as indicated by the UI text: "The installer will restart automatically when the download is complete").
The only way to proceed was by selecting "Continue without updating".

Please see the screenshots and output in the attached file for more details.

For logs please see:
https://bugs.launchpad.net/ubuntu-z-systems/+bug/1855127/comments/8

[Michael Hudson-Doyle (mwhudson)]

Hmm. From the logs

Dec 10 14:17:47 ubuntu-server snapd[1549]: store.go:1365: Cannot download or apply deltas for subiquity: Get https://fastly.cdn.snapcraft.io/download-origin/fastly/ba2aj8guta0zSRlT3QM5aJNAUXPlBtf9_1333_1359_xdelta3.delta?token=1576000800_e13c05043adfe3133b63790f24400d86caeef3d4: dial tcp 199.232.58.217:443: i/o timeout

This smells like a few things going wrong: snapd should be doing autodetection of whether the CDN works and subiquity presumably should be getting some indication that the update has failed and reporting that to the user. Hmm, looks like subiquity does not actually check for failure here :(

[Frank Heimes (fheimes)]

Yeah, that actually makes total sense, since the snap store is NOT reachable from our Z box without a proxy!

What confused me is that the 'waiting until timeout' (I guess) looked in the UI just like a download - and the UI didn't mentioned an error or timeout at the end - and the elapsed time looked reasonable, too.

Will tomorrow do another installation with proxy enabled and see if it works then.

Anyway, the user feedback could be at least a bit improved (handing over the timeout to the UI).

[Dimitri John Ledkov (xnox)]

So snaps connectivity check is meant to catch that, but doesn't.

I thought I reported that before but couldn't reproduce right. Let's see if
we can convince them the check is wrong.

Which network is this from? The hwe z vlan, right?

On Tue, 10 Dec 2019, 20:10 Michael Hudson-Doyle, <email address hidden>
wrote:

> Hmm. From the logs
>
> Dec 10 14:17:47 ubuntu-server snapd[1549]: store.go:1365: Cannot
> download or apply deltas for subiquity: Get
> https://fastly.cdn.snapcraft.io/download-
>
> origin/fastly/ba2aj8guta0zSRlT3QM5aJNAUXPlBtf9_1333_1359_xdelta3.delta?token=1576000800_e13c05043adfe3133b63790f24400d86caeef3d4:
> dial tcp 199.232.58.217:443: i/o timeout
>
> This smells like a few things going wrong: snapd should be doing
> autodetection of whether the CDN works and subiquity presumably should
> be getting some indication that the update has failed and reporting that
> to the user. Hmm, looks like subiquity does not actually check for
> failure here :(
>
> ** Summary changed:
>
> - subiquity detected and downloaded new version but didn't restart
> + subiquity does not detect refresh failure
>
> ** Summary changed:
>
> - subiquity does not detect refresh failure
> + subiquity does not detect snap refresh failure
>
> ** Changed in: subiquity
> Status: New => Triaged
>
> ** Changed in: subiquity
> Importance: Undecided => High
>
> --
> You received this bug notification because you are a member of Canonical
> Foundations Team, which is a bug assignee.
> https://bugs.launchpad.net/bugs/1855921
>
> Title:
> subiquity does not detect snap refresh failure
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/subiquity/+bug/1855921/+subscriptions
>

[Frank Heimes (fheimes)]

I did a new installation and specified a proxy this time (needed to reach the snapstore for updating snaps, especially here the subiquity snap) and that step looked good now:

================================================================================
  Installer update available [ Help ]
================================================================================
  Version 19.12.1 of the installer is now available (19.11.1 is currently
  running).

  You can read the release notes for each version at:

               https://github.com/CanonicalLtd/subiquity/releases

  If you choose to update, the update will be downloaded and the installation
  will continue from here.

                        [ Update to the new installer ]
                        [ Continue without updating ]
                        [ Back ]

================================================================================
  Downloading update... [ Help ]
================================================================================
  Please wait while the updated installer is being downloaded. The installer
  will restart automatically when the download is complete.

   Consider re-refresh of "subiquity" /
   Stop snap "subiquity" services \

                               [ Cancel update ]

# Here, a final msg about the successful update got displayed for a moment, but I wan't quick enough to capture the screen.

This particular installation failed (due to a different reason, probably LP 1855127) and now, with the updated installer, I got a different screen:

================================================================================
  An error occurred during installation [ Help ]
================================================================================

   ┌────────────────────────────────────────────────────────────────────────┐
   │ │
   │ Sorry, there was a problem completing the installation. │
   │ │
   │ [ View full report ] │
   │ │
   │ If you want to help improve the installer, you can send an error │
   │ report. │
   │ │
   │ [ Send to Canonical ] │
   │ │
   │ Do you want to try starting the installation again? │
   │ │
   │ [ Restart the installer ] │
   │ │
   │ ...

[Michael Hudson-Doyle (mwhudson)]

This should be fixed in edge but it would be good to find some way to test that statement...

[Frank Heimes (fheimes)]

I started an installation with subiquity 19.12.2+git42.f925c3fa and did the following two things:
1)
Did not specified a proxy (hence the system is in this particular configuration and environment not able to reach the snap store) and the installer went beyond the upgrade step w/o any problems (no crash, not error).
2)
I specified a proxy and I again didn't saw any problems - but there is no never versions available.
Hence assuming the check for a new version was just cleanly done in the background.

So it looks pretty much that this is now solved in the edge version (19.12.2+git42.f925c3fa).
Hence setting status to Fix Released.