-
-
Notifications
You must be signed in to change notification settings - Fork 1.4k
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
v1.47.1 much slower #2997
Comments
Hello, is slower than which version? have you tried to disable some linters to detect if it's a specific linter? |
Editing description: slower when compared to v1.46.2 |
Seems to be related to the |
Also seeing this issue on Cluster API. I've managed to pin it down a bit and will continue tomorrow. I'm seeing golangci-lint hang forever on the Cluster API test directory with only revive enabled. When I run revive i.e. installed with |
I have noticed the same with ( |
I ran in verbose mode on the CI container and got funny timings (reporting some stages at more than 1 hour when the whole process took 3-4 min to complete). Apparently, the reports indicates that the most time consuming stage is
|
I bumped my Golang binary to @killianmuldoon ^^^ Update - Need to confirm same for other project codebases (may not be a stable solution) |
We also ran into a similar issue when updating to 1.47.1 |
This works around golangci/golangci-lint#2997 and should unblock/fix our CI. Signed-off-by: Joe Richey <joerichey@google.com>
This works around golangci/golangci-lint#2997 and should unblock/fix our CI. Signed-off-by: Joe Richey <joerichey@google.com>
My initial report was already running go v1.18.4. This is not likely to be a fix. |
Can someone give me a public repo? I tried on several large repos and I don't see any regression (since 1.47.1) |
kubernetes-sigs/cluster-api#6943 is the PR on cluster api with the version bump. You can lint locally using |
I have the impression that several topics are mixed up in this issue. $ git clone git@github.com:google/go-tpm-tools.git
Cloning into 'go-tpm-tools'...
remote: Enumerating objects: 4036, done.
remote: Counting objects: 100% (1369/1369), done.
remote: Compressing objects: 100% (576/576), done.
remote: Total 4036 (delta 965), reused 900 (delta 777), pack-reused 2667
Receiving objects: 100% (4036/4036), 5.09 MiB | 1.05 MiB/s, done.
Resolving deltas: 100% (2569/2569), done.
$ cd go-tpm-tools golangci-lint v1.47.1: $ golangci-lint cache clean
$ golangci-lint run -v
INFO [config_reader] Config search paths: [./ /home/ldez/sources/experimental/go-tpm-tools /home/ldez/sources/experimental /home/ldez/sources /home/ldez /home /]
INFO [lintersdb] Active 10 linters: [deadcode errcheck gosimple govet ineffassign staticcheck structcheck typecheck unused varcheck]
INFO [loader] Go packages loading at mode 575 (exports_file|name|types_sizes|compiled_files|deps|files|imports) took 198.88594ms
INFO [runner/filename_unadjuster] Pre-built 0 adjustments in 4.391003ms
INFO [linters context/goanalysis] analyzers took 4.957592699s with top 10 stages: buildir: 3.739985069s, inspect: 166.423655ms, ctrlflow: 131.604222ms, fact_deprecated: 113.509976ms, printf: 100.298109ms, fact_purity: 77.45876ms, SA5012: 74.873303ms, nilness: 66.932027ms, S1038: 64.738689ms, typedness: 49.584477ms
INFO [runner/max_same_issues] 2/5 issues with text "Error return value of `rand.Read` is not checked" were hidden, use --max-same-issues
INFO [runner/max_same_issues] 2/5 issues with text "Error return value of `rw.Write` is not checked" were hidden, use --max-same-issues
INFO [runner/max_same_issues] 2/5 issues with text "Error return value of `tpm2.FlushContext` is not checked" were hidden, use --max-same-issues
INFO [runner] Issues before processing: 84, after processing: 13
INFO [runner] Processors filtering stat (out/in): path_prettifier: 30/30, identifier_marker: 30/30, nolint: 19/19, uniq_by_line: 19/19, max_per_file_from_linter: 19/19, max_same_issues: 13/19, cgo: 30/84, autogenerated_exclude: 30/30, max_from_linter: 13/13, source_code: 13/13, filename_unadjuster: 30/30, skip_files: 30/30, skip_dirs: 30/30, exclude: 30/30, exclude-rules: 19/30, sort_results: 13/13, diff: 19/19, path_shortener: 13/13, severity-rules: 13/13, path_prefixer: 13/13
INFO [runner] processing took 2.706225ms with stages: nolint: 1.679934ms, identifier_marker: 327.886µs, exclude-rules: 302.95µs, autogenerated_exclude: 161.579µs, path_prettifier: 110.883µs, source_code: 53.428µs, skip_dirs: 30.509µs, max_same_issues: 18.791µs, max_per_file_from_linter: 5.413µs, cgo: 5.171µs, uniq_by_line: 3.357µs, filename_unadjuster: 2.148µs, path_shortener: 1.836µs, max_from_linter: 1.328µs, skip_files: 295ns, severity-rules: 183ns, diff: 181ns, exclude: 180ns, sort_results: 104ns, path_prefixer: 69ns
INFO [runner] linters took 1.385889602s with stages: goanalysis_metalinter: 1.383141792s
...
INFO File cache stats: 6 entries of total size 44.0KiB
INFO Memory: 17 samples, avg is 249.4MB, max is 390.5MB
INFO Execution took 1.592595622s golangci-lint v1.46.2: $ golangci-lint cache clean
$ golangci-lint run -v
INFO [config_reader] Config search paths: [./ /home/ldez/sources/experimental/go-tpm-tools /home/ldez/sources/experimental /home/ldez/sources /home/ldez /home /]
INFO [lintersdb] Active 10 linters: [deadcode errcheck gosimple govet ineffassign staticcheck structcheck typecheck unused varcheck]
INFO [loader] Go packages loading at mode 575 (name|types_sizes|compiled_files|exports_file|imports|deps|files) took 190.215957ms
INFO [runner/filename_unadjuster] Pre-built 0 adjustments in 4.861062ms
INFO [linters context/goanalysis] analyzers took 5.212053984s with top 10 stages: buildir: 3.751526359s, inspect: 197.394946ms, fact_purity: 150.007125ms, nilness: 145.973816ms, printf: 119.64419ms, ctrlflow: 105.88835ms, fact_deprecated: 97.88912ms, S1038: 74.70493ms, SA5012: 70.91756ms, typedness: 61.465859ms
INFO [runner/max_same_issues] 2/5 issues with text "Error return value of `rw.Write` is not checked" were hidden, use --max-same-issues
INFO [runner/max_same_issues] 2/5 issues with text "Error return value of `tpm2.FlushContext` is not checked" were hidden, use --max-same-issues
INFO [runner/max_same_issues] 2/5 issues with text "Error return value of `rand.Read` is not checked" were hidden, use --max-same-issues
INFO [runner] Issues before processing: 84, after processing: 13
INFO [runner] Processors filtering stat (out/in): filename_unadjuster: 30/30, autogenerated_exclude: 30/30, nolint: 19/19, uniq_by_line: 19/19, sort_results: 13/13, max_per_file_from_linter: 19/19, cgo: 30/84, path_prettifier: 30/30, skip_files: 30/30, identifier_marker: 30/30, exclude: 30/30, exclude-rules: 19/30, diff: 19/19, max_same_issues: 13/19, source_code: 13/13, severity-rules: 13/13, skip_dirs: 30/30, max_from_linter: 13/13, path_shortener: 13/13, path_prefixer: 13/13
INFO [runner] processing took 3.181381ms with stages: nolint: 2.202775ms, exclude-rules: 311.524µs, identifier_marker: 250.86µs, autogenerated_exclude: 98.35µs, path_prettifier: 96.1µs, source_code: 86.456µs, max_same_issues: 79.497µs, skip_dirs: 29.493µs, max_per_file_from_linter: 8.223µs, uniq_by_line: 5.339µs, cgo: 4.19µs, path_shortener: 2.475µs, filename_unadjuster: 2.439µs, max_from_linter: 2.321µs, skip_files: 286ns, exclude: 272ns, severity-rules: 239ns, diff: 237ns, sort_results: 214ns, path_prefixer: 91ns
INFO [runner] linters took 1.36998947s with stages: goanalysis_metalinter: 1.366749069s
...
INFO File cache stats: 6 entries of total size 44.0KiB
INFO Memory: 17 samples, avg is 282.5MB, max is 458.8MB
INFO Execution took 1.568420006s Maybe I miss something but there is no major difference. |
This issue is odd - but it's reliably repeatable on the Cluster API repo. As far as I can tell it's a timeout that seems to be caused by revive as used through golangci-lint - we're getting timeouts in all of our CI runs and the same thing is happening locally with golangci-lint 1.47+ Interestingly I don't seem to be able to replicate this when running a debug version of golangci-lint locally, still trying to figure out what the delta is between the |
I'm able to get, locally, the slow behavior with the cluster-api repo, thank you @killianmuldoon |
@killianmuldoon can you try to replace the GitHub Action with something like that:
|
The issue is occurring in our |
Just for sharing information: $ git clone git@github.com:kubernetes-sigs/cluster-api.git
Cloning into 'cluster-api'...
remote: Enumerating objects: 135542, done.
remote: Counting objects: 100% (53/53), done.
remote: Compressing objects: 100% (41/41), done.
remote: Total 135542 (delta 32), reused 12 (delta 12), pack-reused 135489
Receiving objects: 100% (135542/135542), 178.40 MiB | 9.79 MiB/s, done.
Resolving deltas: 100% (79150/79150), done.
$ cd cluster-api golangci-lint v1.47.1: $ golangci-lint cache clean
$ golangci-lint run -v
INFO [config_reader] Config search paths: [./ /home/ldez/sources/experimental/cluster-api /home/ldez/sources/experimental /home/ldez/sources /home/ldez /home /]
INFO [config_reader] Used config file .golangci.yml
INFO [lintersdb] Active 40 linters: [asciicheck bodyclose containedctx deadcode depguard dogsled errcheck exportloopref gci goconst gocritic godot gofmt goimports goprintffuncname gosec gosimple govet ifshort importas ineffassign misspell nakedret nilerr noctx nolintlint prealloc predeclared revive rowserrcheck staticcheck structcheck stylecheck thelper typecheck unconvert unparam unused varcheck whitespace]
INFO [loader] Using build tags: [tools e2e]
INFO [loader] Go packages loading at mode 575 (name|types_sizes|deps|files|imports|compiled_files|exports_file) took 967.666356ms
INFO [runner/filename_unadjuster] Pre-built 0 adjustments in 31.32843ms
INFO [linters context/goanalysis] analyzers took 1h11m20.106801116s with top 10 stages: the_only_name: 46m18.370535329s, gocritic: 10m13.526804391s, buildir: 4m24.443847296s, buildssa: 1m35.205753478s, goimports: 43.818896715s, gosec: 32.494367742s, gofmt: 22.650936228s, misspell: 20.030936844s, unparam: 20.000190273s, nilness: 19.795093241s
INFO [runner] Issues before processing: 1727, after processing: 5
INFO [runner] Processors filtering stat (out/in): filename_unadjuster: 1727/1727, max_same_issues: 5/5, path_shortener: 5/5, diff: 5/5, path_prettifier: 1727/1727, skip_files: 764/1727, exclude: 764/764, exclude-rules: 99/764, nolint: 5/99, source_code: 5/5, severity-rules: 5/5, sort_results: 5/5, cgo: 1727/1727, autogenerated_exclude: 764/764, identifier_marker: 764/764, uniq_by_line: 5/5, max_from_linter: 5/5, skip_dirs: 764/764, max_per_file_from_linter: 5/5, path_prefixer: 5/5
INFO [runner] processing took 64.641348ms with stages: exclude-rules: 26.253076ms, nolint: 17.926299ms, identifier_marker: 14.472492ms, path_prettifier: 2.607327ms, autogenerated_exclude: 1.982401ms, skip_dirs: 647.88µs, skip_files: 512.75µs, cgo: 103.641µs, filename_unadjuster: 75.721µs, source_code: 51.607µs, uniq_by_line: 3.022µs, path_shortener: 1.99µs, max_same_issues: 1.072µs, max_per_file_from_linter: 684ns, diff: 342ns, exclude: 328ns, sort_results: 248ns, severity-rules: 215ns, max_from_linter: 164ns, path_prefixer: 89ns
INFO [runner] linters took 3m28.886296989s with stages: goanalysis_metalinter: 3m28.821575629s
...
INFO File cache stats: 898 entries of total size 7.4MiB
INFO Memory: 2011 samples, avg is 4903.5MB, max is 6119.1MB
INFO Execution took 3m29.890013192s golangci-lint v1.46.2: $ golangci-lint cache clean
$ golangci-lint run -v
INFO [config_reader] Config search paths: [./ /home/ldez/sources/experimental/cluster-api /home/ldez/sources/experimental /home/ldez/sources /home/ldez /home /]
INFO [config_reader] Used config file .golangci.yml
INFO [lintersdb] Active 40 linters: [asciicheck bodyclose containedctx deadcode depguard dogsled errcheck exportloopref gci goconst gocritic godot gofmt goimports goprintffuncname gosec gosimple govet ifshort importas ineffassign misspell nakedret nilerr noctx nolintlint prealloc predeclared revive rowserrcheck staticcheck structcheck stylecheck thelper typecheck unconvert unparam unused varcheck whitespace]
INFO [loader] Using build tags: [tools e2e]
INFO [loader] Go packages loading at mode 575 (deps|exports_file|name|types_sizes|compiled_files|files|imports) took 19.962372597s
INFO [runner/filename_unadjuster] Pre-built 0 adjustments in 43.897165ms
WARN [linters context] gci: `local-prefixes` is deprecated, use `sections` and `prefix(sigs.k8s.io/cluster-api)` instead.
INFO [linters context/goanalysis] analyzers took 19m0.405997153s with top 10 stages: gocritic: 6m52.559034007s, buildir: 2m50.086837664s, buildssa: 41.175554675s, gosec: 37.146391742s, the_only_name: 22.905922009s, commentmap: 22.814538801s, goimports: 22.650897482s, whitespace: 22.026630197s, directives: 19.018096417s, unconvert: 15.96399565s
INFO [runner] Issues before processing: 1758, after processing: 4
INFO [runner] Processors filtering stat (out/in): filename_unadjuster: 1758/1758, path_prettifier: 1758/1758, autogenerated_exclude: 763/763, exclude-rules: 98/763, uniq_by_line: 4/4, diff: 4/4, max_per_file_from_linter: 4/4, max_same_issues: 4/4, path_prefixer: 4/4, exclude: 763/763, max_from_linter: 4/4, severity-rules: 4/4, cgo: 1758/1758, nolint: 4/98, source_code: 4/4, path_shortener: 4/4, skip_files: 763/1758, skip_dirs: 763/763, identifier_marker: 763/763, sort_results: 4/4
INFO [runner] processing took 83.050669ms with stages: exclude-rules: 30.20846ms, nolint: 20.391701ms, identifier_marker: 18.814175ms, path_prettifier: 5.747936ms, autogenerated_exclude: 4.311715ms, skip_files: 1.454245ms, skip_dirs: 1.131697ms, cgo: 483.769µs, filename_unadjuster: 409.379µs, source_code: 82.322µs, max_same_issues: 7.315µs, uniq_by_line: 3.298µs, path_shortener: 2.204µs, max_per_file_from_linter: 723ns, exclude: 461ns, max_from_linter: 386ns, diff: 320ns, severity-rules: 229ns, sort_results: 227ns, path_prefixer: 107ns
INFO [runner] linters took 43.356066225s with stages: goanalysis_metalinter: 43.272881906s
...
INFO File cache stats: 897 entries of total size 7.4MiB
INFO Memory: 562 samples, avg is 2474.4MB, max is 6856.2MB
INFO Execution took 1m3.368828408s |
I can confirm that the issue is with Edit: I think it's an interaction between |
In fact, the problem occurs in another process ( FYI: you have to clean the cache before each run otherwise the cache will be used for the second call. |
This comment was marked as off-topic.
This comment was marked as off-topic.
I think it's related to a change inside the package
Now I will try to reproduce that with the binary of |
I can create a version without the
Question for everybody: is it an acceptable workaround for you? Please add a reaction to this message:
|
I need to speak with the CAPI maintainers to figure out if this is an acceptable workaround - but I've tried this solution over on the PR to CAPI and it's working 🙂. Thanks again for working so quickly on root-causing this issue! |
The revive linter got extremely slow in golangci-lint 1.47.1 causing the CI to time out. Disable for the time being until it is fixed. See: golangci/golangci-lint#2997
The revive linter got extremely slow in golangci-lint 1.47.1 causing the CI to time out. Disable for the time being until it is fixed. See: golangci/golangci-lint#2997
I've noticed this problem too in https://github.com/rclone/rclone - linting has gone from a few seconds to 20 minutes!
I think that would be a great interim measure. 👍 from me :-) |
The proposal has been implemented and shipped into the release v1.47.2 We will follow and help the revive team to find a fix. For a summary of the issue: #2997 (comment) |
New version seems faster, but it produces log spam, this message 230+ times in our case:
|
This should fix some recently seen linter performance issues. Ref: golangci/golangci-lint#2997
This should fix some recently seen linter performance issues. There is some log spam, but it's definitely faster. Ref: golangci/golangci-lint#2997 Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>
@ldez thank you so much for the quick workaround. I can confirm that our CI pipelines now resumed to normal behavior. We'll wait quietly until the root cause can be addressed in revive. |
This should fix some recently seen linter performance issues. There is some log spam, but it's definitely faster. Ref: golangci/golangci-lint#2997 Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>
We're still seeing this issue on |
yes because the fix is not in a release of golangci-lint for now. |
I see, I was under the impression the revive check disabling fixed the issue. Got it, thanks! |
Thanks again for fixing this @ldez. Is there any guideline on how long we might be waiting for a release? We're trying to decide whether to update to 1.48.0 or straight to 1.48.1 |
As we have already merged non-fix PRs, we will not release a v1.48.1. |
Thanks! I think we'll update to 1.48.1 for now, and pick up 1.49.0 as soon as it's released. |
Welcome
Description of the problem
Today, our CI pipelines moved to v1.47.1 and we immediately felt the pain:
linting was suddenly taking about 3x longer, exhausting the resources of the CI VM (2 vCPU, 4GB RAM), even with a very small amount of changes and the "--new-from-rev master" flag. This behavior was consistent and observed on a dozen PRs today, even those with no change in the go code base.
run is slower when compared to v1.46.2, which was our previous version.
Running v1.47.1 from docker image: golangci/golangci-lint:latest-alpine
Extra installations required for alpine:
apk add git openssh-client bash ncurses gcc musl-dev
CLI for linting:
golangci-lint run --timeout 10m --new-from-rev master --build-tags integration
Version of golangci-lint
golangci-lint version running on the CI container.
Configuration file
Go environment
go version running on the CI container.
Verbose output of running
Code example or link to a public repository
The text was updated successfully, but these errors were encountered: