Duplicate log output from lintersdb

[rittneje]

Thank you for creating the issue!

• Yes, I'm using a binary release within 2 latest major releases. Only such installations are supported.
• Yes, I've searched similar issues on GitHub and didn't find any.
• Yes, I've included all information below (version, config, etc).

Please include the following information:

Version of golangci-lint

$ golangci-lint --version
# paste output here
golangci-lint has version 1.23.6 built from b9eef79 on 2020-02-10T17:54:23Z

Config file

$ cat .golangci.yml
run:
  deadline: 5m
output:
  format: line-number
  print-issued-lines: false
  print-linter-name: true
linters-settings:
  gocritic:
    enabled-checks:
    - assignOp
    - boolExprSimplify
    - captLocal
    - caseOrder
    - commentFormatting
    - commentedOutCode
    - commentedOutImport
    - defaultCaseOrder
    - docStub
    - dupArg
    - dupBranchBody
    - dupSubExpr
    - emptyStringTest
    - nilValReturn
    - sloppyLen
    - sloppyReassign
    - stringXbytes
    - weakCond
    - yodaStyleExpr
    settings:
      captLocal:
        paramsOnly: false
  misspell:
    locale: US
  nakedret:
    max-func-lines: 0
linters:
  disable-all: true
  enable:
  - bodyclose
  - gocritic
  - golint
  - govet
  - ineffassign
  - misspell
  - nakedret
  - prealloc
  - structcheck
  - unconvert
  - varcheck
issues:
  exclude-use-default: false
  exclude-rules:
  - text: "don't use underscores in Go names"
    linters:
    - golint
  max-issues-per-linter: 0
  max-same-issues: 0

Go environment

$ go version && go env
go version go1.13.7 linux/amd64
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH=""
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build647171824=/tmp/go-build -gno-record-gcc-switches"

Verbose output of running

$ golangci-lint run -v
[2020-02-25T13:42:09.927Z] level=info msg="[config_reader] Used config file .golangci.yml"

[2020-02-25T13:42:11.962Z] level=info msg="[lintersdb] Active 11 linters: [bodyclose gocritic golint govet ineffassign misspell nakedret prealloc structcheck unconvert varcheck]"

[2020-02-25T13:42:11.962Z] level=info msg="[lintersdb] Active 11 linters: [bodyclose gocritic golint govet ineffassign misspell nakedret prealloc structcheck unconvert varcheck]"

[2020-02-25T13:43:21.399Z] level=info msg="[loader] Go packages loading at mode 575 (name|types_sizes|compiled_files|deps|exports_file|files|imports) took 1m5.9308419s"

[2020-02-25T13:43:21.399Z] level=info msg="[runner/filename_unadjuster] Pre-built 0 adjustments in 248.9597ms"

[2020-02-25T13:43:43.773Z] level=info msg="[runner/goanalysis_metalinter/goanalysis] analyzers took 28.3219991s with top 10 stages: buildssa: 7.7690042s, golint: 5.688378s, ineffassign: 3.7454135s, unconvert: 2.2726674s, inspect: 1.9061337s, gocritic: 1.8758655s, misspell: 1.2304017s, ctrlflow: 894.4145ms, printf: 821.4756ms, varcheck: 374.8587ms"

[2020-02-25T13:43:43.773Z] level=info msg="[runner] Issues before processing: 5992, after processing: 0"

[2020-02-25T13:43:43.773Z] level=info msg="[runner] Processors filtering stat (out/in): path_prettifier: 5992/5992, cgo: 5992/5992, skip_files: 5992/5992, skip_dirs: 5992/5992, identifier_marker: 244/244, exclude-rules: 0/244, exclude: 244/244, filename_unadjuster: 5992/5992, autogenerated_exclude: 244/5992"

[2020-02-25T13:43:43.773Z] level=info msg="[runner] processing took 42.6277ms with stages: identifier_marker: 27.3386ms, path_prettifier: 9.0606ms, skip_dirs: 2.7972ms, autogenerated_exclude: 2.3142ms, cgo: 522µs, filename_unadjuster: 382.9µs, exclude-rules: 205µs, max_same_issues: 2.2µs, nolint: 800ns, diff: 700ns, skip_files: 600ns, exclude: 600ns, uniq_by_line: 600ns, source_code: 600ns, path_shortener: 500ns, max_per_file_from_linter: 300ns, max_from_linter: 300ns"

[2020-02-25T13:43:43.773Z] level=info msg="[runner] linters took 22.3000085s with stages: goanalysis_metalinter: 22.2572212s"

[2020-02-25T13:43:43.773Z] level=info msg="File cache stats: 269 entries of total size 4.2MiB"

[2020-02-25T13:43:43.773Z] level=info msg="Memory: 894 samples, avg is 141.4MB, max is 607.0MB"

[2020-02-25T13:43:43.773Z] level=info msg="Execution took 1m30.8895994s"

If you look at the output of golangci-lint run -v, you can see that the "Active 11 linters" log appears twice in a row for some reason.

[rittneje]

I believe I have tracked the source of the problem to run.go. Basically, right now it loads the linters twice in a row - once with optimization, and once without.

golangci-lint/pkg/commands/run.go

Lines 286 to 294 in 4958e50

	enabledLinters, err := e.EnabledLintersSet.Get(true)
	if err != nil {
	return nil, err
	}
	enabledOriginalLinters, err := e.EnabledLintersSet.Get(false)
	if err != nil {
	return nil, err
	}

The Get method will then log the set of linters, and since it gets called twice, the log appears twice.

golangci-lint/pkg/lint/lintersdb/enabled_set.go

Lines 79 to 85 in 4958e50

	func (es EnabledSet) Get(optimize bool) ([]*linter.Config, error) {
	if err := es.v.validateEnabledDisabledLintersConfig(&es.cfg.Linters); err != nil {
	return nil, err
	}
	resultLintersSet := es.build(&es.cfg.Linters, es.m.GetAllEnabledByDefaultLinters())
	es.verbosePrintLintersStatus(resultLintersSet)

Would it be possible to change this so that rather than calling Get twice, it can instead just pass the result of Get to some sort of Optimize method? That will prevent the duplicate log from occurring, and it will prevent run.go from doing the exact same work twice.

[ldez]

Fixed by #1477