core snap stuck refreshing

[Reuben Swartz]

All of our snaps stopped working overnight, attempting to run the snap gives the following error:

cannot locate base snap core: No such file or directory

Running snap changes shows that 12 hours ago an auto-refresh started for the core snap that is still in progress which seems like a really long time.

output of "snap changes":

ID Status Spawn Ready Summary
1 Done yesterday at 10:16 EDT yesterday at 10:16 EDT Initialize system state
2 Done yesterday at 10:17 EDT yesterday at 10:17 EDT Install "ftptransfer" snap from file "ftptransfer_1.0_amd64.snap"
3 Done yesterday at 10:17 EDT yesterday at 10:17 EDT Initialize device
4 Doing yesterday at 19:52 EDT - Auto-refresh snap "core"

Running "snap tasks --last=auto-refresh" gives the following output:
Status Spawn Ready Summary
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Ensure prerequisites for "core" are available
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Download snap "core" (7713) from channel "stable"
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Fetch and check assertions for snap "core" (7713)
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Mount snap "core" (7713)
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Run pre-refresh hook of "core" snap if present
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Stop snap "core" services
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Remove aliases for snap "core"
Done yesterday at 19:52 EDT yesterday at 19:52 EDT Make current revision for snap "core" unavailable
Doing yesterday at 19:52 EDT - Copy snap "core" data
Do yesterday at 19:52 EDT - Setup snap "core" (7713) security profiles
Do yesterday at 19:52 EDT - Make snap "core" (7713) available to the system
Do yesterday at 19:52 EDT - Automatically connect eligible plugs and slots of snap "core"
Do yesterday at 19:52 EDT - Set automatic aliases for snap "core"
Do yesterday at 19:52 EDT - Setup snap "core" aliases
Do yesterday at 19:52 EDT - Run post-refresh hook of "core" snap if present
Do yesterday at 19:52 EDT - Start snap "core" (7713) services
Do yesterday at 19:52 EDT - Clean up "core" (7713) install
Do yesterday at 19:52 EDT - Run configure hook of "core" snap if present
Doing yesterday at 19:52 EDT - Consider re-refresh of "core"

I'm not low on space on the hard disk I have roughly 110GB free

This is a virtual machine running on hyperv

Here is the output from snap --version

snap 2.40
snapd 2.40
series 16
ubuntu 16.04
kernel 4.4.0-157-generic

[Zygmunt Krynicki (zyga)]

Dear reporter. Can you add the output of "snap list" to see if any of the snaps report as broken?

[John Lenton (chipaca)]

What happens if you 'snap abort 4'?

[Reuben Swartz (rbn-swartz)]

Here is the output

Name Version Rev Tracking Publisher Notes
core 16-2.40 7396 stable canonical✓ core,disabled
ftptransfer 1.0 x1 - - devmode

As to why the core snap is disabled I have no idea, I assume it has
something to do with it updating the core snap

On Wed, Sep 11, 2019 at 10:00 AM Zygmunt Krynicki <
<email address hidden>> wrote:

> Dear reporter. Can you add the output of "snap list" to see if any of
> the snaps report as broken?
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1843589
>
> Title:
> core snap stuck refreshing
>
> Status in Snappy:
> New
>
> Bug description:
> All of our snaps stopped working overnight, attempting to run the snap
> gives the following error:
>
> cannot locate base snap core: No such file or directory
>
> Running snap changes shows that 12 hours ago an auto-refresh started
> for the core snap that is still in progress which seems like a really
> long time.
>
> output of "snap changes":
>
> ID Status Spawn Ready Summary
> 1 Done yesterday at 10:16 EDT yesterday at 10:16 EDT Initialize
> system state
> 2 Done yesterday at 10:17 EDT yesterday at 10:17 EDT Install
> "ftptransfer" snap from file "ftptransfer_1.0_amd64.snap"
> 3 Done yesterday at 10:17 EDT yesterday at 10:17 EDT Initialize
> device
> 4 Doing yesterday at 19:52 EDT -
> Auto-refresh snap "core"
>
> Running "snap tasks --last=auto-refresh" gives the following output:
> Status Spawn Ready Summary
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Ensure
> prerequisites for "core" are available
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Download snap
> "core" (7713) from channel "stable"
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Fetch and check
> assertions for snap "core" (7713)
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Mount snap
> "core" (7713)
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Run pre-refresh
> hook of "core" snap if present
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Stop snap "core"
> services
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Remove aliases
> for snap "core"
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Make current
> revision for snap "core" unavailable
> Doing yesterday at 19:52 EDT - Copy snap "core"
> data
> Do yesterday at 19:52 EDT - Setup snap
> "core" (7713) security profiles
> Do yesterday at 19:52 EDT - Make snap "core"
> (7713) available to the system
> Do yesterday at 19:52 EDT - Automatically
> connect eligible plugs and slots of snap "core"
> Do yesterday at 19:52 EDT - Set automatic
> aliases for snap "core"
> Do yesterday at 19:52 EDT - Setup snap
> "core" aliases
> Do yesterday at 19:52 EDT - Run post-r...

[Reuben Swartz (rbn-swartz)]

aborting it stops the process but running the snap still gives the same
error

cannot locate base snap core: No such file or directory

And trying to enable the snap via sudo snap enable core gives the following
output

error: snap "core" has "auto-refresh" change in progress

It looks like the abort might not have finished because it is still listed
as not read in snap tasks

Status Spawn Ready Summary
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Ensure
prerequisites for "core" are available
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Download snap
"core" (7713) from channel "stable"
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Fetch and check
assertions for snap "core" (7713)
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Mount snap "core"
(7713)
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Run pre-refresh
hook of "core" snap if present
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Stop snap "core"
services
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Remove aliases for
snap "core"
Undo yesterday at 19:52 EDT yesterday at 19:52 EDT Make current
revision for snap "core" unavailable
Abort yesterday at 19:52 EDT - Copy snap "core"
data
Hold yesterday at 19:52 EDT today at 10:13 EDT Setup snap "core"
(7713) security profiles
Hold yesterday at 19:52 EDT today at 10:13 EDT Make snap "core"
(7713) available to the system
Hold yesterday at 19:52 EDT today at 10:13 EDT Automatically
connect eligible plugs and slots of snap "core"
Hold yesterday at 19:52 EDT today at 10:13 EDT Set automatic
aliases for snap "core"
Hold yesterday at 19:52 EDT today at 10:13 EDT Setup snap "core"
aliases
Hold yesterday at 19:52 EDT today at 10:13 EDT Run post-refresh
hook of "core" snap if present
Hold yesterday at 19:52 EDT today at 10:13 EDT Start snap "core"
(7713) services
Hold yesterday at 19:52 EDT today at 10:13 EDT Clean up "core"
(7713) install
Hold yesterday at 19:52 EDT today at 10:13 EDT Run configure hook
of "core" snap if present
Hold yesterday at 19:52 EDT today at 10:13 EDT Consider re-refresh
of "core"

On Wed, Sep 11, 2019 at 10:10 AM John Lenton <email address hidden>
wrote:

> What happens if you 'snap abort 4'?
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1843589
>
> Title:
> core snap stuck refreshing
>
> Status in Snappy:
> New
>
> Bug description:
> All of our snaps stopped working overnight, attempting to run the snap
> gives the following error:
>
> cannot locate base snap core: No such file or directory
>
> Running snap changes shows that 12 hours ago an auto-refresh started
> for the core snap that is still in progress which seems like a really
> long time.
>
> output of "snap changes":
>
> ID Status Spawn Ready Summary
> 1 Done yesterday at 10:16 EDT yesterday at 10:16 EDT Initialize
> system state
> 2 Done yesterday at 10:17 EDT yesterday at 10:17 EDT...

[Zygmunt Krynicki (zyga)]

Can you please check if there are any additional changes present after you had issues the "snap abort 4" command? I wonder if it is that abort has not completed or that another refresh has just happened that is causing this.

[Reuben Swartz (rbn-swartz)]

I'm assuming snap changes would give you that information? Here is the
output of that command

ID Status Spawn Ready Summary
4 Abort yesterday at 19:52 EDT - Auto-refresh snap "core"

On Wed, Sep 11, 2019 at 12:21 PM Zygmunt Krynicki <
<email address hidden>> wrote:

> ** Changed in: snappy
> Status: New => Triaged
>
> ** Changed in: snappy
> Importance: Undecided => High
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1843589
>
> Title:
> core snap stuck refreshing
>
> Status in Snappy:
> Triaged
>
> Bug description:
> All of our snaps stopped working overnight, attempting to run the snap
> gives the following error:
>
> cannot locate base snap core: No such file or directory
>
> Running snap changes shows that 12 hours ago an auto-refresh started
> for the core snap that is still in progress which seems like a really
> long time.
>
> output of "snap changes":
>
> ID Status Spawn Ready Summary
> 1 Done yesterday at 10:16 EDT yesterday at 10:16 EDT Initialize
> system state
> 2 Done yesterday at 10:17 EDT yesterday at 10:17 EDT Install
> "ftptransfer" snap from file "ftptransfer_1.0_amd64.snap"
> 3 Done yesterday at 10:17 EDT yesterday at 10:17 EDT Initialize
> device
> 4 Doing yesterday at 19:52 EDT -
> Auto-refresh snap "core"
>
> Running "snap tasks --last=auto-refresh" gives the following output:
> Status Spawn Ready Summary
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Ensure
> prerequisites for "core" are available
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Download snap
> "core" (7713) from channel "stable"
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Fetch and check
> assertions for snap "core" (7713)
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Mount snap
> "core" (7713)
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Run pre-refresh
> hook of "core" snap if present
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Stop snap "core"
> services
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Remove aliases
> for snap "core"
> Done yesterday at 19:52 EDT yesterday at 19:52 EDT Make current
> revision for snap "core" unavailable
> Doing yesterday at 19:52 EDT - Copy snap "core"
> data
> Do yesterday at 19:52 EDT - Setup snap
> "core" (7713) security profiles
> Do yesterday at 19:52 EDT - Make snap "core"
> (7713) available to the system
> Do yesterday at 19:52 EDT - Automatically
> connect eligible plugs and slots of snap "core"
> Do yesterday at 19:52 EDT - Set automatic
> aliases for snap "core"
> Do yesterday at 19:52 EDT - Setup snap
> "core" aliases
> Do yesterday at 19:52 EDT - Run post-refresh
> hook of "core" snap if present
> Do yesterday at 19:52 EDT - ...

[Trent Lloyd (lathiat)]

Hit the same issue during an LXD auto-refresh:
https://bugs.launchpad.net/snappy/+bug/1943419