-
Notifications
You must be signed in to change notification settings - Fork 214
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
Add Backtrace APIs to klog #323
Conversation
Welcome @pchan! |
klog.go
Outdated
pc := make([]uintptr, 100) | ||
n := runtime.Callers(mytrace.skip+1, pc) | ||
|
||
if n == 0 { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We need unit tests for this.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can you put the new code into a separate backtrace.go
file? klog.go
is large enough as it is....
You can also squash all changes into a single commit. I'll use the diff between force-pushes to track changes.
Added unit tests for the backtrace APIs. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
See also my earlier comment about moving this code out of klog.go.
I will move the updated code to backtrace.go/backtrace_test.go in the next checkin. |
Latest checkin moves the Backtrace API to its own file. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for all your work on this. However, I still find it hard to see that TestBackTrace really tests for the right behavior. It also doesn't cover several edge cases. May I suggest to use a different approach?
Instead of doing partial tests for some expected lines in the backtrace, let's compare the entire backtrace after removing a few parts that we allow to vary.
Here's an implementation of that:
/*
Copyright 2022 The Kubernetes Authors.
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/
package klog_test
import (
"fmt"
"regexp"
"runtime"
"strings"
"testing"
"k8s.io/klog/v2"
)
// The tests are sensitive to line changes in the following code. Here are some
// lines that can be added or removed to compensate for import statement
// changes.
//
//
//
//
//
//
//
//
// This must be line 40 (first line is 1).
func outer(callback func() interface{}) interface{} {
return inner(callback)
}
func inner(callback func() interface{}) interface{} {
return callback()
}
//
//
//
//
//
//
//
//
//
//
// This must be line 60. Any line number higher than that gets ignored by normalizeBacktrace.
func TestBacktrace(t *testing.T) {
for name, tt := range map[string]struct {
callback func() interface{}
expected string
}{
"simple": {
callback: func() interface{} { return klog.Backtrace() },
expected: `k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
k8s.io/klog/v2_test.inner():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:47
k8s.io/klog/v2_test.outer():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:43
k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
`,
},
"skip0": {
callback: func() interface{} { return klog.Backtrace(klog.BacktraceSkip(0)) },
expected: `k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
k8s.io/klog/v2_test.inner():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:47
k8s.io/klog/v2_test.outer():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:43
k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
`,
},
"skip1": {
callback: func() interface{} { return klog.Backtrace(klog.BacktraceSkip(1)) },
expected: `k8s.io/klog/v2_test.inner():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:47
k8s.io/klog/v2_test.outer():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:43
k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
`,
},
"skip2": {
callback: func() interface{} { return klog.Backtrace(klog.BacktraceSkip(2)) },
expected: `k8s.io/klog/v2_test.outer():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:43
k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
`,
},
"trace1": {
callback: func() interface{} { return klog.Backtrace(klog.BacktraceSize(1)) },
expected: `k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
`,
},
"trace2": {
callback: func() interface{} { return klog.Backtrace(klog.BacktraceSize(2)) },
expected: `k8s.io/klog/v2_test.TestBacktrace.funcX():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:xxx
k8s.io/klog/v2_test.inner():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:47
`,
},
"skip1-trace1": {
callback: func() interface{} { return klog.Backtrace(klog.BacktraceSize(1), klog.BacktraceSkip(1)) },
expected: `k8s.io/klog/v2_test.inner():
/nvme/gopath/src/k8s.io/klog/backtrace_test.go:47
`,
},
} {
t.Run(name, func(t *testing.T) {
backtrace := outer(tt.callback)
actual := normalizeBacktrace(t, backtrace)
if actual != tt.expected {
t.Errorf("Wrong backtrace. Expected:\n%s\nActual:\n%s\n", tt.expected, actual)
}
})
}
}
func normalizeBacktrace(t *testing.T, backtrace interface{}) string {
str := backtrace.(fmt.Stringer).String()
// This matches the stack entry for the testing package:
// testing.tRunner():
// /nvme/gopath/go-1.18.1/src/testing/testing.go:1439
//
// It and all following entries vary and get removed.
end := regexp.MustCompile(`(?m)^testing\.`).FindStringIndex(str)
if end != nil {
str = str[:end[0]]
}
// Remove varying line numbers.
str = regexp.MustCompile(`(?m):([67890][0-9]|[1-9][0-9][0-9])$`).ReplaceAllString(str, ":xxx")
// Remove varying anonymous function numbers.
str = regexp.MustCompile(`\.func[[:digit:]]+`).ReplaceAllString(str, ".funcX")
return str
}
func TestBacktraceAll(t *testing.T) {
_, callerFile, _, _ := runtime.Caller(0)
actual := klog.Backtrace(klog.BacktraceAll(true)).(fmt.Stringer).String()
t.Logf("Backtrace:\n%s\n", actual)
if strings.Contains(actual, callerFile) == false {
t.Errorf("Expected to see %q in trace:\n%s", callerFile, actual)
}
// Pattern: goroutine 7 [running]:
p := regexp.MustCompile("(?m)(^goroutine [0-9]*.\\[.*\\]*:)")
if len(p.FindAllString(actual, -1)) < 2 {
t.Errorf("Expected more than 1 goroutine stack to be printed, got:\n%s", actual)
}
}
If you agree, can you replace your copy of that file and squash everything into one commit?
One problem is we need normalize the full paths too.
In the above case we will have a mismatch based on the path |
You are right. Can you add that? |
I have attempted a simple normalization. Please review. |
Is there anthing pending ? We are planning on getting this done for 1.25 K8s enhancememt so checking to see if we are good to merge. |
/ok-to-test |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please squash into a single commit with a suitable commit message.
@serathius: this is based on my own API proposal, therefore someone else should review it. Can you take a look? |
/approve |
This confused me because it looked like a reference to the non longer existing BacktraceAll stand-alone function. As it stands now, it compares a function ("Backtrace") with an option ("BacktraceAll"). Depending on the option, "Backtrace" uses different mechanisms. A better commit message would be to describe why this is a useful change. |
How about this: The backtrace APIs allows a developer or klog component to embed backtraces in the log entry aiding debugging. |
Scratch the "or klog component" and it looks good to me. |
/assign @serathius |
The backtrace APIs allows a developer to embed backtraces in the log entry aiding debugging.
Updated the commit message. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why does this belong in klog? It seems convenient, at best. Like why not a kdbg
package or something? Like logr itself, this seems simple and generally useful.
Should it go in github/com/go-logr/dbg
? or k8s.io/kdbg
? Or is this just "good enough, leave it alone, Tim" ?
For the same reason that But you are right, in contrast to
|
I'm a little wary of go-logr/logr/dbg - what principle decides where
that stops? I guess "simple utils that help logging" is not so bad.
OTOH, I don't want need to be greedy - it's not so bad here, either.
I'm fine with it, I guess.
…On Mon, Jun 6, 2022 at 12:04 PM Patrick Ohly ***@***.***> wrote:
Why does this belong in klog? It seems convenient, at best.
For the same reason that KObj and KObjSlice were added to klog: to have a single package that provides everything that is needed for Kubernetes logging. So yes, mostly convenience.
But you are right, in contrast to KObjand friends the new helper is useful also outside of Kubernetes code and it shouldn't be needed often in Kubernetes, so a separate import is not a big burden. Do we need a separate repo, though? How about github.com/go-logr/logr/dbg? Just thinking aloud here.
github/com/go-logr/dbg also works. It's easier to set up than a k8s.io repo (regardless whether it is staging or separate). k8s.io/kdbg also feels wrong because the code is complete independent of Kubernetes.
—
Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you were assigned.Message ID: ***@***.***>
|
The backtrace APIs allows a developer to embed backtraces in a log entry aiding debugging. Signed-off-by: Patrick Ohly <patrick.ohly@intel.com> Copied from kubernetes/klog#323
The backtrace APIs allows a developer to embed backtraces in a log entry aiding debugging. Signed-off-by: Patrick Ohly <patrick.ohly@intel.com> Copied from kubernetes/klog#323
The backtrace APIs allows a developer to embed backtraces in a log entry aiding debugging. Signed-off-by: Patrick Ohly <patrick.ohly@intel.com> Copied from kubernetes/klog#323
Same for Let's try that on for size... I created a private https://github.com/go-logr/loghelper and populated it with the code from this PR. I had to make some minor changes to pass the linter settings. @pchan: I don't see how I can grant you access to it, but here's the diff compared to your code:
Are you okay with that? @thockin: shall we go with that? I can also rename the repo to |
I am ok with the change. |
Shouldn't it be |
Talking API:
vs
??
?? Maybe not.
|
All the other go-logr/*r repos (stdr, gologr, zapr) are logger implementations. go-logr/benchmark and the new one aren't. I still prefer go-logr/loghelper.
go-logr/loghelper/dbg makes sense to me. dbg.Backtrace is okay and text completion in an editor with be able to find the option functions.
I went through that with @pchan earlier. I prefer a single Backtrace because it keeps the API smaller. It also may be simpler to switch between more or less details just by changing options, compared to having to switch between different functions.
Works for me. |
OK with the above, I think - push that as a PR on th eloghelper repo and make it public? Should we tag it 1.0.0 or just let it ride for a bit? |
Will do.
It's a brand-new API. Let's give it some more time before we commit to a stable v1 API. |
One more thought: if all code is going to be in sub-packages, then we don't need a (relatively) unique name for the repo. With that in mind, I prefer |
Why not |
That also works.
I had the same thought. But what's the alternative for such code?
As with logr, I'll draw the line at a very strict "only Go standard library" ... and go-logr/logr itself. |
The backtrace APIs allows a developer to embed backtraces in a log entry aiding debugging. Signed-off-by: Patrick Ohly <patrick.ohly@intel.com> Copied from kubernetes/klog#323
The backtrace APIs allows a developer to embed backtraces in a log entry aiding debugging. Signed-off-by: Patrick Ohly <patrick.ohly@intel.com> Copied from kubernetes/klog#323
See https://github.com/go-logr/lib and #328 for a PR that references the new function in a doc comment. /close |
@pohly: Closed this PR. In response to this:
Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. |
What this PR does / why we need it:
This PR adds Backtrace APIs. See #316 for justification.
Which issue(s) this PR fixes (optional, in
fixes #<issue number>(, fixes #<issue_number>, ...)
format, will close the issue(s) when PR gets merged):Fixes #316
Special notes for your reviewer:
This is an experimental code meant as PoC. The code will be formalized once the APIs themselves are approved/frozen.
Please confirm that if this PR changes any image versions, then that's the sole change this PR makes.
This PR changes API.