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.

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

All tests broken with Go 1.14 beta1 #1096

Closed
eclipseo opened this issue Feb 4, 2020 · 13 comments · Fixed by #1108
Closed

All tests broken with Go 1.14 beta1 #1096

eclipseo opened this issue Feb 4, 2020 · 13 comments · Fixed by #1108
Assignees
Labels

Comments

@eclipseo
Copy link

eclipseo commented Feb 4, 2020

Fedora Rawhide with Go 1.14 beta1

Testing    in: /builddir/build/BUILD/logrus-1.4.2/_build/src
         PATH: /builddir/build/BUILD/logrus-1.4.2/_build/bin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/sbin
       GOPATH: /builddir/build/BUILD/logrus-1.4.2/_build:/usr/share/gocode
  GO111MODULE: off
      command: go test -buildmode pie -compiler gc -ldflags "-X github.com/sirupsen/logrus/version=1.4.2 -extldflags '-Wl,-z,relro -Wl,--as-needed  -Wl,-z,now -specs=/usr/lib/rpm/redhat/redhat-hardened-ld '"
      testing: github.com/sirupsen/logrus
github.com/sirupsen/logrus
{"level":"info","logrus_error":"can not add field \"func\"","msg":"test","time":"2020-02-04T19:25:53Z"}
{"level":"info","msg":"test","str":"str","time":"2020-02-04T19:25:53Z"}
--- FAIL: TestReportCallerWhenConfigured (0.00s)
    logrus_test.go:42: 
        	Error Trace:	logrus_test.go:42
        	            				testutils.go:28
        	            				logrus_test.go:36
        	Error:      	Not equal: 
        	            	expected: "github.com/sirupsen/logrus_test.TestReportCallerWhenConfigured.func3"
        	            	actual  : "github.com/sirupsen/logrus.(*Entry).Info"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-github.com/sirupsen/logrus_test.TestReportCallerWhenConfigured.func3
        	            	+github.com/sirupsen/logrus.(*Entry).Info
        	Test:       	TestReportCallerWhenConfigured
--- FAIL: TestReportCallerHelperDirect (0.00s)
    logrus_test.go:96: 
        	Error Trace:	logrus_test.go:96
        	Error:      	Expect "github.com/sirupsen/logrus.(*Entry).Info" to match "github.com/.*/logrus_test.logSomething"
        	Test:       	TestReportCallerHelperDirect
--- FAIL: TestReportCallerHelperViaPointer (0.00s)
    logrus_test.go:106: 
        	Error Trace:	logrus_test.go:106
        	Error:      	Expect "github.com/sirupsen/logrus.(*Entry).Info" to match "github.com/.*/logrus_test.logSomething"
        	Test:       	TestReportCallerHelperViaPointer
--- FAIL: TestNestedLoggingReportsCorrectCaller (0.00s)
    logrus_test.go:381: 
        	Error Trace:	logrus_test.go:381
        	Error:      	Not equal: 
        	            	expected: "github.com/sirupsen/logrus_test.TestNestedLoggingReportsCorrectCaller"
        	            	actual  : "github.com/sirupsen/logrus.(*Entry).Info"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-github.com/sirupsen/logrus_test.TestNestedLoggingReportsCorrectCaller
        	            	+github.com/sirupsen/logrus.(*Entry).Info
        	Test:       	TestNestedLoggingReportsCorrectCaller
    logrus_test.go:385: 
        	Error Trace:	logrus_test.go:385
        	Error:      	Not equal: 
        	            	expected: "/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/logrus_test.go:373"
        	            	actual  : "/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/entry.go:285"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/logrus_test.go:373
        	            	+/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/entry.go:285
        	Test:       	TestNestedLoggingReportsCorrectCaller
    logrus_test.go:412: 
        	Error Trace:	logrus_test.go:412
        	Error:      	Not equal: 
        	            	expected: "github.com/sirupsen/logrus_test.TestNestedLoggingReportsCorrectCaller"
        	            	actual  : "github.com/sirupsen/logrus.(*Entry).Info"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-github.com/sirupsen/logrus_test.TestNestedLoggingReportsCorrectCaller
        	            	+github.com/sirupsen/logrus.(*Entry).Info
        	Test:       	TestNestedLoggingReportsCorrectCaller
    logrus_test.go:415: 
        	Error Trace:	logrus_test.go:415
        	Error:      	Not equal: 
        	            	expected: "/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/logrus_test.go:399"
        	            	actual  : "/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/entry.go:285"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/logrus_test.go:399
        	            	+/builddir/build/BUILD/logrus-1.4.2/_build/src/github.com/sirupsen/logrus/entry.go:285
        	Test:       	TestNestedLoggingReportsCorrectCaller
time="2020-02-04T19:25:53Z" level=info msg=info
time="2020-02-04T19:25:53Z" level=info msg=info context=clue wow=whale

INFO[0000] test                                          file=file func=func
time="2020-02-04T19:25:53Z" level=info msg=test file=file func=func
--- FAIL: ExampleCustomFormatter (0.00s)
got:
{"file":"logger.go","func":"Log","level":"info","msg":"example of custom format caller"}
want:
{"file":"example_custom_caller_test.go","func":"ExampleCustomFormatter","level":"info","msg":"example of custom format caller"}
FAIL
exit status 1
FAIL	github.com/sirupsen/logrus	0.780s
@markphelps markphelps added the bug label Feb 6, 2020
@dgsb dgsb self-assigned this Feb 11, 2020
@dgsb
Copy link
Collaborator

dgsb commented Feb 11, 2020

do we have a release date for go1.14 already ?
I suggest we wait for its release before fixing things

@ergoz
Copy link

ergoz commented Feb 26, 2020

go 1.14 is already released

@tschaub
Copy link

tschaub commented Feb 26, 2020

I assume this is related to the issue I'm seeing with go 1.14.

When I set logrus.SetReportCaller(true), I see fields like this logged:

{
  "file": "/Users/tschaub/go/pkg/mod/github.com/sirupsen/logrus@v1.4.2/entry.go:285",
  "func": "github.com/sirupsen/logrus.(*Entry).Info"
}

Perhaps @v1.4.2 is causing trouble with the getPackageName function?

Update: I see this reported in #1089 now.

@tietang
Copy link

tietang commented Mar 1, 2020

I see the problem here:
github.com/sirupsen/logrus@v1.4.2/entry.go
line 167:function getCaller

func getCaller() *runtime.Frame {

	// cache this package's fully-qualified name
	callerInitOnce.Do(func() {
		pcs := make([]uintptr, 2)
		_ = runtime.Callers(0, pcs)
		**logrusPackage = getPackageName(runtime.FuncForPC(pcs[1]).Name())**

		// now that we have the cache, we can skip a minimum count of known-logrus functions
		// XXX this is dubious, the number of frames may vary
		minimumCallerDepth = knownLogrusFrames
	})

The variable ’logrusPackage‘’'v value is wrong.
I'm just going to rewrite it as: logrusPackage = "github.com/sirupsen/logrus" , It works.

In addition, it works In debug mode.

@tietang
Copy link

tietang commented Mar 1, 2020

I see the problem here:

logrusPackage = getPackageName(runtime.FuncForPC(pcs[1]).Name())

Modified to:

logrusPackage = getPackageName(runtime.FuncForPC(pcs[0]).Name())

It works.

Go 1.14

@heramerom
Copy link

heramerom commented Mar 2, 2020

// getCaller retrieves the name of the first non-logrus calling function
func getCaller() *runtime.Frame {

	// cache this package's fully-qualified name
	callerInitOnce.Do(func() {
		pcs := make([]uintptr, maximumCallerDepth)
		_ = runtime.Callers(0, pcs)
		// dynamic get the package name and the minimum caller depth will has a mostly compatibility of go version
		for i := 0; i < maximumCallerDepth; i++ {
			funcName := runtime.FuncForPC(pcs[i]).Name()
			if strings.Contains(funcName, "getCaller")  {
				logrusPackage = getPackageName(funcName)
                                 break;
			}
		}
	})

@cirelli94
Copy link
Contributor

cirelli94 commented Mar 9, 2020

I tested @heramerom code and it works for me, with go version go1.14 linux/amd64.

However @heramom, I noticed you do no more:

minimumCallerDepth = knownLogrusFrames

Is it a desired behavior?

@cirelli94
Copy link
Contributor

cirelli94 commented Mar 9, 2020

@dgsb

do we have a release date for go1.14 already ?
I suggest we wait for its release before fixing things

Go 1.14 has been released! https://blog.golang.org/go1.14

@pgbytes
Copy link

pgbytes commented Mar 9, 2020

I see we have the solution. Is someone working on a PR for this issue?

@chibby0ne
Copy link

@panshul007 I see you are primed and eager to help 😄. You are welcome to take a shot at it 🥇 👍

@cirelli94
Copy link
Contributor

cirelli94 commented Mar 9, 2020

@panshul007 @chibby0ne I did it! See #1108

I built and tried my project with my fork with both 1.13 and 1.14 with no issue.

@zhsj
Copy link

zhsj commented Mar 22, 2020

Sorry to bother. But can we have a new tag to address this issue?

@markphelps
Copy link
Collaborator

Done! https://github.com/sirupsen/logrus/releases/tag/v1.5.0

Thank you all!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.