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.

Sign up for GitHub

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

Jump to bottom

Tests fail with Go1.12rc1 #682

Closed
ianlancetaylor opened this issue Feb 15, 2019 · 1 comment · Fixed by #706
Closed

Tests fail with Go1.12rc1 #682

ianlancetaylor opened this issue Feb 15, 2019 · 1 comment · Fixed by #706

Comments

@ianlancetaylor
Copy link

With Go 1.12rc1 when I run go test go.uber.org/zap I see the following. I think this is due to the changes in https://golang.org/issue/26839.

invalid value "unknown" for flag -level: unrecognized level: "unknown"
Usage of test:
  -level value
    	minimum enabled logging level
--- FAIL: TestNewStdLog (0.00s)
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:101
        	            				common_test.go:40
        	            				global_test.go:98
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/common_test.go:40" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLog
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestNewStdLogAt (0.00s)
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:113
        	            				common_test.go:40
        	            				global_test.go:109
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/common_test.go:40" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAt
        	Messages:   	Unexpected caller annotation.
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:113
        	            				common_test.go:40
        	            				global_test.go:109
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/common_test.go:40" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAt
        	Messages:   	Unexpected caller annotation.
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:113
        	            				common_test.go:40
        	            				global_test.go:109
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/common_test.go:40" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAt
        	Messages:   	Unexpected caller annotation.
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:113
        	            				common_test.go:40
        	            				global_test.go:109
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/common_test.go:40" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAt
        	Messages:   	Unexpected caller annotation.
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:113
        	            				common_test.go:40
        	            				global_test.go:109
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/common_test.go:40" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAt
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestNewStdLogAtPanics (0.00s)
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:126
        	            				common_test.go:40
        	            				global_test.go:122
        	Error:      	Expect "/home/iant/gopath/src/github.com/stretchr/testify/assert/assertions.go:862" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAtPanics
        	Messages:   	Unexpected caller annotation.
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:126
        	            				common_test.go:40
        	            				global_test.go:122
        	Error:      	Expect "/home/iant/gopath/src/github.com/stretchr/testify/assert/assertions.go:862" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAtPanics
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestNewStdLogAtFatal (0.00s)
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:137
        	            				exit.go:53
        	            				global_test.go:133
        	            				common_test.go:40
        	            				global_test.go:132
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/internal/exit/exit.go:53" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestNewStdLogAtFatal
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestRedirectStdLogCaller (0.00s)
    global_test.go:174: 
        	Error Trace:	global_test.go:174
        	            				common_test.go:40
        	            				global_test.go:169
        	Error:      	"/home/iant/gopath/src/go.uber.org/zap/common_test.go" does not contain "global_test.go"
        	Test:       	TestRedirectStdLogCaller
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestRedirectStdLogAtCaller (0.00s)
    global_test.go:213: 
        	Error Trace:	global_test.go:213
        	            				common_test.go:40
        	            				global_test.go:206
        	Error:      	"/home/iant/gopath/src/go.uber.org/zap/common_test.go" does not contain "global_test.go"
        	Test:       	TestRedirectStdLogAtCaller
        	Messages:   	Unexpected caller annotation.
    global_test.go:213: 
        	Error Trace:	global_test.go:213
        	            				common_test.go:40
        	            				global_test.go:206
        	Error:      	"/home/iant/gopath/src/go.uber.org/zap/common_test.go" does not contain "global_test.go"
        	Test:       	TestRedirectStdLogAtCaller
        	Messages:   	Unexpected caller annotation.
    global_test.go:213: 
        	Error Trace:	global_test.go:213
        	            				common_test.go:40
        	            				global_test.go:206
        	Error:      	"/home/iant/gopath/src/go.uber.org/zap/common_test.go" does not contain "global_test.go"
        	Test:       	TestRedirectStdLogAtCaller
        	Messages:   	Unexpected caller annotation.
    global_test.go:213: 
        	Error Trace:	global_test.go:213
        	            				common_test.go:40
        	            				global_test.go:206
        	Error:      	"/home/iant/gopath/src/go.uber.org/zap/common_test.go" does not contain "global_test.go"
        	Test:       	TestRedirectStdLogAtCaller
        	Messages:   	Unexpected caller annotation.
    global_test.go:213: 
        	Error Trace:	global_test.go:213
        	            				common_test.go:40
        	            				global_test.go:206
        	Error:      	"/home/iant/gopath/src/go.uber.org/zap/common_test.go" does not contain "global_test.go"
        	Test:       	TestRedirectStdLogAtCaller
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestRedirectStdLogAtPanics (0.00s)
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:230
        	            				common_test.go:40
        	            				global_test.go:225
        	Error:      	Expect "/home/iant/gopath/src/github.com/stretchr/testify/assert/assertions.go:862" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestRedirectStdLogAtPanics
        	Messages:   	Unexpected caller annotation.
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:230
        	            				common_test.go:40
        	            				global_test.go:225
        	Error:      	Expect "/home/iant/gopath/src/github.com/stretchr/testify/assert/assertions.go:862" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestRedirectStdLogAtPanics
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestRedirectStdLogAtFatal (0.00s)
    global_test.go:274: 
        	Error Trace:	global_test.go:274
        	            				global_test.go:248
        	            				exit.go:53
        	            				global_test.go:243
        	            				common_test.go:40
        	            				global_test.go:242
        	Error:      	Expect "/home/iant/gopath/src/go.uber.org/zap/internal/exit/exit.go:53" to match "go.uber.org/zap/global_test.go:\d+$"
        	Test:       	TestRedirectStdLogAtFatal
        	Messages:   	Unexpected caller annotation.
--- FAIL: TestStacktraceFiltersVendorZap (0.00s)
    require.go:794: 
        	Error Trace:	stacktrace_ext_test.go:106
        	            				stacktrace_ext_test.go:144
        	            				stacktrace_ext_test.go:89
        	Error:      	Received unexpected error:
        	            	stat /home/iant/gopath/src/go.uber.org/zap/vendor/github.com/stretchr/testify: no such file or directory
        	Test:       	TestStacktraceFiltersVendorZap
        	Messages:   	Required dependency (/home/iant/gopath/src/go.uber.org/zap/vendor/github.com/stretchr/testify) not installed in vendor
FAIL
FAIL	go.uber.org/zap	0.196s
@prashantv
Copy link
Collaborator

Zap has a hard-coded constant of call stacks to skip added by the standard logger:
https://github.com/uber-go/zap/blob/v1.9.1/global.go#L34

Reducing this to 1 allows tests to pass in go1.12. To ensure the reasoning made sense, I wrote a simple program,

type writer struct{}

func (writer) Write(bs []byte) (int, error) {
        pc := make([]uintptr, 100)
        n := runtime.Callers(0, pc)
        pc = pc[:n]
        for _, pc := range pc {
                f := runtime.FuncForPC(pc)
                fmt.Println(f.FileLine(pc))
        }
        return 0, nil
}

func main() {
        log.SetOutput(writer{})
        log.Printf("test")
}

When run with Go 1.12, the output is:

/home/prashant/.gimme/versions/go1.12.4.linux.amd64/src/runtime/extern.go 208
/home/prashant/tmp/test.go 13
/home/prashant/.gimme/versions/go1.12.4.linux.amd64/src/log/log.go 172
/home/prashant/.gimme/versions/go1.12.4.linux.amd64/src/log/log.go 303
/home/prashant/tmp/test.go 25
/home/prashant/.gimme/versions/go1.12.4.linux.amd64/src/runtime/proc.go 209
/home/prashant/.gimme/versions/go1.12.4.linux.amd64/src/runtime/asm_amd64.s 1338

When run with Go1.11, the output is:

/home/prashant/.gimme/versions/go1.11.9.linux.amd64/src/runtime/extern.go 218
/home/prashant/tmp/test.go 13
<autogenerated> 1
/home/prashant/.gimme/versions/go1.11.9.linux.amd64/src/log/log.go 172
/home/prashant/.gimme/versions/go1.11.9.linux.amd64/src/log/log.go 296
/home/prashant/tmp/test.go 25
/home/prashant/.gimme/versions/go1.11.9.linux.amd64/src/runtime/proc.go 210
/home/prashant/.gimme/versions/go1.11.9.linux.amd64/src/runtime/asm_amd64.s 1334

The go1.12 is missing <autogenerated> 1, likely because golang/go#25338 was fixed in go1.12.

I'll send out a fix which changes the number of callers to skip by Go version.

prashantv added a commit that referenced this issue Apr 29, 2019
@prashantv
Fix call depth of standard logger in go1.12
2bad81b 
Go1.11 includes a caller for the auto-generated wrapper within the
standard library logger, which is no longer included in Go1.12.

See #682 (comment) for
more details.

Fixes #682.
@prashantv prashantv mentioned this issue Apr 29, 2019
Merged
prashantv added a commit that referenced this issue Apr 29, 2019
@prashantv
Fix call depth of standard logger in go1.12 (#706)
5dab936 
Go1.11 includes a caller for the auto-generated wrapper within the
standard library logger, which is no longer included in Go1.12.

See #682 (comment) for
more details.

Fixes #682.
abhinav added a commit that referenced this issue Nov 9, 2021
@abhinav
Drop support for Go < 1.12
fe04ac4 
Go 1.12 is old enough that we don't need to try to support it.
The files global_go112 and global_prego112 existed to
support different stack depths for the standard library logger,
which changed going from Go 1.11 to 1.12.

This is no longer something we need to support because
per our CI configuration, we only support Go 1.15+.

Ref #682
@abhinav abhinav mentioned this issue Nov 9, 2021
Merged
abhinav added a commit that referenced this issue Nov 9, 2021
@abhinav
Drop support for Go < 1.15 (#1028)
aea2a50 
Per our CI, we don't support versions of Go older than 1.15.

The files global_go112 and global_prego112 existed to
support different stack depths for the standard library logger,
which changed going from Go 1.11 to 1.12 (ref #682).
This is no longer necessary; Go 1.11 is old enough that we don't need
to support it.
cgxxv pushed a commit to cgxxv/zap that referenced this issue Mar 25, 2022
@prashantv
Fix call depth of standard logger in go1.12 (uber-go#706)
9ac0ab4 
Go1.11 includes a caller for the auto-generated wrapper within the
standard library logger, which is no longer included in Go1.12.

See uber-go#682 (comment) for
more details.

Fixes uber-go#682.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix call depth of standard logger in go1.12 uber-go/zap
2 participants
@prashantv @ianlancetaylor