Golang - Updates not complete / not tidied #7217
Comments
|
Edit for clarity: not true. The change is more complete but not as if |
|
We literally run the tidy twice if it's configured, in an attempt to squash this bug. I am still not sure what's causing the problem. FYI the app runs with binaryMode=docker, which may be a contributor. Even when you see a failing PR, you should still see the tidy being run in the logs. I'm a bit confused by your links though, can you help me understand? https://github.com/pomerium/pomerium/pull/1381/files is a merged PR, created by the app. It has a single commit, seems to have the correct line there. Did it work as expected, or did you force push to fix it? The debug logs you produce show the following command being run: Meanwhile https://github.com/travisgroth/renovate-test/pull/2/files is your attempt to reproduce the issue? Is there a problem line there, e.g. the 1.7.0 should be removed? |
Yes I can see that it should be run that way in the debug logs but the results just don't match. I'm honestly not even sure how to arrive at the state we get. Internally, do you manually manipulate the go.mod and then let
The app-created PR is missing a line. The diff should have had 3 lines and looked like this: --- a/go.mod
+++ b/go.mod
@@ -57,7 +57,7 @@ require (
github.com/stretchr/testify v1.6.1
github.com/tomnomnom/linkheader v0.0.0-20180905144013-02ca5825eb80
go.opencensus.io v0.22.4
- go.uber.org/zap v1.15.0
+ go.uber.org/zap v1.16.0
golang.org/x/crypto v0.0.0-20200820211705-5c72a883971a
golang.org/x/net v0.0.0-20200904194848-62affa334b73
golang.org/x/oauth2 v0.0.0-20200902213428-5d25da1a8d43
diff --git a/go.sum b/go.sum
index 5194c126..42ad65a7 100644
--- a/go.sum
+++ b/go.sum
@@ -524,6 +524,8 @@ go.uber.org/tools v0.0.0-20190618225709-2cfd321de3ee/go.mod h1:vJERXedbb3MVM5f9E
go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q=
go.uber.org/zap v1.15.0 h1:ZZCA22JRF2gQE5FoNmhmrf7jeJJ2uhqDUNRYKm8dvmM=
go.uber.org/zap v1.15.0/go.mod h1:Mb2vm2krFEG5DV0W9qcHBYFtp/Wku1cvYaqPsS/WYfc=
+go.uber.org/zap v1.16.0 h1:uFRZXykJGK9lLY4HtgSw44DnIcAM+kRBP7x5m+NpAOM=
+go.uber.org/zap v1.16.0/go.mod h1:MA8QOfq0BHJwdXa996Y4dYkAqRKB8/1K1QMMZVaNZjQ=We fixed it with a manual follow up here https://github.com/pomerium/pomerium/pull/1384/files. All that was run was
Is there a better way to get the last exec output for that branch? I pasted all the logs when filtered for that branch. If Moving to the reproduction repos...I see two different issues. Neither is correct but I'm not sure how we get the results in the PRs, unless there is a different command sequence. Without tidy (https://github.com/travisgroth/renovate-test), the renovate PR winds up with a missing line compared to running just https://github.com/travisgroth/renovate-test/pull/2/files vs run `go get -d ./...`With tidy (https://github.com/travisgroth/renovate-test-tidy), I get the expected 3 expected lines added in the renovate PR, but the old lines in https://github.com/travisgroth/renovate-test-tidy/pull/2/files vs `go get -d ./... && go mod tidy`
See above. Without tidy, I wouldn't expect the 1.7.0 line to be removed but I would expect the 3 line change, not two. Hope that helps. Happy to dig in further or try things as needed. Thanks! |
Yes, that's right. But also note that unlike most other package managers, the BTW we have found that the What version of |
|
Adding some more logs from that particular branch/PR: And then the output: The above is captured all in Any chance GOPATH or CGO_ENABLED cause an issue? |
|
I forked the main repo, rolled back the zap update, and then tried to reproduce locally. The results are confusing. The first time it ran, it failed and printed an Artifact error and added that to the PR The second time, it worked and removed the error comment, also updating the commit: https://github.com/renovate-tests/pomerium/pull/1/files |
Yep, but I've been doing it with upstream
Here's an attempt to run the same setup as you have there. Intentionally leaving out Result (correct++ - adds missing lines from other deps, adds both 2 zap % git diff
diff --git a/go.mod b/go.mod
index ce5e0062..abeba3a5 100644
--- a/go.mod
+++ b/go.mod
@@ -57,7 +57,7 @@ require (
github.com/stretchr/testify v1.6.1
github.com/tomnomnom/linkheader v0.0.0-20180905144013-02ca5825eb80
go.opencensus.io v0.22.4
- go.uber.org/zap v1.15.0
+ go.uber.org/zap v1.16.0
golang.org/x/crypto v0.0.0-20200820211705-5c72a883971a
golang.org/x/net v0.0.0-20200904194848-62affa334b73
golang.org/x/oauth2 v0.0.0-20200902213428-5d25da1a8d43
diff --git a/go.sum b/go.sum
index 5194c126..a5efb33b 100644
--- a/go.sum
+++ b/go.sum
@@ -14,6 +14,7 @@ cloud.google.com/go v0.56.0/go.mod h1:jr7tqZxxKOVYizybht9+26Z/gUq7tiRzu+ACVAMbKV
cloud.google.com/go v0.57.0/go.mod h1:oXiQ6Rzq3RAkkY7N6t3TcE6jE+CIBBbA36lwQ1JyzZs=
cloud.google.com/go v0.62.0 h1:RmDygqvj27Zf3fCQjQRtLyC7KwFcHkeJitcO0OoGOcA=
cloud.google.com/go v0.62.0/go.mod h1:jmCYTdRCQuc1PHIIJ/maLInMho30T/Y0M4hTdTShOYc=
+cloud.google.com/go v0.65.0 h1:Dg9iHVQfrhq82rUNu9ZxUDrJLaxFUe/HlCVaLyRruq8=
cloud.google.com/go v0.65.0/go.mod h1:O5N8zS7uWy9vkA9vayVHs65eM1ubvY4h553ofrNHObY=
cloud.google.com/go/bigquery v1.0.1/go.mod h1:i/xbL2UlR5RvWAURpBYZTtm/cXjCha9lbfbpx4poX+o=
cloud.google.com/go/bigquery v1.3.0/go.mod h1:PjpwJnslEMmckchkHFfq+HTD2DmtT67aNFKH1/VBDHE=
@@ -524,6 +525,8 @@ go.uber.org/tools v0.0.0-20190618225709-2cfd321de3ee/go.mod h1:vJERXedbb3MVM5f9E
go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q=
go.uber.org/zap v1.15.0 h1:ZZCA22JRF2gQE5FoNmhmrf7jeJJ2uhqDUNRYKm8dvmM=
go.uber.org/zap v1.15.0/go.mod h1:Mb2vm2krFEG5DV0W9qcHBYFtp/Wku1cvYaqPsS/WYfc=
+go.uber.org/zap v1.16.0 h1:uFRZXykJGK9lLY4HtgSw44DnIcAM+kRBP7x5m+NpAOM=
+go.uber.org/zap v1.16.0/go.mod h1:MA8QOfq0BHJwdXa996Y4dYkAqRKB8/1K1QMMZVaNZjQ=
golang.org/x/crypto v0.0.0-20170930174604-9419663f5a44/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
golang.org/x/crypto v0.0.0-20181029021203-45a5f77698d3/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
@@ -605,6 +608,7 @@ golang.org/x/net v0.0.0-20200520182314-0ba52f642ac2/go.mod h1:qpuaurCH72eLCgpAm/
golang.org/x/net v0.0.0-20200625001655-4c5254603344/go.mod h1:/O7V0waA8r7cgGh81Ro3o1hOxt32SMVPicZroKQ2sZA=
golang.org/x/net v0.0.0-20200707034311-ab3426394381/go.mod h1:/O7V0waA8r7cgGh81Ro3o1hOxt32SMVPicZroKQ2sZA=
golang.org/x/net v0.0.0-20200822124328-c89045814202/go.mod h1:/O7V0waA8r7cgGh81Ro3o1hOxt32SMVPicZroKQ2sZA=
+golang.org/x/net v0.0.0-20200904194848-62affa334b73 h1:MXfv8rhZWmFeqX3GNZRsd6vOLoaCHjYEX3qkRo3YBUA=
golang.org/x/net v0.0.0-20200904194848-62affa334b73/go.mod h1:/O7V0waA8r7cgGh81Ro3o1hOxt32SMVPicZroKQ2sZA=
golang.org/x/oauth2 v0.0.0-20180821212333-d2e6202438be/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U=
golang.org/x/oauth2 v0.0.0-20190226205417-e64efc72b421/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw=
@@ -612,6 +616,7 @@ golang.org/x/oauth2 v0.0.0-20190604053449-0f29369cfe45/go.mod h1:gOpvHmFTYa4Iltr
golang.org/x/oauth2 v0.0.0-20191202225959-858c2ad4c8b6/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw=
golang.org/x/oauth2 v0.0.0-20200107190931-bf48bf16ab8d h1:TzXSXBo42m9gQenoE3b9BGiEpg5IG2JkU5FkPIawgtw=
golang.org/x/oauth2 v0.0.0-20200107190931-bf48bf16ab8d/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw=
+golang.org/x/oauth2 v0.0.0-20200902213428-5d25da1a8d43 h1:ld7aEMNHoBnnDAX15v1T6z31v8HwR2A9FYOuAhWqkwc=
golang.org/x/oauth2 v0.0.0-20200902213428-5d25da1a8d43/go.mod h1:KelEdhl1UZF7XfJ4dDtk6s++YSgaE7mD/BuKKDLBl4A=
golang.org/x/sync v0.0.0-20180314180146-1d60e4601c6f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
@@ -785,6 +790,7 @@ google.golang.org/genproto v0.0.0-20200618031413-b414f8b61790/go.mod h1:jDfRM7Fc
google.golang.org/genproto v0.0.0-20200729003335-053ba62fc06f/go.mod h1:FWY/as6DDZQgahTzZj3fqbO1CbirC29ZNUFHwi0/+no=
google.golang.org/genproto v0.0.0-20200804131852-c06518451d9c/go.mod h1:FWY/as6DDZQgahTzZj3fqbO1CbirC29ZNUFHwi0/+no=
google.golang.org/genproto v0.0.0-20200825200019-8632dd797987/go.mod h1:FWY/as6DDZQgahTzZj3fqbO1CbirC29ZNUFHwi0/+no=
+google.golang.org/genproto v0.0.0-20200904004341-0bd0a958aa1d h1:92D1fum1bJLKSdr11OJ+54YeCMCGYIygTA7R/YZxH5M=
google.golang.org/genproto v0.0.0-20200904004341-0bd0a958aa1d/go.mod h1:FWY/as6DDZQgahTzZj3fqbO1CbirC29ZNUFHwi0/+no=
google.golang.org/grpc v1.19.0/go.mod h1:mqu4LbDTu4XGKhr4mRzUsmM4RtVoemTSY81AxZiDr8c=
google.golang.org/grpc v1.20.0/go.mod h1:chYK+tFQF0nDUGJgXMSgLCQk3phJEuONr2DCgLDdAQM=To your point about Your test repo looks like it matches - https://github.com/renovate-tests/pomerium/pull/1/files. I don't see why the original PR (and the several before it) didn't have the same change set. Is it somehow possible that several of these running at the same time create issues in the app backend? It looks a bit like we could be sharing a cache from that docker command. I don't know if those go commands are safe for concurrent execution. |
I just realized we wound up with 1 PR left from the set that got opened at approximately the same time this week. Due to issues outside of renovate's control, we had to close it unmerged. However, that means renovate would have retried just that one change in isolation. The final diff looks like a normal run of |
|
Concurrency issues wouldn't explain https://github.com/travisgroth/renovate-test/pull/2/files, unfortunately. |
|
We don't have any concurrency of requests on the workers too, although there are times when a cache can be left over from past repos. One thing I'm suspecting is that we don't detect failure every time if the The next question is why we have regular failures instead of only occasional. We set GOPROXY=direct because it was failing for people with private modules (IIRC) but maybe by doing everything direct then we're getting rate limited somewhere? |
|
I looked into my suspicion but did not have it confirmed. Gomod artifact updating here. Exec routine here. Exec appears to catch any error and throw it again, while the gomod logic catches and returns an artifact error. There should be no scenario where the exec throws yet we still update the |
|
One other thing that's currently unexplained is the
But in this case |
|
Finally for now, my suspicion is that this problem comes somehow from our |
|
@rarkins first, thanks for following up on this.
I agree here. I'm at a loss as to how it happens, and so consistently. It did seem to start at the end of July. Were there any changes related to either go support in renovate or the underlying go version you run that coincide with that timeline? |
|
This change was June 3: #6419 BTW we are making a change right now to use the default GOPROXY settings as per discussion in #7233. I think this should reduce the frequency at which our |
|
Hmm. We saw the problem start here https://github.com/pomerium/pomerium/pull/1184/files. Before #6912 and well after #6419. re: GOPROXY. Interesting. Happy to see what happens after. Edit: when will that change be live? |
|
FYI still inconsistent. https://github.com/pomerium/pomerium/pull/1404/files - missing a line in go.sum. Running I'm unsure what to make of it. |
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
|
Does running go get ./.. also fix 1404? Or is it specifically needing a tidy? I still can't work out from the logs what is going "different" between a successful and a non |
Yes it looks like it does. |
|
This problem is really a brain bender. e.g. we have Can you explain more on what you mean by the following?
And to clarify, you got 3 PRs - 1404, 1405, 1406 - and were two good and one bad? FWIW I'm starting to suspect if somehow the cache affects the result. Therefore want to check which was good/bad and if they all ran on the same machine right after each other. And if 1404 was good and 1405/1406 bad then did you see the same pattern previously with the first PR incomplete and later ones complete? |
rarkins
added
type:bug
Yes, and 1405 actually fixed 1404 when it got rebased, I believe. |
|
Closing this issue as it's a duplicate of issue #6213. |
|
Duplicate of #6213 |
HonkingGoose
added
the
duplicate
What Renovate type, platform and version are you using?
Github App
Describe the bug
In recent updates, we're seeing that updates aren't complete in
go.sum, and it doesn't seem likego mod tidyis being run afterwards either.go.sumfile is not being added with the update.go mod tidynormally resolves this state.go mod tidythe final commit by renovate is still missing said line ingo.sumThis PR is an example: https://github.com/pomerium/pomerium/pull/1381/files
There is a missing line which should be present and would have been restored by
go mod tidy:You can see we resolved this (from a number of updates) in this PR by running
go mod tidy: https://github.com/pomerium/pomerium/pull/1384/files. It is the same type of line missing from each previous renovate PR.The strange thing is that running
go get -u [module]does not leave such a state. I've tried it on go1.14.0,1.14.5, and1.15.1. The resulting changes are what you'd expect:I see similar behavior if I manually replace the version in
go.modand rungo get -d ./...Relevant debug logs
Debug Logs from https://github.com/pomerium/pomerium/pull/1381/files
To Reproduce
gomodTidyset: https://github.com/travisgroth/renovate-testgomodTidynot set: https://github.com/travisgroth/renovate-test-tidyBoth of these repos are one patch behind a viper dependency.
Additional context
Our updates are weekly.
The text was updated successfully, but these errors were encountered: