404 error when refreshing/installing snaps

jenny.murphy · April 8, 2021, 9:29am

Hello,
I have a Ubuntu Core Installation as follows:

snap --version
snap 2.49.2
snapd 2.49.2
series 16
kernel 4.4.0-151-generic

On issuing a snap refresh of all snaps, I get errors regarding the update of some of the snaps.
I tried to refresh one of them manually:

snap refresh modem-manager
Download snap “modem-manager” (426) from channel “latest/stable” (received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap)

Any suggestions as to what could be the problem?

ijohnson · April 9, 2021, 7:37pm

Can you include output from snap changes and snap tasks <chg> for any tasks that are in error ?

jenny.murphy · April 12, 2021, 8:44am

Hi,
Thanks for responding. Here is the output you are interested in:

admin@caracalla:~$ snap refresh modem-manager
error: cannot perform the following tasks:

Download snap “modem-manager” (426) from channel “latest/stable” (received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap)
admin@caracalla:~$ snap changes
ID Status Spawn Ready Summary
44 Error 3 days ago, at 14:59 UTC 3 days ago, at 14:59 UTC Initialize device
45 Error today at 08:27 UTC today at 08:27 UTC Initialize device
46 Error today at 08:36 UTC today at 08:36 UTC Refresh “modem-manager” snap
47 Error today at 08:37 UTC today at 08:38 UTC Refresh snaps “modem-manager”, “uefi-fw-tools”, “network-manager”, “wpa-supplicant”, “caracalla-kernel”, “caracalla”, “wifi-ap”, “bluez”
48 Error today at 08:37 UTC today at 08:37 UTC Initialize device
49 Error today at 08:41 UTC today at 08:41 UTC Refresh “modem-manager” snap

admin@caracalla:~$ snap tasks 46
Status Spawn Ready Summary
Done today at 08:36 UTC today at 08:36 UTC Ensure prerequisites for “modem-manager” are available
Error today at 08:36 UTC today at 08:36 UTC Download snap “modem-manager” (426) from channel “latest/stable”
Hold today at 08:36 UTC today at 08:36 UTC Fetch and check assertions for snap “modem-manager” (426)
Hold today at 08:36 UTC today at 08:36 UTC Mount snap “modem-manager” (426)
Hold today at 08:36 UTC today at 08:36 UTC Run pre-refresh hook of “modem-manager” snap if present
Hold today at 08:36 UTC today at 08:36 UTC Stop snap “modem-manager” services
Hold today at 08:36 UTC today at 08:36 UTC Remove aliases for snap “modem-manager”
Hold today at 08:36 UTC today at 08:36 UTC Make current revision for snap “modem-manager” unavailable
Hold today at 08:36 UTC today at 08:36 UTC Copy snap “modem-manager” data
Hold today at 08:36 UTC today at 08:36 UTC Setup snap “modem-manager” (426) security profiles
Hold today at 08:36 UTC today at 08:36 UTC Make snap “modem-manager” (426) available to the system
Hold today at 08:36 UTC today at 08:36 UTC Automatically connect eligible plugs and slots of snap “modem-manager”
Hold today at 08:36 UTC today at 08:36 UTC Set automatic aliases for snap “modem-manager”
Hold today at 08:36 UTC today at 08:36 UTC Setup snap “modem-manager” aliases
Hold today at 08:36 UTC today at 08:36 UTC Run post-refresh hook of “modem-manager” snap if present
Hold today at 08:36 UTC today at 08:36 UTC Start snap “modem-manager” (426) services
Hold today at 08:36 UTC today at 08:36 UTC Clean up “modem-manager” (426) install
Hold today at 08:36 UTC today at 08:36 UTC Run configure hook of “modem-manager” snap if present
Hold today at 08:36 UTC today at 08:36 UTC Run health check of “modem-manager” snap
Done today at 08:36 UTC today at 08:36 UTC Consider re-refresh of “modem-manager”

…
Download snap “modem-manager” (426) from channel “latest/stable”

2021-04-12T08:36:54Z ERROR received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap

ijohnson · April 12, 2021, 5:03pm

Can you enable verbose HTTP debug logs (and also scrub your macaroon out from these logs) by doing the following:

enable HTTP debug logging for snapd by adding the following to /etc/environment:

SNAPD_DEBUG=1
SNAPD_DEBUG_HTTP=7

restart snapd with sudo systemctl restart snapd
re-try the refresh
if it still fails, get logs with a command like this that removes the Macaroon-Root header from the logs:

$ journalctl --no-pager -u snapd | sed -e 's@Macaroon root=\\\".*\\\"@MACAROON-SCRUBBED@'

jenny.murphy · April 13, 2021, 9:36am

We followed the next steps, the refresh failed again and here is the output from journlctl:

root@caracalla:~# journalctl --no-pager -u snapd | sed -e ‘s@Macaroon root=\".*\"@MACAROON-SCRUBBED@’
– Logs begin at Mon 2021-04-12 15:22:45 UTC, end at Tue 2021-04-13 09:03:22 UTC. –
Apr 12 16:20:20 caracalla systemd[1]: Starting Snap Daemon…
Apr 12 16:20:25 caracalla snapd[2124]: AppArmor status: apparmor is enabled and all features are available
Apr 12 16:20:26 caracalla snapd[2124]: daemon.go:347: started snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic.
Apr 12 16:20:26 caracalla snapd[2124]: daemon.go:440: adjusting startup timeout by 1m45s (pessimistic estimate of 30s plus 5s per snap)
Apr 12 16:20:27 caracalla systemd[1]: Started Snap Daemon.
Apr 12 16:20:44 caracalla snapd[2124]: taskrunner.go:271: [change 55 “Run prepare-device hook” task] failed: run hook “prepare-device”: + exec
Apr 12 16:20:45 caracalla snapd[2124]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Apr 12 16:20:45 caracalla snapd[2124]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Apr 12 16:20:45 caracalla snapd[2124]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Apr 13 08:10:34 caracalla snapd[2124]: taskrunner.go:271: [change 56 “Run prepare-device hook” task] failed: run hook “prepare-device”: + exec
Apr 13 08:25:11 caracalla snapd[2124]: taskrunner.go:271: [change 57 “Run prepare-device hook” task] failed: run hook “prepare-device”: + exec
Apr 13 08:25:12 caracalla snapd[2124]: storehelpers.go:551: cannot refresh: snap has no updates available: “alsa-utils”, “core”, “locationd”, “tpm2”, “udisks2”
Apr 13 08:25:15 caracalla snapd[2124]: store_download.go:169: Cannot download or apply deltas for network-manager: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/RmBXKl6HO6YOC2DE4G2q1JzWImC04EUy_379_615_xdelta3.delta
Apr 13 08:25:17 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “uefi-fw-tools” (22) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/Oulq6jI8qkI4ScWVafl3VsxSsd52HSGu_22.snap
Apr 13 08:25:17 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “caracalla-kernel” (152) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/TlJNTzTp0kFRfD3XFCoa4fDIVYDjwMXm_152.snap
Apr 13 08:25:17 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “network-manager” (615) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/RmBXKl6HO6YOC2DE4G2q1JzWImC04EUy_615.snap
Apr 13 08:25:18 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “wpa-supplicant” (53) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/e2hgfjRsvBzotgj7uszUv2ayQS3azzdc_53.snap
Apr 13 08:25:18 caracalla snapd[2124]: store_download.go:169: Cannot download or apply deltas for caracalla: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j_52_53_xdelta3.delta
Apr 13 08:25:20 caracalla snapd[2124]: store_download.go:169: Cannot download or apply deltas for modem-manager: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_232_426_xdelta3.delta
Apr 13 08:25:20 caracalla snapd[2124]: store_download.go:169: Cannot download or apply deltas for bluez: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/JmzJi9kQvHUWddZ32PDJpBRXUpGRxvNS_166_266_xdelta3.delta
Apr 13 08:25:20 caracalla snapd[2124]: store_download.go:169: Cannot download or apply deltas for wifi-ap: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/2rGgvyaY0CCzlWuKAPwFtCWrgwkM8lqS_303_355_xdelta3.delta
Apr 13 08:25:20 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “caracalla” (53) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j_53.snap
Apr 13 08:25:21 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “bluez” (266) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/JmzJi9kQvHUWddZ32PDJpBRXUpGRxvNS_266.snap
Apr 13 08:25:21 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “modem-manager” (426) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap
Apr 13 08:25:22 caracalla snapd[2124]: taskrunner.go:271: [change 58 “Download snap “wifi-ap” (355) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/2rGgvyaY0CCzlWuKAPwFtCWrgwkM8lqS_355.snap
Apr 13 08:45:11 caracalla snapd[2124]: taskrunner.go:271: [change 59 “Run prepare-device hook” task] failed: run hook “prepare-device”: + exec
Apr 13 09:02:32 caracalla systemd[1]: Stopping Snap Daemon…
Apr 13 09:02:32 caracalla snapd[2124]: main.go:155: Exiting on terminated signal.
Apr 13 09:02:32 caracalla systemd[1]: Stopped Snap Daemon.
Apr 13 09:02:32 caracalla systemd[1]: Starting Snap Daemon…
Apr 13 09:02:32 caracalla snapd[2601]: AppArmor status: apparmor is enabled and all features are available
Apr 13 09:02:33 caracalla snapd[2601]: daemon.go:347: started snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic.
Apr 13 09:02:33 caracalla snapd[2601]: daemon.go:440: adjusting startup timeout by 1m45s (pessimistic estimate of 30s plus 5s per snap)
Apr 13 09:02:33 caracalla snapd[2601]: standby.go:96: DEBUG: will consider standby after: 5s
Apr 13 09:02:33 caracalla snapd[2601]: main.go:88: DEBUG: Setting up sd_notify() watchdog timer every 2m30s
Apr 13 09:02:33 caracalla snapd[2601]: main.go:149: DEBUG: activation done in 1.015s
Apr 13 09:02:33 caracalla systemd[1]: Started Snap Daemon.
Apr 13 09:02:33 caracalla snapd[2601]: catalogrefresh.go:113: DEBUG: Catalog refresh starting now; next scheduled for 2021-04-14 09:02:33.91925985 +0000 UTC m=+86401.077408882.
Apr 13 09:02:33 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/sections, attempt 1, elapsed time=14.738µs
Apr 13 09:02:33 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:33 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/sections HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: application/hal+json\r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:34 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 200 OK\r\nContent-Length: 558\r\nAge: 3266\r\nCache-Control: public, max-age=3600\r\nContent-Type: application/hal+json\r\nDate: Tue, 13 Apr 2021 08:08:08 GMT\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nVary: X-Ubuntu-Series\r\nVia: 1.1 juju-f25c99-prod-ols-snap-store-774 (squid/3.5.27)\r\nX-Cache: HIT from juju-f25c99-prod-ols-snap-store-774\r\nX-Cache-Lookup: HIT from juju-f25c99-prod-ols-snap-store-774:3128\r\nX-Request-Id: 9F085E7492AA0A325D7301BB607551672DB9BD3\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_search.section_listing\r\n\r\n{”_embedded": {“clickindex:sections”: [{“name”: “art-and-design”}, {“name”: “books-and-reference”}, {“name”: “development”}, {“name”: “devices-and-iot”}, {“name”: “education”}, {“name”: “entertainment”}, {“name”: “featured”}, {“name”: “finance”}, {“name”: “games”}, {“name”: “health-and-fitness”}, {“name”: “music-and-audio”}, {“name”: “news-and-weather”}, {“name”: “personalisation”}, {“name”: “photo-and-video”}, {“name”: “productivity”}, {“name”: “science”}, {“name”: “security”}, {“name”: “server-and-cloud”}, {“name”: “social”}, {“name”: “utilities”}]}}"
Apr 13 09:02:34 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/api/v1/snaps/sections finished after 1 retries, elapsed time=685.684265ms, status: 200
Apr 13 09:02:34 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/names?confinement=strict, attempt 1, elapsed time=14.955µs
Apr 13 09:02:34 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:34 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/names?confinement=strict HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: application/hal+json\r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:35 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.0 429 Too Many Requests\r\nCache-Control: no-cache\r\nConnection: close\r\nContent-Type: text/html\r\n\r\n”
Apr 13 09:02:35 caracalla snapd[2601]: retry.go:184: DEBUG: Not retrying: &errors.errorString{s:“too many requests”}
Apr 13 09:02:35 caracalla snapd[2601]: retry.go:112: DEBUG: ShouldRetryError: too many requests *errors.errorString -> false
Apr 13 09:02:35 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/api/v1/snaps/names?confinement=strict finished after 1 retries, elapsed time=511.903621ms, status: too many requests
Apr 13 09:02:35 caracalla snapd[2601]: catalogrefresh.go:120: DEBUG: Catalog refresh postponed.
Apr 13 09:02:35 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1496 on Do: Run prepare-device hook
Apr 13 09:02:36 caracalla snapd[2601]: task.go:337: DEBUG: 2021-04-13T09:02:36Z ERROR run hook “prepare-device”:
Apr 13 09:02:36 caracalla snapd[2601]: -----
Apr 13 09:02:36 caracalla snapd[2601]: cmd_run.go:407: DEBUG: SELinux not enabled
Apr 13 09:02:36 caracalla snapd[2601]: tracking.go:44: DEBUG: creating transient scope snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: tracking.go:305: DEBUG: created transient scope as object: /org/freedesktop/systemd1/job/2232
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: umask reset, old umask was 022
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: security tag: snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: executable: /usr/lib/snapd/snap-exec
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: confinement: non-classic
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: base snap: core
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: ruid: 0, euid: 0, suid: 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: rgid: 0, egid: 0, sgid: 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: apparmor label on snap-confine is: /usr/lib/snapd/snap-confine
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: apparmor mode is: enforce
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: creating lock directory /run/snapd/lock (if missing)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock directory /run/snapd/lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock file: /run/snapd/lock/.lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: acquiring exclusive lock (scope (global), uid 0)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: ensuring that snap mount directory is shared
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: unsharing snap namespace directory
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: releasing lock 6
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opened snap-update-ns executable as file descriptor 6
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opened snap-discard-ns executable as file descriptor 7
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: creating lock directory /run/snapd/lock (if missing)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock directory /run/snapd/lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock file: /run/snapd/lock/caracalla.lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: acquiring exclusive lock (scope caracalla, uid 0)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: initializing mount namespace: caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: setting up device cgroup
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: no devices tagged with snap_caracalla_hook_prepare-device, skipping device cgroup setup
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: forked support process 2649
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: block device of snap core, revision 10958 is 7:9
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: changing apparmor hat to mount-namespace-capture-helper
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process waiting for command
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: joining preserved mount namespace for inspection
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: preserved mount is not stale, reusing
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: joined preserved mount namespace caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: moved process 2636 to cgroup hierarchy /sys/fs/cgroup/freezer/snap.caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: releasing lock 8
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sending command 0 to helper process (pid: 2649)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: waiting for response from helper
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process received command 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: waiting for the helper process to exit
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process exiting
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process exited normally
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: resetting PATH to values in sync with core snap
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: yes), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: creating user data directory: /root/snap/caracalla/52
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: requesting changing of apparmor profile on next exec to snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: ruid: 0, euid: 0, suid: 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: loading bpf program for security tag snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: read 7024 bytes from /var/lib/snapd/seccomp/bpf//snap.caracalla.hook.prepare-device.bin
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: read 152 bytes from /var/lib/snapd/seccomp/bpf/global.bin
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: execv(/usr/lib/snapd/snap-exec, /usr/lib/snapd/snap-exec…)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: argv[1] = --hook=prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: argv[2] = caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: umask restored to 022
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: working directory restored to /
Apr 13 09:02:36 caracalla snapd[2601]: + exec
Apr 13 09:02:36 caracalla snapd[2601]: -----
Apr 13 09:02:36 caracalla snapd[2601]: taskrunner.go:271: [change 60 “Run prepare-device hook” task] failed: run hook “prepare-device”:
Apr 13 09:02:36 caracalla snapd[2601]: -----
Apr 13 09:02:36 caracalla snapd[2601]: cmd_run.go:407: DEBUG: SELinux not enabled
Apr 13 09:02:36 caracalla snapd[2601]: tracking.go:44: DEBUG: creating transient scope snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: tracking.go:305: DEBUG: created transient scope as object: /org/freedesktop/systemd1/job/2232
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: umask reset, old umask was 022
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: security tag: snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: executable: /usr/lib/snapd/snap-exec
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: confinement: non-classic
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: base snap: core
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: ruid: 0, euid: 0, suid: 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: rgid: 0, egid: 0, sgid: 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: apparmor label on snap-confine is: /usr/lib/snapd/snap-confine
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: apparmor mode is: enforce
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: creating lock directory /run/snapd/lock (if missing)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock directory /run/snapd/lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock file: /run/snapd/lock/.lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: acquiring exclusive lock (scope (global), uid 0)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: ensuring that snap mount directory is shared
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: unsharing snap namespace directory
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: releasing lock 6
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opened snap-update-ns executable as file descriptor 6
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opened snap-discard-ns executable as file descriptor 7
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: creating lock directory /run/snapd/lock (if missing)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock directory /run/snapd/lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: opening lock file: /run/snapd/lock/caracalla.lock
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: acquiring exclusive lock (scope caracalla, uid 0)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: initializing mount namespace: caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: setting up device cgroup
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: no devices tagged with snap_caracalla_hook_prepare-device, skipping device cgroup setup
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: forked support process 2649
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: block device of snap core, revision 10958 is 7:9
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: changing apparmor hat to mount-namespace-capture-helper
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process waiting for command
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: DEBUG: sanity timeout initialized and set for 30 seconds
Apr 13 09:02:36 caracalla snapd[2601]: joining preserved mount namespace for inspection
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: preserved mount is not stale, reusing
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: joined preserved mount namespace caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: moved process 2636 to cgroup hierarchy /sys/fs/cgroup/freezer/snap.caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: releasing lock 8
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sending command 0 to helper process (pid: 2649)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: waiting for response from helper
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: sanity timeout reset and disabled
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process received command 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: waiting for the helper process to exit
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process exiting
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: helper process exited normally
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: resetting PATH to values in sync with core snap
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: set_effective_identity uid:0 (change: yes), gid:0 (change: yes)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: creating user data directory: /root/snap/caracalla/52
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: requesting changing of apparmor profile on next exec to snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: ruid: 0, euid: 0, suid: 0
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: loading bpf program for security tag snap.caracalla.hook.prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: read 7024 bytes from /var/lib/snapd/seccomp/bpf//snap.caracalla.hook.prepare-device.bin
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: read 152 bytes from /var/lib/snapd/seccomp/bpf/global.bin
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: execv(/usr/lib/snapd/snap-exec, /usr/lib/snapd/snap-exec…)
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: argv[1] = --hook=prepare-device
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: argv[2] = caracalla
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: umask restored to 022
Apr 13 09:02:36 caracalla snapd[2601]: DEBUG: working directory restored to /
Apr 13 09:02:36 caracalla snapd[2601]: + exec
Apr 13 09:02:36 caracalla snapd[2601]: -----
Apr 13 09:02:37 caracalla snapd[2601]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Apr 13 09:02:37 caracalla snapd[2601]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Apr 13 09:02:37 caracalla snapd[2601]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Apr 13 09:02:37 caracalla snapd[2601]: hotplug.go:160: DEBUG: ignoring device /dev/bus/usb/001/003 (2404; serial: USB_CAN_FD_Application), interface “serial-port” (handled by gadget slot canbus-adapter)
Apr 13 09:02:37 caracalla snapd[2601]: hotplug.go:160: DEBUG: ignoring device /dev/ttyACM3 (Atom Processor Z36xxx/Z37xxx, Celeron N2000 Series USB xHCI; serial: USB_CAN_FD_Application), interface “serial-port” (handled by gadget slot canbus-adapter)
Apr 13 09:02:37 caracalla snapd[2601]: hotplug.go:160: DEBUG: ignoring device /dev/ttyS4, interface “serial-port” (handled by gadget slot ttys4)
Apr 13 09:02:37 caracalla snapd[2601]: hotplug.go:160: DEBUG: ignoring device /dev/ttyS5, interface “serial-port” (handled by gadget slot ttys5)
Apr 13 09:02:47 caracalla snapd[2601]: daemon.go:317: DEBUG: pid=2658;uid=0;socket=/run/snapd.socket; GET /v2/snaps 356.615088ms 200
Apr 13 09:02:49 caracalla snapd[2601]: store_action.go:441: DEBUG: Deltas enabled. Adding header Snap-Accept-Delta-Format: xdelta3
Apr 13 09:02:49 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/v2/snaps/refresh, attempt 1, elapsed time=17.849µs
Apr 13 09:02:49 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:49 caracalla snapd[2601]: logger.go:67: DEBUG: > “POST /v2/snaps/refresh HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nContent-Length: 2772\r\nAccept: application/json\r\nContent-Type: application/json\r\nSnap-Accept-Delta-Format: xdelta3\r\nSnap-Classic: false\r\nSnap-Device-Architecture: amd64\r\nSnap-Device-Capabilities: default-tracks\r\nSnap-Device-Series: 16\r\nSnap-Device-Store: he9Haizai7thooneiph9\r\nAccept-Encoding: gzip\r\n\r\n{“context”:[],“actions”:[{“action”:“fetch-assertions”,“key”:“CgA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“2rGgvyaY0CCzlWuKAPwFtCWrgwkM8lqS”],“if-newer-than”:5}]},{“action”:“fetch-assertions”,“key”:“DAA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“99T7MUlRhtI3U0QFgl5mXXESAiSwt776”],“if-newer-than”:0}]},{“action”:“fetch-assertions”,“key”:“DQA”,“assertions”:[{“type”:“store”,“primary-key”:[“he9Haizai7thooneiph9”],“if-newer-than”:1}]},{“action”:“fetch-assertions”,“key”:“CQA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“bUB8lXpOC3pItJMaJattT2jhDTyBWClE”],“if-newer-than”:10}]},{“action”:“fetch-assertions”,“key”:“AAA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”],“if-newer-than”:19}]},{“action”:“fetch-assertions”,“key”:“BgA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“e2hgfjRsvBzotgj7uszUv2ayQS3azzdc”],“if-newer-than”:8}]},{“action”:“fetch-assertions”,“key”:“CwA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“RmBXKl6HO6YOC2DE4G2q1JzWImC04EUy”],“if-newer-than”:26}]},{“action”:“fetch-assertions”,“key”:“AQA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“KTyDAsgNZg4u9UBJ63MHn6q12fmUjOfn”],“if-newer-than”:6}]},{“action”:“fetch-assertions”,“key”:“AAABAAIAAwAEAAUABgAHAAgACQAKAAsADAANAA”,“assertions”:[{”
Apr 13 09:02:49 caracalla snapd[2601]: type":“account-key”,“primary-key”:[“BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul”],“if-newer-than”:2}]},{“action”:“fetch-assertions”,“key”:“AwA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“gpXp4JZnUWzybzeOgDEHkHfMUKvCJL7u”],“if-newer-than”:5}]},{“action”:“fetch-assertions”,“key”:“AgA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“xoHNzwxGwQ2D4rSZwI3DKsjtRuy9saeI”],“if-newer-than”:8}]},{“action”:“fetch-assertions”,“key”:“BwA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j”],“if-newer-than”:12}]},{“action”:“fetch-assertions”,“key”:“CAA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“JmzJi9kQvHUWddZ32PDJpBRXUpGRxvNS”],“if-newer-than”:19}]},{“action”:“fetch-assertions”,“key”:“BQA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“TlJNTzTp0kFRfD3XFCoa4fDIVYDjwMXm”],“if-newer-than”:0}]},{“action”:“fetch-assertions”,“key”:“BAA”,“assertions”:[{“type”:“snap-declaration”,“primary-key”:[“16”,“Oulq6jI8qkI4ScWVafl3VsxSsd52HSGu”],“if-newer-than”:11}]}],“fields”:[“architectures”,“base”,“confinement”,“contact”,“created-at”,“description”,“download”,“epoch”,“license”,“name”,“prices”,“private”,“publisher”,“revision”,“snap-id”,“snap-yaml”,“summary”,“title”,“type”,“version”,“website”,“store-url”,“media”,“common-ids”],“assertion-max-formats”:{“snap-declaration”:4,“system-user”:1}}"
Apr 13 09:02:49 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 200 OK\r\nContent-Length: 1100\r\nContent-Type: application/json\r\nDate: Tue, 13 Apr 2021 09:02:49 GMT\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nX-Request-Id: 25E4E02413600A325C3701BB60755E392D8404C\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_refresh.snap_refresh\r\n\r\n{“error-list”:[],“results”:[{“assertion-stream-urls”:[],“key”:“CgA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“DAA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“DQA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“CQA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“AAA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“BgA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“CwA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“AQA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“AAABAAIAAwAEAAUABgAHAAgACQAKAAsADAANAA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“AwA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“AgA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“BwA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“CAA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“BQA”,“result”:“fetch-assertions”},{“assertion-stream-urls”:[],“key”:“BAA”,“result”:“fetch-assertions”}]}\n”
Apr 13 09:02:49 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/v2/snaps/refresh finished after 1 retries, elapsed time=202.224017ms, status: 200
Apr 13 09:02:49 caracalla snapd[2601]: store_action.go:441: DEBUG: Deltas enabled. Adding header Snap-Accept-Delta-Format: xdelta3
Apr 13 09:02:49 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/v2/snaps/refresh, attempt 1, elapsed time=11.347µs
Apr 13 09:02:49 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:49 caracalla snapd[2601]: logger.go:67: DEBUG: > “POST /v2/snaps/refresh HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nContent-Length: 3323\r\nAccept: application/json\r\nContent-Type: application/json\r\nSnap-Accept-Delta-Format: xdelta3\r\nSnap-Classic: false\r\nSnap-Device-Architecture: amd64\r\nSnap-Device-Capabilities: default-tracks\r\nSnap-Device-Series: 16\r\nSnap-Device-Store: he9Haizai7thooneiph9\r\nAccept-Encoding: gzip\r\n\r\n{“context”:[{“snap-id”:“TlJNTzTp0kFRfD3XFCoa4fDIVYDjwMXm”,“instance-key”:“TlJNTzTp0kFRfD3XFCoa4fDIVYDjwMXm”,“revision”:111,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:10Z”},{“snap-id”:“99T7MUlRhtI3U0QFgl5mXXESAiSwt776”,“instance-key”:“99T7MUlRhtI3U0QFgl5mXXESAiSwt776”,“revision”:10958,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2021-04-09T11:28:52.373987324Z”},{“snap-id”:“RmBXKl6HO6YOC2DE4G2q1JzWImC04EUy”,“instance-key”:“RmBXKl6HO6YOC2DE4G2q1JzWImC04EUy”,“revision”:379,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:31Z”},{“snap-id”:“xoHNzwxGwQ2D4rSZwI3DKsjtRuy9saeI”,“instance-key”:“xoHNzwxGwQ2D4rSZwI3DKsjtRuy9saeI”,“revision”:68,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:23:20Z”},{“snap-id”:“ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j”,“instance-key”:“ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j”,“revision”:52,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:13Z”},{“snap-id”:“Oulq6jI8qkI4ScWVafl3VsxSsd52HSGu”,“instance-key”:“Oulq6jI8qkI4ScWVafl3VsxSsd52HSGu”,“revision”:13,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:58Z”},{“snap-id”:“bUB8lXpOC3pItJMaJattT2jhDTyBWClE”,“instance-key”
Apr 13 09:02:49 caracalla snapd[2601]: :“bUB8lXpOC3pItJMaJattT2jhDTyBWClE”,“revision”:163,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:45Z”},{“snap-id”:“gpXp4JZnUWzybzeOgDEHkHfMUKvCJL7u”,“instance-key”:“gpXp4JZnUWzybzeOgDEHkHfMUKvCJL7u”,“revision”:42,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:36Z”},{“snap-id”:“2rGgvyaY0CCzlWuKAPwFtCWrgwkM8lqS”,“instance-key”:“2rGgvyaY0CCzlWuKAPwFtCWrgwkM8lqS”,“revision”:303,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:23:08Z”},{“snap-id”:“KTyDAsgNZg4u9UBJ63MHn6q12fmUjOfn”,“instance-key”:“KTyDAsgNZg4u9UBJ63MHn6q12fmUjOfn”,“revision”:100,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:23:15Z”},{“snap-id”:“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”,“instance-key”:“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”,“revision”:232,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:24Z”},{“snap-id”:“e2hgfjRsvBzotgj7uszUv2ayQS3azzdc”,“instance-key”:“e2hgfjRsvBzotgj7uszUv2ayQS3azzdc”,“revision”:41,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:23:26Z”},{“snap-id”:“JmzJi9kQvHUWddZ32PDJpBRXUpGRxvNS”,“instance-key”:“JmzJi9kQvHUWddZ32PDJpBRXUpGRxvNS”,“revision”:166,“tracking-channel”:“latest/stable”,“epoch”:{“read”:[0],“write”:[0]},“refreshed-date”:“2019-06-20T17:22:19Z”}],“actions”:[{“action”:“refresh”,“instance-key”:“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”,“snap-id”:“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”,“channel”:“latest/stable”,“ignore-validation”:false}],“fields”:[“architectures”,“base”,“confinement”,“contact”,“created-at”,“description”,“download”,“epoch”,“license”,“name”,“prices”,“private”,“publisher”,“revision”,“snap-id”,“s
Apr 13 09:02:49 caracalla snapd[2601]: nap-yaml”,“summary”,“title”,“type”,“version”,“website”,“store-url”,“media”,“common-ids”]}”
Apr 13 09:02:49 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 200 OK\r\nContent-Length: 4026\r\nContent-Type: application/json\r\nDate: Tue, 13 Apr 2021 09:02:49 GMT\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nX-Request-Id: 25E4E02413600A325C3701BB60755E392D840AB\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_refresh.snap_refresh\r\n\r\n{“error-list”:[],“results”:[{“effective-channel”:“latest/stable”,“instance-key”:“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”,“name”:“modem-manager”,“released-at”:“2020-02-04T10:21:20.614094+00:00”,“result”:“refresh”,“snap”:{“architectures”:[“amd64”],“base”:null,“common-ids”:[],“confinement”:“strict”,“contact”:“mailto:snaps@canonical.com”,“created-at”:“2020-01-21T15:05:08.435692+00:00”,“description”:“ModemManager is a DBus-activated daemon which controls mobile broadband (2G/3G/4G) devices and connections. Whether built-in devices, USB dongles, bluetooth-paired telephones or professional RS232/USB devices with external power supplies, ModemManager is able to prepare and configure the modems and setup connections with them.\n\nThe modem-manager snap is usually used together with the network-manager snap. The snap is geared towards devices and IoT and is optimized for Ubuntu Core. Its usage on desktop/server Ubuntu is possible, but manual connection of interfaces is needed and do not expect full integration with the GUI.\n\nDocumentation on how to use the snap can be found in https://docs.ubuntu.com/core/en/stacks/network/modem-manager/docs/.\n\nPlease find the source code at [https://code.launchpad.net/~snappy-hwe-team/snappy-hwe-snaps/+git/modem-manager](https://code.launchpad.net/~snappy-hwe-team/snappy-hwe-snaps/+git/modem-manager\)”,“download”:{“deltas”:[{“format”:“xdelta3”,“sha3-384”:“aeaf3c8997b5b7c483ed69f7a2db3fdb025f4e76b7efc624010a5c0428f5631d7fce0d45e1590366d9c369a7d988cb0c”,“size”:956195,“source”:232,“target”:426,“url”:”[https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_232_426_xdelta3.delta](https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_232_426_xdelta3.delta\)"}],“sha3-384”:“9119847c082bee2f17a2e675e9b6077ae5a4bc17c7345f5572
Apr 13 09:02:50 caracalla snapd[2601]: 3208fd128bdd9d25cf0c2e612024ec0229186a9bcfae43”,“size”:1630208,“url”:"[https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap](https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap\)"},“epoch”:{“read”:[0],“write”:[0]},“license”:“GPL-2.0”,“media”:[{“height”:379,“type”:“icon”,“url”:"[https://dashboard.snapcraft.io/site_media/appmedia/2020/05/mm-logo.png](https://dashboard.snapcraft.io/site_media/appmedia/2020/05/mm-logo.png\)",“width”:379}],“name”:“modem-manager”,“prices”:{},“private”:false,“publisher”:{“display-name”:“Canonical”,“id”:“canonical”,“username”:“canonical”,“validation”:“verified”},“revision”:426,“snap-id”:“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”,“snap-yaml”:“name: modem-manager\nversion: 1.8.0-12\nsummary: ModemManager is a service which controls mobile broadband\ndescription: |\n ModemManager is a DBus-activated daemon which controls mobile broadband\n (2G/3G/4G) devices and connections. Whether built-in devices, USB dongles,\n bluetooth-paired telephones or professional RS232/USB devices with external\n power supplies, ModemManager is able to prepare and configure the modems and\n setup connections with them.\n Please find the source code at https://code.launchpad.net/~snappy-hwe-team/snappy-hwe-snaps/+git/modem-manager\napps:\n mbim-network:\n command: bin/mbim-network\n command-chain:\n - snap/command-chain/snapcraft-runner\n slots:\n - service\n mbimcli:\n command: bin/mbimcli\n command-chain:\n - snap/command-chain/snapcraft-runner\n slots:\n - service\n mmcli:\n command: bin/mmcli\n command-chain:\n - snap/command-chain/snapcraft-runner\n plugs:\n - mmcli\n modemmanager:\n command: bin/modemmanager\n command-chain:\n - snap/command-chain/snapcraft-runner\n daemon: simple\n slots:\n - service\n qmi-network:\n command: bin/qmi-network\n command-chain:\n - snap/command-chain/snapcraft-runner\n slots:\n - service\n qmicli:\n command: bin/qmicli\n command-chain:\n - snap/command-chain/snapcraft-ru
Apr 13 09:02:50 caracalla snapd[2601]: nner\n slots:\n - service\narchitectures:\n- amd64\nassumes:\n- command-chain\nconfinement: strict\ngrade: stable\nhooks:\n configure:\n plugs:\n - mmcli\nplugs:\n mmcli:\n interface: modem-manager\nslots:\n service:\n interface: modem-manager\n”,“summary”:“ModemManager is a service which controls mobile broadband”,“title”:“modem-manager”,“type”:“app”,“version”:“1.8.0-12”,“website”:null},“snap-id”:“KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo”}]}\n"
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/v2/snaps/refresh finished after 1 retries, elapsed time=184.146492ms, status: 200
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/assertions/validation/16/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo/426?max-format=0, attempt 1, elapsed time=15.458µs
Apr 13 09:02:50 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/assertions/validation/16/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo/426?max-format=0 HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: application/x.ubuntu.assertion\r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 200 OK\r\nContent-Length: 1034\r\nAge: 0\r\nContent-Type: application/x.ubuntu.assertion\r\nDate: Tue, 13 Apr 2021 09:02:50 GMT\r\nEtag: “0”\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nVary: Accept\r\nVia: 1.1 juju-f25c99-prod-ols-snap-store-769 (squid/3.5.27)\r\nX-Cache: HIT from juju-f25c99-prod-ols-snap-store-769\r\nX-Cache-Lookup: HIT from juju-f25c99-prod-ols-snap-store-769:3128\r\nX-Request-Id: 25E4E02413600A325C3701BB60755E392D84197\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_assertions.assertions_find\r\n\r\ntype: validation\nauthority-id: canonical\nseries: 16\nsnap-id: ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j\napproved-snap-id: KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo\napproved-snap-revision: 426\nrevoked: false\ntimestamp: 2020-02-04T16:21:41.786696Z\nsign-key-sha3-384: BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul\n\nAcLBUgQAAQoABgUCXjmaFQAA6l0QABdH269P2fCf4IhT+7G28DjK+UqHhkaGFdQjUIFbBQ9z+Dw4\nmQsnIF3CEaFbdnO1QMiFEbJOV/PuU4H9GexhubAP7EEdrLtCy2b9tQYw5F+8dl4aJZ7qa1udb8RL\nt9hWEmm+ZSFbTnpsJVRTzCYkqVC5DJslBOC02ujUzePZLmQ+DVOXtk1aSoC6B8COZ3cvYq7YISJD\nn9AswB/PWeCbIaNu4Cme6dq2zLPCEcnGoG21AYI3yy9Jyl7nNlDrXdfZ78dWBtgiTLlt8VT/gIfe\nDfxZsBWafpLkusyy95EqEwPFtQ2aBwGAZP/6ZPxdi8dcvx9/ascQpu5pDfHaEyPHhkgyrHYW2YOK\ncvtVuE3Ndh4/2qgLAMi0XCsdl2M+JCMGrkuJqraJZopN+uoXQ+yRCiJLobTXya9O9+bv35jW3tk9\nAyzAVJyEwDwf5iU4ABtiDQ4bHqS8TuE5IAVhrLXJJO3faMdjiiKaKwU6Tu42O4+YJRYphGYpLcY1\nTJP4fYNdKMeBg0+RQzghw+wCbAkh83rpMRxG9MD+w2ro1IYibdcAQbAlm4RMY1vouupHhtjuNDSZ\n8g03rPWkR/NeNFFpJOiDOyc3b3R4p1Q9eHnvYeNI15UFgOhp54sEgDdCn9dn4FNVSfeEDt8pSp+E\nund3mPYVfl//wWat2uZRVuRXQ4GM\n”
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/api/v1/snaps/assertions/validation/16/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo/426?max-format=0 finished after 1 retries, elapsed time=63.445563ms, status: 200
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/assertions/snap-declaration/16/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j?max-format=4, attempt 1, elapsed time=11.46µs
Apr 13 09:02:50 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/assertions/snap-declaration/16/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j?max-format=4 HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: application/x.ubuntu.assertion\r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 200 OK\r\nContent-Length: 1718\r\nAge: 0\r\nContent-Type: application/x.ubuntu.assertion\r\nDate: Tue, 13 Apr 2021 09:02:50 GMT\r\nEtag: “12”\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nVary: Accept\r\nVia: 1.1 juju-f25c99-prod-ols-snap-store-769 (squid/3.5.27)\r\nX-Cache: HIT from juju-f25c99-prod-ols-snap-store-769\r\nX-Cache-Lookup: HIT from juju-f25c99-prod-ols-snap-store-769:3128\r\nX-Request-Id: 25E4E02413600A325C3701BB60755E3A2D84238\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_assertions.assertions_find\r\n\r\ntype: snap-declaration\nformat: 1\nauthority-id: canonical\nrevision: 12\nseries: 16\nsnap-id: ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j\nplugs:\n kernel-module-control:\n allow-auto-connection: true\npublisher-id: canonical\nrefresh-control:\n - JmzJi9kQvHUWddZ32PDJpBRXUpGRxvNS\n - TlJNTzTp0kFRfD3XFCoa4fDIVYDjwMXm\n - 99T7MUlRhtI3U0QFgl5mXXESAiSwt776\n - bUB8lXpOC3pItJMaJattT2jhDTyBWClE\n - KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo\n - RmBXKl6HO6YOC2DE4G2q1JzWImC04EUy\n - cr5pkasGhR7N3M8wKfP9DJqGxbBGeET2\n - gpXp4JZnUWzybzeOgDEHkHfMUKvCJL7u\n - Oulq6jI8qkI4ScWVafl3VsxSsd52HSGu\n - 2rGgvyaY0CCzlWuKAPwFtCWrgwkM8lqS\n - KTyDAsgNZg4u9UBJ63MHn6q12fmUjOfn\n - xoHNzwxGwQ2D4rSZwI3DKsjtRuy9saeI\n - e2hgfjRsvBzotgj7uszUv2ayQS3azzdc\n - sLCsFAO8PKM5Z0fAKNszUOX0YASjQfeZ\nslots:\n gpio:\n allow-auto-connection:\n plug-snap-id:\n - GYPMTEVa6Do5jGbHemaSuRHZlzit6jZ4\nsnap-name: caracalla\ntimestamp: 2017-06-15T18:23:29.292543Z\nsign-key-sha3-384: BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul\n\nAcLBUgQAAQoABgUCWULQoQAAt9cQACjQHRaUE215scxCnWrRC65IYXAtw9IqkZVDOZjS7Yrtd6+a\nZBu2yYUElFDY4w2wwfp+Kfp2XDD8uay2WEAmGIb+9VcFuQn2omShUXQBKpV/TqvmyiXgh1CmgCBo\nzwgYxNRkhsX2TT5iokAOpS9B2ROfLmwa5FjfP0YziTB3YSBwmiQOyXn/uE6CzxmLgCgLDHuKoxqt\n74JEBpj7OMnrm7ShisaiQoSDr6Glxq0uorJB82ozmNzzCWeND7+RBickdpqtPWsQros/bcNicytl\npoCXYTC1Oab7FdIvWizVu9F+/HWLS9wUkujGvkO7fUOidbXSc2KsfHEJG6Zji0YZE68wmFqVUbTQ\nwfcFPpYEu65UpFsABQjeOgW19RhU+QTJgrFcLde
Apr 13 09:02:50 caracalla snapd[2601]: mB2rNqFOzRqlO05gATRjp1mNVJuIN9i4h+ZW+\ne3NPMXT3s2ykQBtlROJ1o9sSsHX1LxY4KW4uiW8P5SIc+9ALZqM8wR2Yz0W6ft56C/8jYhYsWQRQ\nfcg4YTD4BWtVeZc/qMCvLRG6uhFQvSFitZ2uhnZ/VZ1jaiVe8oMv//ydUxt4sLtsmuFe1YyDGFRS\nOknzvRMAW6Ckl0QFOkU8GLSKzsWiHFdVG6FQ+gE7o/3OFGjk5MUYjE7CPvfXoDDLZJRFr9kKI6Gy\nitG4FEUleDXJWuU9y04cwQz++MPj\n”
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/api/v1/snaps/assertions/snap-declaration/16/ttZZbj4ZjaFakobHQghX8Z6C5SOTtK0j?max-format=4 finished after 1 retries, elapsed time=72.786706ms, status: 200
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/assertions/account-key/BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul?max-format=0, attempt 1, elapsed time=24.119µs
Apr 13 09:02:50 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/assertions/account-key/BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul?max-format=0 HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: application/x.ubuntu.assertion\r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 200 OK\r\nContent-Length: 2452\r\nAge: 88\r\nContent-Type: application/x.ubuntu.assertion\r\nDate: Thu, 04 Mar 2021 06:09:22 GMT\r\nEtag: “2”\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 33\r\nVary: Accept\r\nVia: 1.1 juju-f25c99-prod-ols-snap-store-66 (squid/3.5.27)\r\nX-Cache: HIT from juju-f25c99-prod-ols-snap-store-66\r\nX-Cache-Lookup: HIT from juju-f25c99-prod-ols-snap-store-66:3128\r\nX-Request-Id: BE026CA12B910A325D7301BB6040799123BF45D\r\nX-Vcs-Revision: c14c361\r\nX-View-Name: snapdevicegw.webapi_assertions.assertions_find\r\n\r\ntype: account-key\nauthority-id: canonical\nrevision: 2\npublic-key-sha3-384: BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul\naccount-id: canonical\nname: store\nsince: 2016-04-01T00:00:00.0Z\nbody-length: 717\nsign-key-sha3-384: -CvQKAwRQ5h3Ffn10FILJoEZUXOv6km9FwA80-Rcj-f-6jadQ89VRswHNiEB9Lxk\n\nAcbBTQRWhcGAARAA0KKYYQWuHOrsFVi4p4l7ZzSvX7kLgJFFeFgOkzdWKBTHEnsMKjl5mefFe9ji\nqe8NlmJdfY7BenP7XeBtwKp700H/t9lLrZbpTNAPHXYxEWFJp5bPqIcJYBZ+29oLVLN1Tc5X482R\nvCiDqL8+pPYqBrK2fNlyPlNNSum9wI70rDDL4r6FVvr+osTnGejibdV8JphWX+lrSQDnRSdM8KJi\nUM43vTgLGTi9W54oRhsA2OFexRfRksTrnqGoonCjqX5wO3OFSaMDzMsO2MJ/hPfLgDqw53qjzuKL\nIec9OL3k5basvu2cj5u9tKwVFDsCKK2GbKUsWWpx2KTpOifmhmiAbzkTHbH9KaoMS7p0kJwhTQGA\no9aJ9VMTWHJc/NCBx7eu451u6d46sBPCXS/OMUh2766fQmoRtO1OwCTxsRKG2kkjbMn54UdFULl9\nVfzvyghMNRKIezsEkmM8wueTqGUGZWa6CEZqZKwhe/PROxOPYzqtDH18XZknbU1n5lNb7vNfem9F\n2ai+3+JyFnW9UhfvpVF7gzAgdyCqNli4C6BIN43uwoS8HkykocZS/+Gv52aUQ/NZ8BKOHLw+7ant\nQ0o8W9ltSLZbEMxFIPSN0stiZlkXAp6DLyvh1Y4wXSynDjUondTpej2fSvSlCz/W5v5V7qA4nIcG\nvUvV7RjVzv17ut0AEQEAAQ==\n\nAcLDXAQAAQoABgUCV83k9QAKCRDUpVvql9g3IBT8IACKZ7XpiBZ3W4lqbPssY6On81WmxQLtvsMV\nWTp6zZpl/wWOSt2vMNUk9pvcmrNq1jG9CuhDfWFLGXEjcrrmVkN3YuCOajMSPFCGrxsIBLSRt/bP\nnrKykdLAAzMfG8rP1d82bjFFiIieE+urQ0Kcv09Jtdvavq3JT1Tek5mFyyfhHNlQEKOzWqmRWiLg\n3c3VOZUs1ZD8TSlnuq/x+5T0X0YtOyGjSlVxk7UybbyMNd6MZfNaMpIG4x+mxD3KHFtBAC7O6kLe\neX3i6j5nCY5UABfA3DZEAkWP4zlmdBEOvZ9t293NaDdOpzsUHRkoi0Zez/9BHQ/kwx/uNc2WqrYm\ninCmu16JGNeXqsyinnLl7Ghn2R
Apr 13 09:02:50 caracalla snapd[2601]: whvDMlLxF6RTx8xdx1yk6p3PBTwhZMUvuZGjUtN/AG8BmVJQ19\nrsGSRkkSywvnhVJRB2sudnrMBmNS2goJbzSbmJnOlBrd2WsV0T9SgNMWZBiov3LvU4o2SmAb6b+k\nrYwh8H5QHcuuYJuxDjFhPswIp6Wes5T6hUicf3SWtObcDS4HSkVS4ImBjjX9YgCuFy7QdnooOWEY\naPvkRw3XCVeYq0K6w9GRsk1YFErD4XmXXZjDYY650MX9v42Sz5MmphHV8jdIY5ssbadwFSe2rCQI\n6UX08zy7RsIb19hTndE6ncvSNDChUR9eEnCm73eYaWTWTnq1cxdVP/s52r8uss++OYOkPWqh5nOu\nhaRn7INjH/yZX4qXjNXlTjo0PnHH0q08vNKDwLhxS+D9du+70FeacXFyLIbcWllSbJ7DmbumGpFo\nyYbtj3FDDPzachFQdIG3lSt+cSUGeyfSs6wVtc3cIPka/2Urx7RprfmoWSI6+a5NcLdj0u2z8O96\nHxeIgxDpg/3gT8ZIuFKePMcLDM19Fh/p0ysCsX+84B9chNWtsMSmIaE57V+959MVtsLu7SLb9gi7\nskrju0pQCwsu2wHMLTNd1f3PTHmrr49hxetTus07HSQUApMtAGKzQilF5zqFjbyaTd4xgQbd+PKW\nCjFyzQTDOcUhXpuUGt/IzlqiFfsCsmbj2K4KdSNYMlqIgZ3Azu8KvZLIhsyN7v5vNIZSPfEbjdeu\nClU9r0VRiJmtYBUjcSghD9LWn+yRLwOxhfQVjm0cBwIt5R/yPF/qC76yIVuWUtM5Y2/zJR1J8OFq\nqWchvlImHtvDzS9FQeLyzJAOjvZ2CnWp2gILgUz0WQdOk1Dq8ax7KS9BQ42zxw9EZAEPw3PEFqRy\nIQsRTONp+iVS8YxSmoYZjDlCgRMWUmawez/Fv5b9Fb/XkO5Eq4e+KfrpUujXItaipb+tV8h5v3tr\noG3Ie3WOHrVjCLXIdYslpL1O4nadqR6Xv58pHj6k\n”
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/api/v1/snaps/assertions/account-key/BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul?max-format=0 finished after 1 retries, elapsed time=39.26667ms, status: 200
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/assertions/snap-declaration/16/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo?max-format=4, attempt 1, elapsed time=14.032µs
Apr 13 09:02:50 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/assertions/snap-declaration/16/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo?max-format=4 HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: application/x.ubuntu.assertion\r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 200 OK\r\nContent-Length: 1287\r\nAge: 0\r\nContent-Type: application/x.ubuntu.assertion\r\nDate: Tue, 13 Apr 2021 09:02:50 GMT\r\nEtag: “19”\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nVary: Accept\r\nVia: 1.1 juju-f25c99-prod-ols-snap-store-773 (squid/3.5.27)\r\nX-Cache: HIT from juju-f25c99-prod-ols-snap-store-773\r\nX-Cache-Lookup: HIT from juju-f25c99-prod-ols-snap-store-773:3128\r\nX-Request-Id: 25E4E02413600A325C3701BB60755E3A2D842A7\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_assertions.assertions_find\r\n\r\ntype: snap-declaration\nformat: 1\nauthority-id: canonical\nrevision: 19\nseries: 16\nsnap-id: KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo\naliases:\n -\n name: mmcli\n target: mmcli\nauto-aliases:\n - mmcli\nplugs:\n modem-manager:\n allow-auto-connection: true\npublisher-id: canonical\nslots:\n modem-manager:\n allow-connection: true\n allow-installation:\n slot-snap-type:\n - app\n deny-auto-connection: true\nsnap-name: modem-manager\ntimestamp: 2017-11-16T20:03:51.724943Z\nsign-key-sha3-384: BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul\n\nAcLBUgQAAQoABgUCWg3vJwAABT8QABd4o5C9DlYw6+sRH+z5PTDEo1pMWi95a+bt+3lyATloq5gb\nVNB6SdeFupuvS2a7fmNwzvp2A4h4trAz306uGY2KCcIofxATgxl/KynSlnOZ8sgxVB75IGN59pri\ntsSP13GNutYNqXNYV9qZ6bdOfgHydCnD+pW3pzrJACW4nUMtpcYEAq9AJzyqisGQqFOcUx6Er9in\nLlaPSjLskMUS1Ce1B9Hd+8HNWAz3EA8jW1JAYPqiJnmaNEQ8ZrsC1z4w5t4pXIG7QEUQLQELZocE\nUN0Zjg84wdp06dT1zjD46de5ho9aaFuV1PscSzrjFAss8yV9kubH+y6nA7IEx/wdWNROLSCogihn\nv7q2QGmJs1AZaJjeJbSvpfl85dAYTCTE5ZX2mrbbOI9opjUMSTmKMmHb9L3KzoJwfw8kL9Fk0YBT\nGIoijUwz23Zw57bUjsb70zCGCgjOlI6FNwEkuLHGwOLJHn+CDoE+qYIzk546eCeROrfkyirKTQKX\nmN/0pDPK4yrhIvoh44L2VAsZQKGcM5EJ55Ii+igiS13Lhjx6HWNr6GFZhZD1ngvTw3zgyXrMGpPO\nUmW4Yr4un0bJr71xrb4pN+OIFh1AmzBh2QtBIzc/IfR7+jBvycwCJ5Z4vWqDapxwjsYEmpIVSds4\nK1Ej5Utl4SAMoCpjCXVSDTcC07no\n”
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/api/v1/snaps/assertions/snap-declaration/16/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo?max-format=4 finished after 1 retries, elapsed time=77.396904ms, status: 200
Apr 13 09:02:50 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1518 on Do: Consider re-refresh of “modem-manager”
Apr 13 09:02:50 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1499 on Do: Ensure prerequisites for “modem-manager” are available
Apr 13 09:02:50 caracalla snapd[2601]: daemon.go:317: DEBUG: pid=2680;uid=0;socket=/run/snapd.socket; POST /v2/snaps/modem-manager 1.104104422s 202
Apr 13 09:02:50 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1500 on Do: Download snap “modem-manager” (426) from channel “latest/stable”
Apr 13 09:02:50 caracalla snapd[2601]: store_download.go:161: DEBUG: Available deltas returned by store: [{232 426 xdelta3 https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_232_426_xdelta3.delta 956195 aeaf3c8997b5b7c483ed69f7a2db3fdb025f4e76b7efc624010a5c0428f5631d7fce0d45e1590366d9c369a7d988cb0c}]
Apr 13 09:02:50 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_232_426_xdelta3.delta, attempt 1, elapsed time=50.332µs
Apr 13 09:02:50 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:50 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_232_426_xdelta3.delta HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: \r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:51 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1518 on Doing: Consider re-refresh of “modem-manager”
Apr 13 09:02:51 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 404 NOT FOUND\r\nContent-Length: 233\r\nContent-Type: application/json\r\nDate: Tue, 13 Apr 2021 09:02:51 GMT\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nX-Request-Id: 25E4E02413400A325D7701BB60755E3B307CE8A\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_download.snap_download\r\n\r\n”
Apr 13 09:02:51 caracalla snapd[2601]: store_download.go:169: Cannot download or apply deltas for modem-manager: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_232_426_xdelta3.delta
Apr 13 09:02:51 caracalla snapd[2601]: store_download.go:197: DEBUG: Starting download of “/var/lib/snapd/snaps/modem-manager_426.snap.partial”.
Apr 13 09:02:51 caracalla snapd[2601]: retry.go:49: DEBUG: Retrying https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap, attempt 1, elapsed time=106.626µs
Apr 13 09:02:51 caracalla snapd[2601]: store.go:929: DEBUG: cannot set device session: no device serial yet
Apr 13 09:02:51 caracalla snapd[2601]: logger.go:67: DEBUG: > “GET /api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap HTTP/1.1\r\nHost: api.snapcraft.io\r\nUser-Agent: snapd/2.49.2 (series 16) ubuntu-core/16 (amd64) linux/4.4.0-151-generic\r\nAccept: \r\nSnap-Device-Capabilities: default-tracks\r\nX-Ubuntu-Architecture: amd64\r\nX-Ubuntu-Classic: false\r\nX-Ubuntu-Series: 16\r\nX-Ubuntu-Store: he9Haizai7thooneiph9\r\nX-Ubuntu-Wire-Protocol: 1\r\nAccept-Encoding: gzip\r\n\r\n”
Apr 13 09:02:51 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1518 on Doing: Consider re-refresh of “modem-manager”
Apr 13 09:02:52 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1518 on Doing: Consider re-refresh of “modem-manager”
Apr 13 09:02:52 caracalla snapd[2601]: logger.go:74: DEBUG: < “HTTP/1.1 404 NOT FOUND\r\nContent-Length: 207\r\nContent-Type: application/json\r\nDate: Tue, 13 Apr 2021 09:02:52 GMT\r\nServer: gunicorn/19.7.1\r\nSnap-Store-Version: 34\r\nX-Request-Id: 25E4E02412E00A325D5F01BB60755E3C2F9761E\r\nX-Vcs-Revision: 61bdb1d\r\nX-View-Name: snapdevicegw.webapi_download.snap_download\r\n\r\n”
Apr 13 09:02:52 caracalla snapd[2601]: store_download.go:213: DEBUG: download of “https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap” failed: &store.DownloadError{Code:404, URL:(*url.URL)(0xc4203e4880)}
Apr 13 09:02:52 caracalla snapd[2601]: task.go:337: DEBUG: 2021-04-13T09:02:52Z ERROR received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap
Apr 13 09:02:52 caracalla snapd[2601]: taskrunner.go:271: [change 61 “Download snap “modem-manager” (426) from channel “latest/stable”” task] failed: received an unexpected http response code (404) when trying to download https://api.snapcraft.io/api/v1/snaps/download/KtwxgRlwCAVKFw92BUdt1WloH1Va3QPo_426.snap
Apr 13 09:02:53 caracalla snapd[2601]: taskrunner.go:439: DEBUG: Running task 1518 on Doing: Consider re-refresh of “modem-manager”
root@caracalla:~#

mborzecki · April 13, 2021, 9:45am

Looks like other endpoints are accessible, but https://api.snapcraft.io/api/v1/snaps/download consistently returns 404. Response headers suggest that the request reached the store.

Edit: moved the topic to ‘store’ category.