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

add log filename and line number #252

Merged
merged 1 commit into from
May 11, 2022
Merged

add log filename and line number #252

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
2 changes: 2 additions & 0 deletions main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import (
// to ensure that exec-entrypoint and run can make use of them.
_ "k8s.io/client-go/plugin/pkg/client/auth"

zaplog "go.uber.org/zap"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

just zap

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we have imported "sigs.k8s.io/controller-runtime/pkg/log/zap" before.

"go.uber.org/zap/zapcore"
schedulingv1 "k8s.io/api/scheduling/v1"
"k8s.io/apimachinery/pkg/runtime"
Expand Down Expand Up @@ -70,6 +71,7 @@ func main() {

opts := zap.Options{
TimeEncoder: zapcore.RFC3339NanoTimeEncoder,
ZapOpts: []zaplog.Option{zaplog.AddCaller(), zaplog.AddCallerSkip(-1)},
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What's the skip for?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we cannot get the right caller if we do not add zaplog.AddCallerSkip(-1).
we get some logs like this:
"caller":"controller/controller.go:114","msg":"Job is suspended and workload not yet admitted by a clusterQueue, nothing to do",
In fact this log should be printed at pkg/controller/workload/job/job_controller.go:208.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What about other log lines? For example, the ones coming from the scheduler.

I'm wondering if controller-runtime is increasing the Skip somewhere just when calling Reconcile.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the controller-runtime will add 1 Skip in controller-runtime/pkg/log/zap/zap.go. Maybe we should descrease 1?
there is an issue to track this problem: kubernetes-sigs/controller-runtime#1737

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

logs in scheduler.go:
{"level":"Level(-2)","ts":"2022-05-10T02:37:06.627754573Z","logger":"scheduler","caller":"scheduler/scheduler.go:306","msg":"Workload assumed in the cache","workload":{"name":"sample-job-hw88n","namespace":"default"},"clusterQueue":{"name":"cluster-total"}} {"level":"Level(-3)","ts":"2022-05-10T02:37:06.627876656Z","logger":"scheduler","caller":"scheduler/scheduler.go:137","msg":"Workload evaluated for admission","workload":{"name":"sample-job-hw88n","namespace":"default"},"clusterQueue":{"name":"cluster-total"},"status":"assumed","reason":""}

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are those logs with the -1 you added?

If so, then I'm fine leaving it and then we can remove it once kubernetes-sigs/controller-runtime#1737 is fixed.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are those logs with the -1 you added?

These logs are not added by me. Line number was not correct because I pushed these code based on the old commit(e5fdd9b)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let me restate the question:

Do the logs for scheduler.go file look accurate when using the code in this PR?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes.

kueue/pkg/scheduler/scheduler.go

Lines 303 to 307 in e5fdd9b

if err := s.cache.AssumeWorkload(newWorkload); err != nil {
return err
}
log.V(2).Info("Workload assumed in the cache")

}
opts.BindFlags(flag.CommandLine)
flag.Parse()
Expand Down
13 changes: 10 additions & 3 deletions test/integration/framework/framework.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ import (

"github.com/onsi/ginkgo/v2"
"github.com/onsi/gomega"
zaplog "go.uber.org/zap"
"go.uber.org/zap/zapcore"
batchv1 "k8s.io/api/batch/v1"
corev1 "k8s.io/api/core/v1"
Expand Down Expand Up @@ -58,10 +59,16 @@ type Framework struct {
}

func (f *Framework) Setup() (context.Context, *rest.Config, client.Client) {
logTimeEncodeOpt := func(o *zap.Options) {
o.TimeEncoder = zapcore.RFC3339NanoTimeEncoder
opts := zap.Options{
TimeEncoder: zapcore.RFC3339NanoTimeEncoder,
ZapOpts: []zaplog.Option{zaplog.AddCaller(), zaplog.AddCallerSkip(-1)},
}
ctrl.SetLogger(zap.New(zap.WriteTo(ginkgo.GinkgoWriter), zap.UseDevMode(true), zap.Level(zapcore.Level(-3)), logTimeEncodeOpt))
ctrl.SetLogger(zap.New(
zap.WriteTo(ginkgo.GinkgoWriter),
zap.UseDevMode(true),
zap.Level(zapcore.Level(-3)),
zap.UseFlagOptions(&opts)),
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is probably overriding the level above, @kerthcet. We should set the options as a function.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks aldo, I'll have a test then.

)

ginkgo.By("bootstrapping test environment")
f.testEnv = &envtest.Environment{
Expand Down