Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

WARN: Unexpected downgrade detected: skipping #29919

Closed
rarkins opened this issue Jun 28, 2024 · 41 comments
Closed

WARN: Unexpected downgrade detected: skipping #29919

rarkins opened this issue Jun 28, 2024 · 41 comments
Assignees
Labels
priority-2-high Bugs impacting wide number of users or very important features type:bug Bug fix of existing functionality

Comments

@rarkins
Copy link
Collaborator

rarkins commented Jun 28, 2024

Describe the proposed change(s).

Renovate in some cases is creating PRs to update dependencies where it's actually a downgrade. It appears to be isolated to docker versioning, which is used for the docker datasource and also for github actions.

Discussion: #29901

Unfortunately we are not yet able to reproduce it

Update: we have added code to suppress such workarounds and log a message WARN: Unexpected downgrade detected: skipping instead, so I have updated the title of this Issue to match

@rarkins rarkins added type:bug Bug fix of existing functionality priority-1-critical A bad bug or work that is holding up a lot of other important features or fixes labels Jun 28, 2024
@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

This GitHub Action example was autoclosed: ayushmanchhabra/vsx#554

Related log:

          {
            "autoReplaceStringTemplate": "{{depName}}@{{#if newDigest}}{{newDigest}}{{#if newValue}} # {{newValue}}{{/if}}{{/if}}{{#unless newDigest}}{{newValue}}{{/unless}}",
            "commitMessageTopic": "{{{depName}}} action",
            "currentValue": "v4.0.2",
            "currentVersion": "v4.0.2",
            "currentVersionTimestamp": "2024-02-07T04:42:16.000Z",
            "datasource": "github-tags",
            "depName": "actions/setup-node",
            "depType": "action",
            "fixedVersion": "v4.0.2",
            "packageName": "actions/setup-node",
            "registryUrl": "https://github.com",
            "replaceString": "actions/setup-node@v4.0.2",
            "sourceUrl": "https://github.com/actions/setup-node",
            "versioning": "docker",
            "warnings": [],
            "updates": [
              {
                "bucket": "major",
                "newVersion": "v2.3.0",
                "newValue": "v2.3.0",
                "releaseTimestamp": "2021-07-20T12:22:13.000Z",
                "newMajor": 2,
                "newMinor": 3,
                "newPatch": 0,
                "updateType": "minor",
                "branchName": "renovate/actions-setup-node-2.x"
              }
            ],
            "isSingleVersion": true
          },

@rarkins

This comment was marked as resolved.

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

This appears to be a Docker downgrade: #29855

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

Another GitHub Action example: etrias-nl/php-dev#467

@MarcWort
Copy link

MarcWort commented Jun 28, 2024

We are facing the same problem on our self-hosted instance. With dockerimages from dockerhub and our own gitlab registry. We havent noticed any downgrade before 06/22, but now we get ~1 per day.

Jun 24 02:25:32.862:            {
Jun 24 02:25:32.862:              "deps": [
Jun 24 02:25:32.862:                {
Jun 24 02:25:32.862:                  "depName": "earthly/buildkitd",
Jun 24 02:25:32.862:                  "currentValue": "v0.8.14",
Jun 24 02:25:32.862:                  "currentDigest": "sha256:c6b989bb1280c04d26ce8d32567dacadd731f8e398a226eaf65d8fcf8ac06bc6",
Jun 24 02:25:32.862:                  "datasource": "docker",
Jun 24 02:25:32.862:                  "versioning": "docker",
Jun 24 02:25:32.862:                  "replaceString": "earthly/buildkitd:v0.8.14@sha256:c6b989bb1280c04d26ce8d32567dacadd731f8e398a226eaf65d8fcf8ac06bc6",
Jun 24 02:25:32.862:                  "updates": [
Jun 24 02:25:32.862:                    {
Jun 24 02:25:32.862:                      "bucket": "minor",
Jun 24 02:25:32.862:                      "newVersion": "v0.5.1",
Jun 24 02:25:32.862:                      "newValue": "v0.5.1",
Jun 24 02:25:32.862:                      "newMajor": 0,
Jun 24 02:25:32.862:                      "newMinor": 5,
Jun 24 02:25:32.862:                      "newPatch": 1,
Jun 24 02:25:32.862:                      "updateType": "patch",
Jun 24 02:25:32.862:                      "newDigest": "sha256:8a3a2f4d51f4ffa3a37da95341aa473d57e827ef7f22c2a447756eb5ca612e28",
Jun 24 02:25:32.862:                      "branchName": "renovate/patch-earthly"
Jun 24 02:25:32.862:                    }
Jun 24 02:25:32.862:                  ],
Jun 24 02:25:32.862:                  "packageName": "earthly/buildkitd",
Jun 24 02:25:32.862:                  "warnings": [],
Jun 24 02:25:32.862:                  "registryUrl": "https://index.docker.io",
Jun 24 02:25:32.862:                  "currentVersion": "v0.8.14",
Jun 24 02:25:32.862:                  "isSingleVersion": true,
Jun 24 02:25:32.862:                  "fixedVersion": "v0.8.14"
Jun 24 02:25:32.862:                }
Jun 24 02:25:32.862:              ],
Jun 24 02:25:32.862:              "matchStrings": [
Jun 24 02:25:32.862:                "(?<depName>[^ :\"]+?):(?<currentValue>[^ :@]+?)@(?<currentDigest>sha256:[a-f0-9]+)"
Jun 24 02:25:32.862:              ],
Jun 24 02:25:32.862:              "datasourceTemplate": "docker",
Jun 24 02:25:32.862:              "versioningTemplate": "docker",
Jun 24 02:25:32.862:              "packageFile": "hieradata/roles/gitlab_runner::earthly.yaml"
Jun 24 02:25:32.862:            },
 

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

@zharinov now we know it's not related to the Mend app/cache specifically.

@MarcWort are you using repository or package caching when your self-host? e.g. disk-based or S3-based for repository cache, or disk-based or Redis-based for package cache?

@MarcWort
Copy link

are you using repository or package caching when your self-host? e.g. disk-based or S3-based for repository cache, or disk-based or Redis-based for package cache?

@rarkins I use the defaults with the renovate docker image. So just disk based package cache.

@MarcWort
Copy link

MarcWort commented Jun 28, 2024

Debug logs from the buildkitd downgrade I mentioned:

Jun 24 02:25:20.827 DEBUG: getDigest(https://index.docker.io, earthly/buildkitd, v0.5.1) (repository=provid/puppet-control)
Jun 24 02:25:20.828 DEBUG: getManifestResponse(https://index.docker.io, earthly/buildkitd, v0.5.1, head) (repository=provid/puppet-control)
Jun 24 02:25:26.498 DEBUG: getDigest(https://index.docker.io, earthly/buildkitd, v0.8.14) (repository=provid/puppet-control)
Jun 24 02:25:26.498 DEBUG: getManifestResponse(https://index.docker.io, earthly/buildkitd, v0.8.14, head) (repository=provid/puppet-control)

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

Docker versioning hasn't changed in 7 months: https://github.com/renovatebot/renovate/tree/main/lib/modules/versioning/docker

Here's the recent changes to the common lookup logic: https://github.com/renovatebot/renovate/commits/main/lib/workers/repository/process/lookup

Can anyone narrow down the release range in which this would have started?

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

We're seeing a reasonably high number of these which autoclose themselves. Which is kind of good of course, but it also means it's related to some type of temporary data problem, which is harder to diagnose.

@echoix
Copy link

echoix commented Jun 28, 2024

But it still decreases my confidence of ever using automerge with Renovate :s. I had to request to retry the PRs to have renovate figure out it wasn't needed. Does having the preset to separate minor major have something to do in this?

@MarcWort
Copy link

it's related to some type of temporary data problem, which is harder to diagnose.

Since we are self-hosted, I can see the requests made to our gitlab registry. Notice that the response is always the exact same number of bytes because nothing has changed. But that renovate did a downgrade at [27/Jun/2024:10:06:34 +0200]

192.168.110.217 - - [27/Jun/2024:02:36:58 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 401 188 "" "RenovateBot/37.419.1 (https://github.com/renovatebot/renovate)" -
192.168.110.217 - - [27/Jun/2024:02:37:04 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 200 1471 "" "RenovateBot/37.419.1 (https://github.com/renovatebot/renovate)" 4.64
192.168.110.217 - - [27/Jun/2024:10:06:33 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 401 188 "" "RenovateBot/37.420.1 (https://github.com/renovatebot/renovate)" -
192.168.110.217 - - [27/Jun/2024:10:06:34 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 200 1471 "" "RenovateBot/37.420.1 (https://github.com/renovatebot/renovate)" 4.64
192.168.110.217 - - [27/Jun/2024:13:02:12 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 401 188 "" "RenovateBot/37.420.1 (https://github.com/renovatebot/renovate)" -
192.168.110.217 - - [27/Jun/2024:13:02:18 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 200 1471 "" "RenovateBot/37.420.1 (https://github.com/renovatebot/renovate)" 4.64
192.168.110.217 - - [27/Jun/2024:15:53:55 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 401 188 "" "RenovateBot/37.420.1 (https://github.com/renovatebot/renovate)" -
192.168.110.217 - - [27/Jun/2024:15:54:01 +0200] "GET /v2/provid/kubernetes-extensions/tags/list?n=10000 HTTP/1.1" 200 1471 "" "RenovateBot/37.420.1 (https://github.com/renovatebot/renovate)" 4.64

@robinschneider
Copy link
Contributor

Can anyone narrow down the release range in which this would have started?

This version was fine for us, so we moved back to this ghcr.io/renovatebot/renovate:37.409.1

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

This PR should hopefully avoid these happening, but not solve the root cause: #29921

@TWiStErRob

This comment was marked as resolved.

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 28, 2024

@TWiStErRob could you save the full log - or Job IDs - of the run where it was autoclosed and the one before it when it was created? I'd like to see if there's any helpful indicators

@TWiStErRob
Copy link
Contributor

Yep, @rarkins I was looking at that, here are the files:

I was diffing T and T+3, a few observations:

  • Docker registry user names differ, I guess this is simply because there are many servers running renovate.
  • GitHub Actions' dependency lookups are not listed as detailed as Gradle's,
    however POSTs to https://api.github.com/graphql is 2 when it was opened and 1 when it was closed (I assume this is how the data source is looked up)
  • How long is the cache timeout? Is it possible some "bad" data was stored in cache, which confused a subsequent run? (Let me know if this make sense, and you need more job IDs from past hours and days; or temporarily add you as collaborator on the repo to see all.)

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 29, 2024

@TWiStErRob thanks for the logs and detailed descriptions.

The T-3 one also has 1 GraphQL query too. The first GraphQL should be the initRepo() one, so it implies that no github tags/releases were queried (results came from cache).

This indicates that caching alone doesn't cause it, although doesn't rule out that something about caching may contribute to it. It just doesn't happen every time the result is from cache. From a quick code inspection I couldn't figure out which cache period applied here.

The fact that self-hosted users are also seeing this seems to imply:

  • It's not a quirk of the Mend Renovate app only, or some user's data interfering with others, and
  • It's not related to Redis specifically, if it's cache-related

@rarkins rarkins pinned this issue Jun 29, 2024
@echoix
Copy link

echoix commented Jun 29, 2024

And what about non-docker downgrades, with GitHub actions? I just got another one right now: oxsecurity/megalinter#3715

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 29, 2024

GitHub actions have already been mentioned multiple times above. They use docker versioning.

@rarkins rarkins changed the title Mistaken downgrading when using Docker versioning Renovate raises occasional downgrade PRs Jun 29, 2024
@rarkins
Copy link
Collaborator Author

rarkins commented Jun 29, 2024

Renamed the issue to be less "technically correct" (that it's limited to Docker versioning) so that it's less confusing for most.

It seems the problem is limited to Docker or GitHub Actions, both of which use versioning=docker

@rarkins
Copy link
Collaborator Author

rarkins commented Jun 30, 2024

FYI the workaround will be deployed to the hosted app today

Cc @nabeelsaabna

@mxey
Copy link
Contributor

mxey commented Jul 2, 2024

With the workaround released, we have noticed some warnings in our logs. So first of all, the workaround does work, which is good :)

I noticed a very curious pattern. I don't know if it's important, but I thought I would share it. Apparently when the bug triggers, the version that is picked is in the middle of the list of versions.

In this case, there are 121 versions and the 60th was picked:

Jul  2 03:20:00.078 WARN: Unexpected downgrade detected: skipping (repository=provid/puppet-control)
Jul  2 03:20:00.079       "update": {
Jul  2 03:20:00.079         "bucket": "patch",
Jul  2 03:20:00.079         "newVersion": "v0.2.36",
Jul  2 03:20:00.079         "newValue": "v0.2.36",
Jul  2 03:20:00.079         "newMajor": 0,
Jul  2 03:20:00.079         "newMinor": 2,
Jul  2 03:20:00.079         "newPatch": 36,
Jul  2 03:20:00.079         "updateType": "patch"
Jul  2 03:20:00.079       },
Jul  2 03:20:00.079       "allVersions": [
Jul  2 03:20:00.079         {"version": "v0.0.1"},
Jul  2 03:20:00.079         {"version": "v0.1.0"},
Jul  2 03:20:00.079         {"version": "v0.1.1"},
Jul  2 03:20:00.079         {"version": "v0.1.2"},
Jul  2 03:20:00.079         {"version": "v0.1.3"},
Jul  2 03:20:00.079         {"version": "v0.1.4"},
Jul  2 03:20:00.079         {"version": "v0.1.5"},
Jul  2 03:20:00.079         {"version": "v0.1.6"},
Jul  2 03:20:00.079         {"version": "v0.1.7"},
Jul  2 03:20:00.079         {"version": "v0.1.8"},
Jul  2 03:20:00.079         {"version": "v0.1.9"},
Jul  2 03:20:00.079         {"version": "v0.1.10"},
Jul  2 03:20:00.079         {"version": "v0.1.11"},
Jul  2 03:20:00.079         {"version": "v0.1.12"},
Jul  2 03:20:00.079         {"version": "v0.1.13"},
Jul  2 03:20:00.079         {"version": "v0.1.14"},
Jul  2 03:20:00.079         {"version": "v0.1.15"},
Jul  2 03:20:00.079         {"version": "v0.1.16"},
Jul  2 03:20:00.079         {"version": "v0.1.17"},
Jul  2 03:20:00.079         {"version": "v0.1.18"},
Jul  2 03:20:00.079         {"version": "v0.1.19"},
Jul  2 03:20:00.079         {"version": "v0.1.20"},
Jul  2 03:20:00.079         {"version": "v0.1.21"},
Jul  2 03:20:00.079         {"version": "v0.2.0"},
Jul  2 03:20:00.079         {"version": "v0.2.1"},
Jul  2 03:20:00.079         {"version": "v0.2.2"},
Jul  2 03:20:00.079         {"version": "v0.2.3"},
Jul  2 03:20:00.079         {"version": "v0.2.4"},
Jul  2 03:20:00.079         {"version": "v0.2.5"},
Jul  2 03:20:00.079         {"version": "v0.2.6"},
Jul  2 03:20:00.079         {"version": "v0.2.7"},
Jul  2 03:20:00.079         {"version": "v0.2.8"},
Jul  2 03:20:00.079         {"version": "v0.2.9"},
Jul  2 03:20:00.079         {"version": "v0.2.10"},
Jul  2 03:20:00.079         {"version": "v0.2.11"},
Jul  2 03:20:00.079         {"version": "v0.2.12"},
Jul  2 03:20:00.079         {"version": "v0.2.13"},
Jul  2 03:20:00.079         {"version": "v0.2.14"},
Jul  2 03:20:00.079         {"version": "v0.2.15"},
Jul  2 03:20:00.079         {"version": "v0.2.16"},
Jul  2 03:20:00.079         {"version": "v0.2.17"},
Jul  2 03:20:00.079         {"version": "v0.2.18"},
Jul  2 03:20:00.079         {"version": "v0.2.19"},
Jul  2 03:20:00.079         {"version": "v0.2.20"},
Jul  2 03:20:00.079         {"version": "v0.2.21"},
Jul  2 03:20:00.079         {"version": "v0.2.22"},
Jul  2 03:20:00.079         {"version": "v0.2.23"},
Jul  2 03:20:00.079         {"version": "v0.2.24"},
Jul  2 03:20:00.079         {"version": "v0.2.25"},
Jul  2 03:20:00.079         {"version": "v0.2.26"},
Jul  2 03:20:00.079         {"version": "v0.2.27"},
Jul  2 03:20:00.079         {"version": "v0.2.28"},
Jul  2 03:20:00.079         {"version": "v0.2.29"},
Jul  2 03:20:00.079         {"version": "v0.2.30"},
Jul  2 03:20:00.079         {"version": "v0.2.31"},
Jul  2 03:20:00.079         {"version": "v0.2.32"},
Jul  2 03:20:00.079         {"version": "v0.2.33"},
Jul  2 03:20:00.079         {"version": "v0.2.34"},
Jul  2 03:20:00.079         {"version": "v0.2.35"},
Jul  2 03:20:00.079         {"version": "v0.2.36"},
Jul  2 03:20:00.079         {"version": "v0.2.37"},
Jul  2 03:20:00.079         {"version": "v0.2.38"},
Jul  2 03:20:00.079         {"version": "v0.2.39"},
Jul  2 03:20:00.079         {"version": "v0.2.40"},
Jul  2 03:20:00.079         {"version": "v0.2.41"},
Jul  2 03:20:00.079         {"version": "v0.2.42"},
Jul  2 03:20:00.079         {"version": "v0.2.43"},
Jul  2 03:20:00.079         {"version": "v0.2.44"},
Jul  2 03:20:00.079         {"version": "v0.2.45"},
Jul  2 03:20:00.079         {"version": "v0.2.46"},
Jul  2 03:20:00.079         {"version": "v0.2.47"},
Jul  2 03:20:00.079         {"version": "v0.2.48"},
Jul  2 03:20:00.079         {"version": "v0.2.49"},
Jul  2 03:20:00.079         {"version": "v0.2.50"},
Jul  2 03:20:00.079         {"version": "v0.2.51"},
Jul  2 03:20:00.079         {"version": "v0.2.52"},
Jul  2 03:20:00.079         {"version": "v0.2.53"},
Jul  2 03:20:00.079         {"version": "v0.2.54"},
Jul  2 03:20:00.079         {"version": "v0.2.55"},
Jul  2 03:20:00.079         {"version": "v0.2.56"},
Jul  2 03:20:00.079         {"version": "v0.2.57"},
Jul  2 03:20:00.079         {"version": "v0.2.58"},
Jul  2 03:20:00.079         {"version": "v0.2.59"},
Jul  2 03:20:00.079         {"version": "v0.2.60"},
Jul  2 03:20:00.079         {"version": "v0.2.61"},
Jul  2 03:20:00.079         {"version": "v0.2.62"},
Jul  2 03:20:00.079         {"version": "v0.2.63"},
Jul  2 03:20:00.079         {"version": "v0.2.64"},
Jul  2 03:20:00.079         {"version": "v0.2.65"},
Jul  2 03:20:00.079         {"version": "v0.2.66"},
Jul  2 03:20:00.079         {"version": "v0.2.67"},
Jul  2 03:20:00.079         {"version": "v0.2.68"},
Jul  2 03:20:00.079         {"version": "v0.2.69"},
Jul  2 03:20:00.079         {"version": "v0.2.70"},
Jul  2 03:20:00.079         {"version": "v0.2.71"},
Jul  2 03:20:00.079         {"version": "v0.2.72"},
Jul  2 03:20:00.079         {"version": "v0.2.73"},
Jul  2 03:20:00.079         {"version": "v0.2.74"},
Jul  2 03:20:00.079         {"version": "v0.2.75"},
Jul  2 03:20:00.079         {"version": "v0.2.76"},
Jul  2 03:20:00.079         {"version": "v0.2.77"},
Jul  2 03:20:00.079         {"version": "v0.2.78"},
Jul  2 03:20:00.079         {"version": "v0.2.79"},
Jul  2 03:20:00.079         {"version": "v0.2.80"},
Jul  2 03:20:00.079         {"version": "v0.2.81"},
Jul  2 03:20:00.079         {"version": "v0.2.82"},
Jul  2 03:20:00.079         {"version": "v0.2.83"},
Jul  2 03:20:00.079         {"version": "v0.2.84"},
Jul  2 03:20:00.079         {"version": "v0.2.85"},
Jul  2 03:20:00.079         {"version": "v0.2.86"},
Jul  2 03:20:00.079         {"version": "v0.2.87"},
Jul  2 03:20:00.079         {"version": "v0.2.88"},
Jul  2 03:20:00.079         {"version": "v0.2.89"},
Jul  2 03:20:00.079         {"version": "v0.2.90"},
Jul  2 03:20:00.079         {"version": "v0.2.91"},
Jul  2 03:20:00.079         {"version": "v0.2.92"},
Jul  2 03:20:00.079         {"version": "v0.2.93"},
Jul  2 03:20:00.079         {"version": "v0.2.94"},
Jul  2 03:20:00.079         {"version": "v0.2.95"},
Jul  2 03:20:00.079         {"version": "v0.2.96"},
Jul  2 03:20:00.079         {"version": "v0.2.97"}
Jul  2 03:20:00.079       ],
Jul  2 03:20:00.079       "filteredReleases": [{"version": "v0.2.36"}]

In another case, there were 340 versions, and the 168th was picked.

@mxey
Copy link
Contributor

mxey commented Jul 2, 2024

I also went spelunking through Renovate's recent changes and found two things of note:

Again, I don't know if either of these is relevant, but I thought I'd share them, just in case.

It does not explain why this only happens on some Renovate runs. Maybe sometimes the container registry responds with the tags in a different order than the other runs? The response size would still be the same.

@rarkins
Copy link
Collaborator Author

rarkins commented Jul 2, 2024

Interesting. I actually just modified the log message in #29978 to remove the full allVersions as I thought it could be too long/annoying. Glad you spotted that quirk first.

@MarcWort
Copy link

MarcWort commented Jul 5, 2024

Since no one has posted it yet, here is the new log message. Note that currentVersion is undefined. Could this related?

Jul  3 07:39:27.128  WARN: Unexpected downgrade detected: skipping (repository=our/repo)
Jul  3 07:39:27.128        "packageName": "docker-dev-registry.example.com/docker-base/java-stack/jdk",
Jul  3 07:39:27.128        "currentValue": "v3.9.39-corretto11",
Jul  3 07:39:27.128        "compareValue": "v3.9.39-corretto11",
Jul  3 07:39:27.128        "currentVersion": undefined,
Jul  3 07:39:27.128        "update": {
Jul  3 07:39:27.128          "bucket": "minor",
Jul  3 07:39:27.128          "newVersion": "v3.8.0-corretto11",
Jul  3 07:39:27.128          "newValue": "v3.8.0-corretto11",
Jul  3 07:39:27.128          "newMajor": 3,
Jul  3 07:39:27.128          "newMinor": 8,
Jul  3 07:39:27.128          "newPatch": 0,
Jul  3 07:39:27.128          "updateType": "patch"
Jul  3 07:39:27.128        },
Jul  3 07:39:27.128        "allVersionsLength": 1018,
Jul  3 07:39:27.128        "filteredReleaseVersions": ["v3.8.0-corretto11"]

@zharinov
Copy link
Collaborator

zharinov commented Jul 5, 2024

Hi @MarcWort, could you please check whether the following DEBUG message is present or absent for the same run containing the WARN message:

Vulnerability alert found: limiting results to a single release

@MarcWort
Copy link

MarcWort commented Jul 5, 2024

could you please check whether the following DEBUG message is present or absent for the same run containing the WARN message

Sure, this message did not appear on any downgrade. We had 2 downgrades since updating to 37.422.1.

@otbe
Copy link

otbe commented Jul 9, 2024

We experience the opposite direction for the aws-machine-image datasource&versioning for some reason. Since 2 weeks legit updates are autoclosed later as an unexpected downgrade. Might be related to the fix in #29921

@rarkins
Copy link
Collaborator Author

rarkins commented Jul 9, 2024

@otbe can you create a minimal reproduction of that?

@otbe
Copy link

otbe commented Jul 9, 2024

@rarkins sadly it does not work on public Github repos/Github Renovate app because of missing permissions to describe images but this would be an example repo: https://github.com/otbe/aws-downgrade
There should be (right now) one newer version of the AMI available. Thats the public ubuntu image.

Thats the log I get on our infrastructure:

{
  "allVersionsLength": 1,
  "compareValue": "ami-0b6226e8488760b25",
  "currentValue": "ami-0b6226e8488760b25",
  "currentVersion": "ami-0b6226e8488760b25",
  "filteredReleaseVersions": [
    "ami-07652eda1fbad7432"
  ],
  "level": 40,
  "logContext": "9yMOWY0EK5m36QI_9_8b4",
  "msg": "Unexpected downgrade detected: skipping",
  "name": "renovate",
  "packageName": "[{\"Name\":\"owner-id\",\"Values\":[\"099720109477\"]},{\"Name\":\"name\",\"Values\":[\"ubuntu/images/hvm-ssd/ubuntu-jammy-22.04-amd64-server-*\"]}]",
  "repository": "myrepo",
  "span_id": "f6bfdd2aac1111e9",
  "time": "2024-07-09T05:29:25.919Z",
  "trace_flags": "00",
  "trace_id": "d9d0aa6db744af8d714dec3f2da739d7",
  "update": {
    "bucket": "non-major",
    "newDigest": "ubuntu/images/hvm-ssd/ubuntu-jammy-22.04-amd64-server-20240701",
    "newMajor": 1,
    "newMinor": 0,
    "newPatch": 0,
    "newValue": "ami-07652eda1fbad7432",
    "newVersion": "ami-07652eda1fbad7432",
    "releaseTimestamp": "2024-07-01T16:36:28.000Z",
    "updateType": "patch"
  },
  "v": 0
}

@otbe
Copy link

otbe commented Jul 9, 2024

Even after deploying 37.426.4 (with #30105) I get the downgrade warning for aws-machine-image versioning which is strange and no update PRs :/
The fix works, there was still an old version running (sorry :D)

@viceice
Copy link
Member

viceice commented Jul 23, 2024

Saw it on our helm chart repo for renovate image

WARN: Unexpected downgrade detected: skipping
{
  "packageName": "ghcr.io/renovatebot/renovate"
  "currentValue": "37.440.0"
  "compareValue": "37.440.0"
  "currentVersion": "37.440.0"
  "update": {
    "bucket": "latest",
    "newVersion": "37.49.0",
    "newValue": "37.49.0",
    "newMajor": 37,
    "newMinor": 49,
    "newPatch": 0,
    "updateType": "patch"
  }
  "allVersionsLength": 5787
  "filteredReleaseVersions": [
    "37.49.0"
  ]
}

https://developer.mend.io/github/renovatebot/helm-charts/-/job/c23bc731-28f2-4222-89b3-4a44a521c064

@rarkins rarkins added priority-2-high Bugs impacting wide number of users or very important features and removed priority-1-critical A bad bug or work that is holding up a lot of other important features or fixes labels Jul 26, 2024
@rarkins
Copy link
Collaborator Author

rarkins commented Jul 26, 2024

We are still blocked on this - not sure why it's happening. Any suggestions or new observations are appreciated.

@allanlewis
Copy link

I've had this with actions/cache:

WARN: Unexpected downgrade detected: skipping
{
  "packageName": "actions/cache"
  "currentValue": "v4"
  "compareValue": "v4"
  "currentVersion": "v4"
  "update": {
    "bucket": "major",
    "newVersion": "v2",
    "newValue": "v2",
    "newDigest": "8492260343ad570701412c2f464a5877dc76bace",
    "releaseTimestamp": "2023-03-14T07:34:53.000Z",
    "newMajor": 2,
    "newMinor": null,
    "newPatch": null,
    "updateType": "patch"
  }
  "allVersionsLength": 57
  "filteredReleaseVersions": [
    "v2"
  ]
}

@zharinov
Copy link
Collaborator

Hey @allanlewis, thank you for reporting. Could you please tell whether this run also contained Vulnerability alert found: limiting results to a single release DEBUG message or not?

@allanlewis
Copy link

Could you please tell whether this run also contained Vulnerability alert found: limiting results to a single release DEBUG message or not?

Yes, there are 12 of those. I can see that some do reference dependencies with known sec vulns, why would that be relevant?

@zharinov
Copy link
Collaborator

zharinov commented Aug 15, 2024

Yes, there are 12 of those. I can see that some do reference dependencies with known sec vulns, why would that be relevant?

We had the hypothesis of how these lines could be a root cause of the problem: isVulnerabilityAlert flag depends on the GitHub API, and its responses could be flickering. We shrink the array of allowed versions so that it contains just the first element, but the assumption of this array being properly sorted may be false (this logic was introduced quite a long ago). Therefore, once vulnerability alert is false positive, we were picking wrong version and making downgrade PRs, but we close/overwrite it during the next run.

The last edit of the if-statement correlates with the first occurrences of the bug, so we had indirect confirmation, though not 100% sure yet.

@MarcWort
Copy link

Hi @zharinov,
I don't think this is the issue as we see the downgrades on our own self-hosted gitlab registry (see log #29919 (comment) ). I dont think there is a vulnerability notification API. Of course, I do not see any Vulnerability alert found: limiting results to a single release debug messages on a run with WARN: Unexpected downgrade detected: skipping.

@vladimir-avinkin
Copy link

vladimir-avinkin commented Aug 22, 2024

At least one cause of downgrades I believe can be attributed to reusing a branch when the target branch updates.

Also explains the fact that when ticking 'rebase' checkbox, the problem goes away

Here is the discussion with the reproduction included

#29276

Here is another candidate, the maintainer's answer states that it's only relevant to a group with a regex manager, but I'm fairly certain the regex manager isn't needed to reproduce it.

#13363

As a side note, I'm not sure why renovate warns you that the updates might break if you don't pin your dependencies in poetry, but then uses update-lockfile as a rangeStrategy when rangeStragety is set to auto :)

@rarkins rarkins changed the title Renovate raises occasional downgrade PRs WARN: Unexpected downgrade detected: skipping Aug 23, 2024
@rarkins
Copy link
Collaborator Author

rarkins commented Sep 16, 2024

This problem was never explained, and it seems to have disappeared as mysteriously as it came. The Mend App hasn't had this log message in at least 7 days, unfortunately we didn't notice when exactly it stopped in order to identify which release it was.

@rarkins rarkins closed this as completed Sep 16, 2024
@rarkins rarkins unpinned this issue Sep 27, 2024
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Oct 17, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
priority-2-high Bugs impacting wide number of users or very important features type:bug Bug fix of existing functionality
Projects
None yet
Development

No branches or pull requests