PR's are getting opened that revert a bunch of deps

[jeffwidman]

Seeing something seriously wrong with Dependabot PR's that just got opened in some private repos.

This is for Golang code.

It's trying to bump some basic open source libs such as:

• Bump github.com/spf13/viper from 1.10.0 to 1.10.1
• Bump google.golang.org/grpc from 1.42.0 to 1.43.0

However, the go.mod file changes are modifying a bunch of libraries that are completely unrelated... even worse, they're reverting those versions to really old versions.

The job ids:

• 244841423
• 245085086

[jeffwidman]

Right before this, @dtomcej also spotted an error about out of disk space on job 245009475

Maybe related to the issue mentioned in #4346

Maybe that is causing this? IDK, that seems very weird that this would partially work and not completely blow up...

[dtomcej]

In addition, we are seeing attempts to upgrade to package versions that are higher than the latest, and therefore do not even exist.

[jurre]

Thanks for reporting! We're investigating what's happening

[mctofu]

@jeffwidman are you able to reproduce this with the dry run script on the repo?

[mx-psi]

This may be related to #4322, which also had some random dependencies being changed and where we also saw "out of memory errors" (we haven't experienced this again, but we are seeing "out of memory errors" again in the last days)

[dtomcej]

@mx-psi it is very possible as the repos have large numbers of related dependencies

[jurre]

@dtomcej are you able to reproduce the problem on a public repo? I'm trying to find a way to figure out what's going on

[dtomcej]

@jurre I am currently running the dry_run script against one of the affected repos. Will post the results here when they are ready.

[dtomcej]

Hello @jurre I have compiled some results that hopefully may shed some light on the issue. I ran the dry_run script on my workstation, without any CPU/RAM/Disk limits, and returned the same results! I take this to mean that it is not an issue of resources, as there were no limits in my testing.

Sanitized results are as follows:

[dependabot-core-dev] ~/dependabot-core $ bin/dry-run.rb go_modules private/repository
=> cloning into /home/dependabot/dependabot-core/tmp/private/repository
=> parsing dependency files
=> updating 27 dependencies: (...)

(...)

=== github.com/private/I (0.53.0)
 => checking for updates 8/27
 => latest available version is 0.54.0
 => latest allowed version is 0.54.0
 => requirements to unlock: own
 => requirements update strategy: 
 => updating github.com/private/I from 0.53.0 to 0.54.0
 => handled error whilst updating github.com/private/I: git_dependencies_not_reachable {:"dependency-urls"=>["github.com/private/I v0.54.0\ngo get"]}

=== github.com/private/M (0.38.0)
 => checking for updates 9/27
 => latest available version is 0.38.0
 => latest allowed version is 0.38.0
    (no update needed as it's already up-to-date)

(...)

=== github.com/private/P (0.29.0)
 => checking for updates 10/27
 => latest available version is 0.30.0
 => latest allowed version is 0.30.0
 => requirements to unlock: own
 => requirements update strategy: 
 => updating github.com/private/P from 0.29.0 to 0.30.0

    ± go.mod
    ~~~
    13,15c13,15
    <   github.com/private/I v0.53.0
    <   github.com/private/M v0.38.0
    <   github.com/private/P v0.29.0
    ---
    >   github.com/private/I v0.9.0
    >   github.com/private/M v0.30.0
    >   github.com/private/P v0.30.0
    119c119
    ---

The tool recognizes that module private/M is up to date at v0.38.0 then proceeds to directly downgrade it to v0.30 a few lines later. The same thing happens for private/I, which the tool recognizes needs an upgrade from v0.53.0 to v0.54.0, and then directly proceeds to downgrade it to v0.9.0 a few lines later.

[mctofu]

@dtomcej: Thanks! Something odd is definitely going on but it's great that you can reproduce it. Since we don't have access to this repo would you be able to run these steps that Dependabot would perform in the dev container and see if any of them result in the unexpected changes? If so it would be worth repeating them outside the dev container as well.

1. git clone private/repository & cd into it
2. GOPRIVATE=* go get -d github.com/private/P@v0.30.0
3. GOPRIVATE=* go get -d
4. GOPRIVATE=* go mod tidy
5. GOPRIVATE=* go mod vendor (if vendoring)

Another way to inspect what Dependabot is doing here would be to used the debugger. You could insert a line containing byebug to https://github.com/dependabot/dependabot-core/blob/b78e5d7ca40d6f51aaa41339067533802e161612/go_modules/lib/dependabot/go_modules/file_updater/go_mod_updater.rb#L86 and then run the dry-run script as bin/dry-run.rb go_modules private/repository --dep github.com/private/P. That would allow you to step through what's going on.

[dtomcej]

Hello @mctofu, those goprivate commands worked without any issues, and they correctly updated the required module, and nothing else.

I tried with private/P and private/I, both of which needed updating, and both of them updated independently correctly, only touching the required deps.

[dtomcej]

Could you give me a more detailed prcedure to add byebug to the updater file? I would like to try that route too.

Not sure what would need to be added.

[mctofu]

@dtomcej: I pushed up a branch that adds some debugging statements during the update process that will hopefully guide us to where it's going wrong: https://github.com/dependabot/dependabot-core/compare/mctofu/debug-go-mod-update. If you switch to that branch and redo the dry run we should see some additional output like:

output with debug

``` [dependabot-core-dev] ~/dependabot-core $ bin/dry-run.rb go_modules mctofu/pushgate --dep github.com/aws/aws-lambda-go => cloning into /home/dependabot/dependabot-core/tmp/mctofu/pushgate => parsing dependency files => updating 1 dependencies: github.com/aws/aws-lambda-go === github.com/aws/aws-lambda-go (1.20.0) => checking for updates 1/1 => latest available version is 1.27.1 => latest allowed version is 1.27.1 => requirements to unlock: own => requirements update strategy: => updating github.com/aws/aws-lambda-go from 1.20.0 to 1.27.1 ** original go.mod: module github.com/mctofu/pushgate go 1.14 require ( github.com/aws/aws-lambda-go v1.20.0 github.com/gregdel/pushover v0.0.0-20200416074932-c8ad547caed4 github.com/stretchr/testify v1.6.1 ) ** substitute go.mod: module github.com/mctofu/pushgate go 1.14 require ( github.com/aws/aws-lambda-go v1.20.0 github.com/gregdel/pushover v0.0.0-20200416074932-c8ad547caed4 github.com/stretchr/testify v1.6.1 ) ** package: true ** run go get -d github.com/aws/aws-lambda-go@v1.27.1 ** updated dep go.mod: module github.com/mctofu/pushgate go 1.14 require ( github.com/aws/aws-lambda-go v1.27.1 github.com/gregdel/pushover v0.0.0-20200416074932-c8ad547caed4 github.com/stretchr/testify v1.6.1 ) ** package: true ** run go get -d ** updated go.mod: module github.com/mctofu/pushgate go 1.14 require ( github.com/aws/aws-lambda-go v1.27.1 github.com/gregdel/pushover v0.0.0-20200416074932-c8ad547caed4 github.com/stretchr/testify v1.6.1 ) ** run go mod tidy -e ** tidy go.mod: module github.com/mctofu/pushgate go 1.14 require ( github.com/aws/aws-lambda-go v1.27.1 github.com/gregdel/pushover v0.0.0-20200416074932-c8ad547caed4 github.com/stretchr/testify v1.6.1 ) ** vendor go.mod: module github.com/mctofu/pushgate go 1.14 require ( github.com/aws/aws-lambda-go v1.27.1 github.com/gregdel/pushover v0.0.0-20200416074932-c8ad547caed4 github.com/stretchr/testify v1.6.1 ) ** version adjusted go.mod: module github.com/mctofu/pushgate go 1.14 require ( github.com/aws/aws-lambda-go v1.27.1 github.com/gregdel/pushover v0.0.0-20200416074932-c8ad547caed4 github.com/stretchr/testify v1.6.1 ) ± go.mod ~~~ 6c6 < github.com/aws/aws-lambda-go v1.20.0 --- > github.com/aws/aws-lambda-go v1.27.1 ~~~ ± go.sum ~~~ 2,3c2,3 < github.com/aws/aws-lambda-go v1.20.0 h1:ZSweJx/Hy9BoIDXKBEh16vbHH0t0dehnF8MKpMiOWc0= < github.com/aws/aws-lambda-go v1.20.0/go.mod h1:jJmlefzPfGnckuHdXX7/80O3BvUUi12XOkbv4w9SGLU= --- > github.com/aws/aws-lambda-go v1.27.1 h1:MAH6hbrsktcSr/gGQKLvHeJPeoOoaspJqh+O4g05bpA= > github.com/aws/aws-lambda-go v1.27.1/go.mod h1:jJmlefzPfGnckuHdXX7/80O3BvUUi12XOkbv4w9SGLU= 6d5 < github.com/davecgh/go-spew v1.1.0 h1:ZDRjVQ15GmhC3fiQ8ni8+OwkZQO4DARzQgrnXU1Liz8= 16d14 < github.com/stretchr/objx v0.1.0 h1:4G4v2dO3VZwixGIRoQ5Lfboy6nUhCyYzaqnIAPPhYs4= 23d20 < gopkg.in/yaml.v2 v2.2.2 h1:ZCJp+EgiOT7lHqUV2J862kp8Qj64Jo6az82+3Td9dZw= 25d21 < gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c h1:dUUwHk2QECo/6vqA44rthZ8ie2QXMNeKRTHCNY2nXvo= ~~~ ```

That will be easier than using byebug but if you want to give that a try too you'll add the byebug statement wherever you'd like to start debugging.

        def update_files # rubocop:disable Metrics/AbcSize, Metrics/PerceivedComplexity
          in_repo_path do
            # Map paths in local replace directives to path hashes
            original_go_mod = File.read("go.mod")
            byebug
            puts "** original go.mod:\n#{original_go_mod}"
            original_manifest = parse_manifest
            original_go_sum = File.read("go.sum") if File.exist?("go.sum")

Then when you run the dry-run script you'll get an interactive terminal:

[dependabot-core-dev] ~/dependabot-core $ bin/dry-run.rb go_modules mctofu/pushgate --dep github.com/aws/aws-lambda-go
=> cloning into /home/dependabot/dependabot-core/tmp/mctofu/pushgate
=> parsing dependency files
=> updating 1 dependencies: github.com/aws/aws-lambda-go

=== github.com/aws/aws-lambda-go (1.20.0)
 => checking for updates 1/1
 => latest available version is 1.27.1
 => latest allowed version is 1.27.1
 => requirements to unlock: own
 => requirements update strategy: 
 => updating github.com/aws/aws-lambda-go from 1.20.0 to 1.27.1

[83, 92] in /home/dependabot/dependabot-core/go_modules/lib/dependabot/go_modules/file_updater/go_mod_updater.rb
   83:         def update_files # rubocop:disable Metrics/AbcSize, Metrics/PerceivedComplexity
   84:           in_repo_path do
   85:             # Map paths in local replace directives to path hashes
   86:             original_go_mod = File.read("go.mod")
   87:             byebug
=> 88:             puts "** original go.mod:\n#{original_go_mod}"
   89:             original_manifest = parse_manifest
   90:             original_go_sum = File.read("go.sum") if File.exist?("go.sum")
   91:  
   92: 
(byebug) 

From there you can evaluate statements like

(byebug) File.exist?("go.sum")
true

Or use n to step to the next line, s to step in or c to continue as some basic commands.

[dtomcej]

Hello @mctofu, I think we are getting somewhere:

When using your branch, it appears that the versions get broken after the go get -d github.com/private/P@v0.30.0 step:

[dependabot-core-dev] ~/dependabot-core $ bin/dry-run.rb go_modules private/repository --dep github.com/private/P
=> cloning into /home/dependabot/dependabot-core/tmp/private/repository
=> parsing dependency files
=> updating 1 dependencies: github.com/private/P

=== github.com/private/P (0.29.0)
 => checking for updates 1/1
 => latest available version is 0.30.0
 => latest allowed version is 0.30.0
 => requirements to unlock: own
 => requirements update strategy: 
 => updating github.com/private/P from 0.29.0 to 0.30.0
** original go.mod:
module github.com/private/repository

go 1.17

require (
    (...)
    github.com/private/I v0.53.0
    github.com/private/M v0.38.0
    github.com/private/P v0.29.0
    (...)
)

** substitute go.mod:
module github.com/private/repository

go 1.17

require (
    (...)
    github.com/private/I v0.53.0
    github.com/private/M v0.38.0
    github.com/private/P v0.29.0
    (...)
)

** package: false
** run go get -d github.com/private/P@v0.30.0
** updated dep go.mod:
module github.com/private/repository

go 1.17

require (
    (...)
    github.com/private/I v0.9.0
    github.com/private/M v0.30.0
    github.com/private/P v0.30.0
    (...)
)

** package: false
** run go get -d
** updated go.mod:
module github.com/private/repository

go 1.17

require (
    (...)
    github.com/private/I v0.9.0
    github.com/private/M v0.30.0
    github.com/private/P v0.30.0
    (...)
)

(...)

** version adjusted go.mod:
module github.com/private/repository

go 1.17

require (
    (...)
    github.com/private/I v0.9.0
    github.com/private/M v0.30.0
    github.com/private/P v0.30.0
    (...)
)

    ± go.mod
    ~~~
    13,15c13,15
    <   github.com/private/I v0.53.0
    <   github.com/private/M v0.38.0
    <   github.com/private/P v0.29.0
    ---
    >   github.com/private/I v0.9.0
    >   github.com/private/M v0.30.0
    >   github.com/private/P v0.30.0
    ~~~

    (...)

[mctofu]

Thanks @dtomcej! That definitely narrows it down but is also very strange 🤔!

Because ** package: false is in the output that tells me Dependabot is creating a dummy go file in the working dir before running go get

https://github.com/dependabot/dependabot-core/blob/c5389f68a6c0c8ea52bc151721b9e53be03fa759/go_modules/lib/dependabot/go_modules/file_updater/go_mod_updater.rb#L184

I'm not familiar with why that's necessary but some next steps to try could be:

• Removing that line so the file isn't created
• Redo the manual steps in https://github.com/dependabot/dependabot-core/issues/4536#issuecomment-999170445 but manually create a dummy.go containing package dummypkg and see if that reproduces the issue.

If that doesn't seem to be the culprit the next thing we could try is switching back to an older version of go. That is configured here: https://github.com/dependabot/dependabot-core/blob/c5389f68a6c0c8ea52bc151721b9e53be03fa759/Dockerfile#L170-L171

Some previous versions: https://github.com/dependabot/dependabot-core/commit/50b95a07207fc8ef02b4addeafe7d11d40d45191, https://github.com/dependabot/dependabot-core/commit/1cba38d8b91ecd3a1d6d1c9b5458ffe94dac6db1, https://github.com/dependabot/dependabot-core/commit/093592f524b38d3b0c7fb8b0354bcb5a5167cf52, https://github.com/dependabot/dependabot-core/commit/af35f1bc6f3b95774a679998809ea68f9b631262

After changing it you need to relaunch the dev shell with bin/docker-dev-shell --rebuild and then you'll be able to verify it updated successfully by running go version in the shell.

[dtomcej]

I think I am making more progress here. After fighting with our corp SSO, I was able to get a lot closer to reproducing the issue in a raw format:

On my workstation (outside the dev container), in our repo, this is the output:

% go version
go version go1.17.5 darwin/amd64
% GOPRIVATE=* go get -v -d github.com/private/P@v0.30.0
go get: upgraded github.com/private/P v0.29.0 => v0.30.0
go get: upgraded github.com/spf13/viper v1.10.0 => v1.10.1
go get: upgraded google.golang.org/grpc v1.42.0 => v1.43.0

In the dev container, in our same repo, this is the output:

$ go version
go version go1.17.5 linux/amd64
$ GOPRIVATE=* go get -v -d github.com/private/P@v0.30.0
get "google.golang.org/grpc": found meta tag vcs.metaImport{Prefix:"google.golang.org/grpc", VCS:"git", RepoRoot:"https://github.com/grpc/grpc-go"} at //google.golang.org/grpc?go-get=1
go get: downgraded github.com/private/I v0.53.0 => v0.9.0
go get: downgraded github.com/private/M v0.38.0 => v0.30.0
go get: upgraded github.com/private/P v0.29.0 => v0.30.0
go get: upgraded github.com/spf13/viper v1.10.0 => v1.10.1
go get: upgraded google.golang.org/grpc v1.42.0 => v1.43.0

[mctofu]

@dtomcej: Wow, that's interesting! Curious if you'd get the same results using the golang:1.17.5 docker image.

[dtomcej]

@mctofu Turns out we get the exact identical results with the golang:1.17.5 image as we did with the dependabot dev image, so it doesn't seem to be an issue with dependabot at all :(

[mctofu]

Would you mind trying with older versions of the golang image to determine if this is a problem that's been recently introduced? We may want to roll Dependabot back to an older version temporarily if it's a bug and knowing which version causes it would help track down the issue.

Thanks for your help in debugging this!

[dtomcej]

Hello @mctofu, Have tested with all versions of 1.17, and it does not appear to be related to any of the minor version updates.

It appears that the issue stems from how go handles updating dependencies using go get in combination with go 1.17 lazy module loading, and the go module cache.

Running:

go clean -modcache && \
GOPRIVATE=* go get -v -d github.com/private/P@v0.30.0 && \
GOPRIVATE=* go mod tidy - compat=1.17 && \
git diff go.mod

returns the incorrect versions noted above, whether it is on my local workstation, or in any of the containers.

However:

go clean -modcache && \
GOPRIVATE=* go mod download && \
GOPRIVATE=* go get -v -d github.com/private/P@v0.30.0 && \
GOPRIVATE=* go mod tidy - compat=1.17 && \
git diff go.mod

Returns the correct versions. It appears from what I can tell that the go get -d in the presence of no module cache overwrites and downgrades private/I and private/P despite being direct dependencies, and when the cache is primed, it does not overwrite.

[dtomcej]

I will see if I can open a PR to get a patch working, and test it against our repo for confirmation.

[mctofu]

@dtomcej Did you have any success in determining what the issue was in go get -d? We could add the go mod download step as a workaround but if there is a fix possible to the go tooling that would be preferred.

[dtomcej]

Hello @mctofu unfortunately my tests gave inconsistent results. Since go 1.18 changes this a bit, and is so close, I am waiting to test with 1.18 and see whether that gives my tests more repeatable outcomes.

[janisz]

I faced similar issue. When quota is available again dependabot creates PRs with stale data causing reverts.

https://github.com/stackrox/stackrox/pull/2810#discussion_r953686055

[jeffwidman]

@janisz reading your thread it looks like you're seeing a race/timing issue with PR's being opened right after others are merged... that's totally unrelated to this issue. I suspect you're seeing https://github.com/dependabot/dependabot-core/issues/4603.

[abdulapopoola]

Closing out as stale