I’m trying to refresh my snaps while away from home. This is though a 4G mifi router so the latency is a little bit high. fast.com says it’s about 1.3 Mbps, which is bearable. I’ve noticed sometimes it drops packets when trying to update ubuntu packages. However, this snapd behaviour is unexpected, to me at least:
:) bduncan@w7700:~$ sudo snap refresh
error: cannot perform the following tasks:
- Fetch and check assertions for snap "firefox" (3836) (Get "https://api.snapcraft.io/v2/assertions/snap-revision/sCbBKAugF0jqvCREZXuqyoMjmDVyoQakE9xbSJwRJ3RCQ1uTANalKk2WApexdVlG?max-format=0": context deadline exceeded)
:( 1 bduncan@w7700:~$ sudo snap refresh
error: cannot perform the following tasks:
- Fetch and check assertions for snap "firefox" (3836) (Get "https://api.snapcraft.io/v2/assertions/snap-revision/sCbBKAugF0jqvCREZXuqyoMjmDVyoQakE9xbSJwRJ3RCQ1uTANalKk2WApexdVlG?max-format=0": net/http: request canceled (Client.Timeout exceeded while awaiting headers))
Notice that snap is downloading the entire snap, which must be about 80MB each time. This takes a long time. Then, something times out and it gives up. OK, that’s not so bad. But then I try again and it downloads the entire snap all over again!
Maybe I’m missing something here, but should snapd not at least download the snap in the background, so that I can continue using firefox until it’s ready to upgrade? Or if the upgrade fails, cache the downloaded snap for the next time? Sitting watching progress bars, even if they are pretty, is not a good use of my time.
There is indeed an issue with keeping the partial downloads, which I’ll look into.
However, the output suggest that the problem is with downloading snap assertions, which are small text documents with metadata concerning the snap, and are usually at most few kB long. This code runs after the snap data has been downloaded or reconstructed from deltas and cached. Requests are retried a couple of times before finally giving up. If you run snap refresh firefox again it should reuse the snap file that’s there in the system.
If you want to look into this a little more, you can run snap changes find the ID of the change which relates to the firefox installation you run the second time, then run snap debug timings <ID> and paste the output.
Thanks, that would be great. Yes the network problem seems to be related to assertions (this modem does weird things, I think its DNS cache sometimes stops responding until the client reconnects) but I can’t see a good reason for snapd to throw away a successfully downloaded snap (unless it fails a checksum or signature or whatever). Fixing that would be great!
:) bduncan@w7700:~$ snap debug timings 780
ID Status Doing Undoing Summary
9238 Hold - - Mount snap "firefox" (3836)
9239 Hold - - Run pre-refresh hook of "firefox" snap if present
9240 Hold - - Stop snap "firefox" services
9241 Hold - - Remove aliases for snap "firefox"
9242 Hold - - Make current revision for snap "firefox" unavailable
9243 Hold - - Copy snap "firefox" data
9244 Hold - - Setup snap "firefox" (3836) security profiles
9245 Hold - - Make snap "firefox" (3836) available to the system
9246 Hold - - Automatically connect eligible plugs and slots of snap "firefox"
9247 Hold - - Set automatic aliases for snap "firefox"
9248 Hold - - Setup snap "firefox" aliases
9249 Hold - - Run post-refresh hook of "firefox" snap if present
9250 Hold - - Start snap "firefox" (3836) services
9251 Hold - - Remove data for snap "firefox" (3728)
9252 Hold - - Remove snap "firefox" (3728) from the system
9253 Hold - - Clean up "firefox" (3836) install
9254 Hold - - Run configure hook of "firefox" snap if present
9255 Hold - - Run health check of "firefox" snap
9237 Error 40946ms - Fetch and check assertions for snap "firefox" (3836)
9236 Undone 305125ms 6ms Download snap "firefox" (3836) from channel "latest/stable"
^ 305111ms - download snap "firefox"
9235 Done 23ms - Ensure prerequisites for "firefox" are available
9256 Done 6547ms - Monitoring snap "firefox" to determine whether extra refresh steps are required
:) bduncan@w7700:~$ snap debug timings 781
ID Status Doing Undoing Summary
9260 Hold - - Mount snap "firefox" (3836)
9261 Hold - - Run pre-refresh hook of "firefox" snap if present
9262 Hold - - Stop snap "firefox" services
9263 Hold - - Remove aliases for snap "firefox"
9264 Hold - - Make current revision for snap "firefox" unavailable
9265 Hold - - Copy snap "firefox" data
9266 Hold - - Setup snap "firefox" (3836) security profiles
9267 Hold - - Make snap "firefox" (3836) available to the system
9268 Hold - - Automatically connect eligible plugs and slots of snap "firefox"
9269 Hold - - Set automatic aliases for snap "firefox"
9270 Hold - - Setup snap "firefox" aliases
9271 Hold - - Run post-refresh hook of "firefox" snap if present
9272 Hold - - Start snap "firefox" (3836) services
9273 Hold - - Remove data for snap "firefox" (3728)
9274 Hold - - Remove snap "firefox" (3728) from the system
9275 Hold - - Clean up "firefox" (3836) install
9276 Hold - - Run configure hook of "firefox" snap if present
9277 Hold - - Run health check of "firefox" snap
9259 Error 41030ms - Fetch and check assertions for snap "firefox" (3836)
9258 Undone 289183ms 9ms Download snap "firefox" (3836) from channel "latest/stable"
^ 289164ms - download snap "firefox"
9257 Done 28ms - Ensure prerequisites for "firefox" are available
9278 Done 6806ms - Monitoring snap "firefox" to determine whether extra refresh steps are required
:) bduncan@w7700:~$ snap debug timings 782
ID Status Doing Undoing Summary
9279 Done 20ms - Ensure prerequisites for "firefox" are available
9280 Done 356783ms - Download snap "firefox" (3836) from channel "latest/stable"
^ 356764ms - download snap "firefox"
9281 Done 1673ms - Fetch and check assertions for snap "firefox" (3836)
9282 Done 872ms - Mount snap "firefox" (3836)
^ 36ms - check snap "firefox"
^ 803ms - setup snap "firefox"
9283 Done 10ms - Run pre-refresh hook of "firefox" snap if present
9284 Done 9ms - Stop snap "firefox" services
9285 Done 17ms - Remove aliases for snap "firefox"
9286 Done 135ms - Make current revision for snap "firefox" unavailable
9287 Done 51ms - Copy snap "firefox" data
9288 Done 1415ms - Setup snap "firefox" (3836) security profiles
^ 253ms - setup security backend "mount" for snap "firefox"
^ 1125ms - setup security backend "apparmor" for 4 snaps
^ 1034ms - load changed security profiles of 4 snaps
9289 Done 124ms - Make snap "firefox" (3836) available to the system
^ 10ms - generate wrappers for snap firefox
^ 85ms - update font config caches
9290 Done 24ms - Automatically connect eligible plugs and slots of snap "firefox"
9291 Done 25ms - Set automatic aliases for snap "firefox"
9292 Done 15ms - Setup snap "firefox" aliases
9293 Done 178ms - Run post-refresh hook of "firefox" snap if present
9294 Done 23ms - Start snap "firefox" (3836) services
9295 Done 13ms - Remove data for snap "firefox" (3728)
9296 Done 820ms - Remove snap "firefox" (3728) from the system
9297 Done 0ms - Clean up "firefox" (3836) install
9298 Done 2725ms - Run configure hook of "firefox" snap if present
9299 Done 11ms - Run health check of "firefox" snap
9300 Done 20419ms - Monitoring snap "firefox" to determine whether extra refresh steps are required
