Intermittent failure to "snap refresh" becauses of Store issue?

Hello,

Starting in the first days of 2024, we are experiencing intermittent issues, https://bugzilla.mozilla.org/show_bug.cgi?id=1873359 ; I’ve found this bug on launchpad that looks to be the same behavior: Bug #2048104 “Cant install firefox update - Mount snap “firefox”...” : Bugs : snapd

We have CI tests that force a snap refresh (that was the only way I found to workaround bug 2039052) and they now fail because of that error: Mount snap "firefox" (3600) (cannot find required base "core22")

Is this a known Store issue ? Being actively worked on ?

And the missing link is Bug #2039052 “blocking refresh does not block auto-refresh” : Bugs : snapd

If you suspect any downtime on the store side, https://status.snapcraft.io/ is always a good place to check…

It does not looks like a full blown downtime, and honestly I have no idea how this error can be triggered, all I know is that it started a few days ago and it’s continuing, and it’s intermittent. I’ve shared the requested logs on the launchpad issue, but there’s obviously nothing actionable in those.

Hi ! @alissy .

Looking at your log file. Unless I’m mistaken, it looks like you have a problem at the level of urllib.request.urlopen(), the function in question seems outdated :face_with_monocle:.

Perhaps, you should update the module or the package linked to this target function.

I’m unsure what you are referring to, I’m not writing any module or package, just using snap refresh

I can’t see any reported outage matching the failures: https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=snap-upstream&revision=1c750a1732587e3087eef34602f4db18db976280

At the level of the first link, look at line 9 .

Yeah, this was rather meant as a general hint (to rule or not rule out the store itself), doesn’t look like the issue is related to current store outages…

There must be some other communication issue in play here

That’s not my code and that’s totally unrelated to the problem ?

For the moment, the only relevant issue I found is linked to this function (the one raised above).

I am unsure what you are trying to achieve here or why you focus on that, https://treeherder.mozilla.org/logviewer?job_id=442231971&repo=mozilla-central&lineNumber=53-55

[fetches 2024-01-05T01:05:19.757Z] fetching artifacts
[fetches 2024-01-05T01:05:19.758Z] executing ['/usr/bin/python3', '-u', '/home/ubuntu/tasks/task_170441667401445/./fetch-content', 'task-artifacts']
[fetches 2024-01-05T01:05:19.999Z] attempt 1/5
[fetches 2024-01-05T01:05:19.999Z] Downloading https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNwhWKDjQtWNedLYBYYGwQ/artifacts/public/build/firefox.snap to /home/ubuntu/tasks/task_170441667401445/fetches/firefox.snap
[fetches 2024-01-05T01:05:19.999Z] Downloading https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNwhWKDjQtWNedLYBYYGwQ/artifacts/public/build/firefox.snap
[fetches 2024-01-05T01:05:20.000Z] /home/ubuntu/tasks/task_170441667401445/./fetch-content:186: DeprecationWarning: cafile, capath and cadefault are deprecated, use a custom context instead.
[fetches 2024-01-05T01:05:20.000Z]   with urllib.request.urlopen(
[fetches 2024-01-05T01:05:20.001Z] attempt 1/5
[fetches 2024-01-05T01:05:20.001Z] Downloading https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNwhWKDjQtWNedLYBYYGwQ/artifacts/public/build/snap-tests.zip to /home/ubuntu/tasks/task_170441667401445/fetches/snap-tests.zip
[fetches 2024-01-05T01:05:20.002Z] Downloading https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNwhWKDjQtWNedLYBYYGwQ/artifacts/public/build/snap-tests.zip
[fetches 2024-01-05T01:05:22.077Z] https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNwhWKDjQtWNedLYBYYGwQ/artifacts/public/build/snap-tests.zip resolved to 3100 bytes with sha256 b582e7e7c1d8bdfd1f635fc562f2067c7b6832acf7a2e14b201900bb619b6af4 in 2.075s
[fetches 2024-01-05T01:05:22.078Z] Extracting /home/ubuntu/tasks/task_170441667401445/fetches/snap-tests.zip to /home/ubuntu/tasks/task_170441667401445/fetches
[fetches 2024-01-05T01:05:22.113Z] Archive:  /home/ubuntu/tasks/task_170441667401445/fetches/snap-tests.zip
[fetches 2024-01-05T01:05:22.114Z]   inflating: basic_tests.py          
[fetches 2024-01-05T01:05:22.115Z]   inflating: expectations.json.in    
[fetches 2024-01-05T01:05:22.115Z]   inflating: requirements.txt        
[fetches 2024-01-05T01:05:22.115Z]   inflating: tests.sh                
[fetches 2024-01-05T01:05:22.116Z] /home/ubuntu/tasks/task_170441667401445/fetches/snap-tests.zip extracted in 0.038s
[fetches 2024-01-05T01:05:22.116Z] Removing /home/ubuntu/tasks/task_170441667401445/fetches/snap-tests.zip
[fetches 2024-01-05T01:05:45.423Z] https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNwhWKDjQtWNedLYBYYGwQ/artifacts/public/build/firefox.snap resolved to 982831104 bytes with sha256 f82a238ee5a56ae2bb76de9db266db88e095165faebe53b155939a52ba6c46ee in 25.424s
[fetches 2024-01-05T01:05:45.424Z] Extracting /home/ubuntu/tasks/task_170441667401445/fetches/firefox.snap to /home/ubuntu/tasks/task_170441667401445/fetches
[fetches 2024-01-05T01:05:45.437Z] PERFHERDER_DATA: {"framework": {"name": "build_metrics"}, "suites": [{"name": "fetch_content", "value": 22.92402491700001, "lowerIsBetter": true, "shouldAlert": false, "subtests": []}]}
[fetches 2024-01-05T01:05:45.439Z] finished fetching artifacts
[task 2024-01-05T01:05:45.440Z] executing ['bash', '-cx', 'export TASKCLUSTER_ROOT_DIR=$PWD && cd $MOZ_FETCHES_DIR/ && ./tests.sh']
[task 2024-01-05T01:05:45.444Z] + export TASKCLUSTER_ROOT_DIR=/home/ubuntu/tasks/task_170441667401445
[task 2024-01-05T01:05:45.444Z] + TASKCLUSTER_ROOT_DIR=/home/ubuntu/tasks/task_170441667401445
[task 2024-01-05T01:05:45.444Z] + cd /home/ubuntu/tasks/task_170441667401445/fetches/
[task 2024-01-05T01:05:45.444Z] + ./tests.sh
[task 2024-01-05T01:05:45.447Z] + pwd
[task 2024-01-05T01:05:45.447Z] /home/ubuntu/tasks/task_170441667401445/fetches
[task 2024-01-05T01:05:45.447Z] + ARTIFACT_DIR=/home/ubuntu/tasks/task_170441667401445/builds/worker/artifacts/
[task 2024-01-05T01:05:45.447Z] + mkdir -p /home/ubuntu/tasks/task_170441667401445/builds/worker/artifacts/
[task 2024-01-05T01:05:45.451Z] + sudo snap refresh
[task 2024-01-05T01:06:12.855Z] 2024-01-05T01:06:05Z INFO Waiting for automatic snapd restart...
[task 2024-01-05T01:07:02.127Z] error: cannot perform the following tasks:
[task 2024-01-05T01:07:02.127Z] - Mount snap "firefox" (3600) (cannot find required base "core22")

The line [fetches 2024-01-05T01:05:20.000Z] with urllib.request.urlopen( is 100% unrelated to the sudo snap refresh call that is triggering the problem.

Look at this - >

[fetches 2024-01-05T01:05:20.000Z] /home/ubuntu/tasks/task_170441667401445/./fetch-content:186: DeprecationWarning: cafile, capath and cadefault are deprecated, use a custom context instead. [fetches 2024-01-05T01:05:20.000Z] with urllib.request.urlopen(

Yes, and ? How does it relates to the problem ? It’s fetch-content from TC infra, completely orthogonal to snap.

As you can see here https://searchfox.org/mozilla-central/rev/961a9e56a0b5fa96ceef22c61c5e75fb6ba53395/taskcluster/scripts/misc/fetch-content#186 it is just used to download the payload of the task we are going to run, i.e., the tests script (those that will issue sudo snap refresh). Feel free to file a bug and send a patch but it’s likely TC people already know about that …

Maybe I’m wrong, I thought that this function is the cause of the download of the Firefox that you have which seems corrupt to me.

We’re not even downloading FIrefox yet at that point. This is really unrelated to the issue.

Okay :thinking:!

Did you try to reinstall snap ?

I’m wondering if it is really a snap store issue, I see latest/stable: 2.61.1 2024-01-04 (20671) 42MB - So snapd 2.61.1 shipped on jan 4th and sherrifs also reported it started to fail the same day: https://bugzilla.mozilla.org/show_bug.cgi?id=1873359#c1

Would you have the ability to install the former snapd version from your CI scripts somehow? (i.e. by calling snap install --revision=xxxx snapd at the start (not sure what that revision was though, we’d need to find out first indeed) and then using snap hold ... to prevent it from being updated later on in the build)

That way you could pin it down on the snapd version/update