add log filename and line number #252

nayihz · 2022-05-06T10:53:07Z

Signed-off-by: cmssczy smartczy@outlook.com

What type of PR is this?

/kind feature

What this PR does / why we need it:

print filename and line number in log

Which issue(s) this PR fixes:

Fixes #

Special notes for your reviewer:

you can see caller in log

{"level":"Level(-2)","ts":"2022-05-06T09:13:43.617296029Z","logger":"controller.workload","caller":"core/workload_controller.go:82","msg":"Reconciling Workload","reconciler group":"kueue.x-k8s.io","reconciler kind":"Workload","name":"pi","namespace":"default","workload":{"name":"pi","namespace":"default"}}

k8s-ci-robot · 2022-05-06T10:53:15Z

Hi @cmssczy. Thanks for your PR.

I'm waiting for a kubernetes-sigs member to verify that this patch is reasonable to test. If it is, they should reply with /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

I understand the commands that are listed here.

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.

denkensk · 2022-05-06T13:59:31Z

/ok-to-test

alculquicondor

/approve

alculquicondor · 2022-05-06T14:45:11Z

main.go

@@ -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"


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

alculquicondor · 2022-05-06T14:45:21Z

main.go

@@ -70,6 +71,7 @@ func main() {

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


What's the skip for?

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.

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.

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

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":""}

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.

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)

Let me restate the question:

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

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")

alculquicondor

/approve
/lgtm

k8s-ci-robot · 2022-05-11T12:26:28Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: alculquicondor, cmssczy

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [alculquicondor]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

alculquicondor · 2022-06-27T18:10:18Z

test/integration/framework/framework.go

+		zap.WriteTo(ginkgo.GinkgoWriter),
+		zap.UseDevMode(true),
+		zap.Level(zapcore.Level(-3)),
+		zap.UseFlagOptions(&opts)),


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

Thanks aldo, I'll have a test then.

k8s-ci-robot added kind/feature Categorizes issue or PR as related to a new feature. cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. labels May 6, 2022

k8s-ci-robot added the needs-ok-to-test Indicates a PR that requires an org member to verify it is safe to test. label May 6, 2022

k8s-ci-robot requested review from ArangoGutierrez and denkensk May 6, 2022 10:53

k8s-ci-robot added the size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. label May 6, 2022

add log filename and line number

1bc605f

nayihz force-pushed the add-source-line-in-log branch from bee7083 to 1bc605f Compare May 6, 2022 11:06

k8s-ci-robot added size/S Denotes a PR that changes 10-29 lines, ignoring generated files. and removed size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels May 6, 2022

k8s-ci-robot added ok-to-test Indicates a non-member PR verified by an org member that is safe to test. and removed needs-ok-to-test Indicates a PR that requires an org member to verify it is safe to test. labels May 6, 2022

alculquicondor reviewed May 6, 2022

View reviewed changes

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label May 6, 2022

alculquicondor reviewed May 11, 2022

View reviewed changes

k8s-ci-robot assigned alculquicondor May 11, 2022

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label May 11, 2022

k8s-ci-robot merged commit 8da3a0f into kubernetes-sigs:main May 11, 2022

nayihz deleted the add-source-line-in-log branch May 11, 2022 12:58

kerthcet mentioned this pull request Jun 27, 2022

Missing detail logs in integration tests #287

Closed

alculquicondor reviewed Jun 27, 2022

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

add log filename and line number #252

add log filename and line number #252

nayihz commented May 6, 2022

k8s-ci-robot commented May 6, 2022

denkensk commented May 6, 2022

alculquicondor left a comment

alculquicondor May 6, 2022

nayihz May 7, 2022

alculquicondor May 6, 2022

nayihz May 7, 2022

alculquicondor May 9, 2022

nayihz May 10, 2022

nayihz May 10, 2022

alculquicondor May 10, 2022

nayihz May 10, 2022

alculquicondor May 10, 2022

nayihz May 11, 2022

alculquicondor left a comment

k8s-ci-robot commented May 11, 2022

alculquicondor Jun 27, 2022

kerthcet Jun 28, 2022

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

add log filename and line number #252

add log filename and line number #252

Conversation

nayihz commented May 6, 2022

What type of PR is this?

What this PR does / why we need it:

Which issue(s) this PR fixes:

Special notes for your reviewer:

k8s-ci-robot commented May 6, 2022

denkensk commented May 6, 2022

alculquicondor left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

alculquicondor left a comment

Choose a reason for hiding this comment

k8s-ci-robot commented May 11, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment