kubeadm 883 Updated logging to be consistent. #68455

Klaven · 2018-09-10T04:10:24Z

What this PR does / why we need it:
There was inconsistent logging methods used in kubeadm init using glog, these have been updated to output like the rest of kubeadm.

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 # kubernetes/kubeadm#883

Special notes for your reviewer:
SIG Cluster Lifecycle/kubeadm

Release note:

NONE

Klaven · 2018-09-10T04:13:06Z

/assign @neolit123

neolit123 · 2018-09-10T11:43:12Z

cmd/kubeadm/app/util/system/kernel_validator.go

@@ -78,7 +78,7 @@ func (k *KernelValidator) Validate(spec SysSpec) (error, error) {

 // validateKernelVersion validates the kernel version.
 func (k *KernelValidator) validateKernelVersion(kSpec KernelSpec) error {
-	glog.V(1).Info("Validating kernel version")
+	fmt.Printf("[%s] Validating kernel version\n", k.Name())


might be better to remove this call and the other one [1].

and then also convert this line to use fmt.Printf()
https://github.com/kubernetes/kubernetes/blob/master/cmd/kubeadm/app/util/system/validators.go#L44

neolit123 · 2018-09-10T20:14:20Z

cmd/kubeadm/app/util/system/kernel_validator.go

@@ -93,7 +93,7 @@ func (k *KernelValidator) validateKernelVersion(kSpec KernelSpec) error {

 // validateKernelConfig validates the kernel configurations.
 func (k *KernelValidator) validateKernelConfig(kSpec KernelSpec) error {
-	glog.V(1).Info("Validating kernel config")
+	fmt.Printf("[%s] Validating kernel config\n", k.Name())


just remove this one.

neolit123 · 2018-09-10T12:37:20Z

/kind cleanup

please change the release note:

Updated the output in kubeadm init to be consistent in style...

to:

NONE

we usually add it only for bigger user facing bug fixes and features.

neolit123 · 2018-09-10T13:01:11Z

as in my comment here:
kubernetes/kubeadm#883 (comment)

we need to convert these glog calls to printf / println:

cmd/join.go:329:		glog.Infoln("[join] running pre-flight checks before initializing the new control plane instance")
util/system/validators.go:44:		glog.Infof("Validating %s...", v.Name())

removing the glog.V(1).Info("Validating kernel .... calls seems optional, they seem like duplicates to me.

Klaven · 2018-09-10T13:29:25Z

@neolit123 I fear I am a bit confused. could you please explain a little when and how kubeadm logs? I see extensive use of glog in the kubeadm project (grep "glog." $KUBE_HOME/cmd/kubeadm/* -rnI), but it seems like a lot of those uses are OK. while some are not. I have attempted to understand but feel like I am failing to do so.

I also found these, should these be updated?

grep "glog.Infof" $KUBE_HOME/cmd/kubeadm/* -rnI

./cmd/kubeadm/app/util/version.go:89:			glog.Infof("could not fetch a Kubernetes version from the internet: %v", err)
./cmd/kubeadm/app/util/version.go:94:			glog.Infof("falling back to the local client version: %s", body)
./cmd/kubeadm/app/util/system/validators.go:44:		glog.Infof("Validating %s...", v.Name())

and
grep "glog.V(1).Info" $KUBE_HOME/cmd/kubeadm/* -rnI

./cmd/kubeadm/app/cmd/join.go:542:	glog.V(1).Info("[join] uploading currently used configuration to the cluster")
./cmd/kubeadm/app/cmd/join.go:547:	glog.V(1).Info("[join] marking the master with right label")
./cmd/kubeadm/app/cmd/reset.go:145:	glog.V(1).Info("[reset] removing kubernetes-managed containers")
./cmd/kubeadm/app/util/system/kernel_validator.go:81:	glog.V(1).Info("Validating kernel version")
./cmd/kubeadm/app/util/system/kernel_validator.go:96:	glog.V(1).Info("Validating kernel config")

I also think I understand why you think those are duplicate logs. I would prefer to make those a separate PR as the original request was about updating to not use glog.Info but can make it part of this request if you would like.

neolit123 · 2018-09-10T13:44:09Z

@neolit123 I fear I am a bit confused. could you please explain a little when and how kubeadm logs? I see extensive use of glog in the kubeadm project (grep "glog." $KUBE_HOME/cmd/kubeadm/* -rnI), but it seems like a lot of those uses are OK. while some are not. I have attempted to understand but feel like I am failing to do so.

the confusion is understandable,
we don't want to show glog.Info and glog.Infof calls by default, without special conditions surrounding them and you have to understand the code base.

these two are special cases which can happen in air-gapped scenarios:

./cmd/kubeadm/app/util/version.go:89:			glog.Infof("could not fetch a Kubernetes version from the internet: %v", err)
./cmd/kubeadm/app/util/version.go:94:			glog.Infof("falling back to the local client version: %s", body)

in such cases we show it as a glog entry to also point the time and the line where this was called.

this on the other hand is always shown to the user and it should be fmt.Print...(), because we don't want the extra glog formatting to pollute the output.

./cmd/kubeadm/app/util/system/validators.go:44:		glog.Infof("Validating %s...", v.Name())

grep "glog.V(1).Info" $KUBE_HOME/cmd/kubeadm/* -rnI

note that these have V(1) - verbosity level. please have a look at glog docs to understand how that works.

I also think I understand why you think those are duplicate logs. I would prefer to make those a separate PR as the original request was about updating to not use glog.Info but can make it part of this request if you would like.

please try to consolidate this update in a single PR.
also once the PR has been update please share output from kubeadm init.

thanks

neolit123 · 2018-09-10T13:47:30Z

as a summary:

convert these to fmt.Print* calls.

cmd/join.go:329:		glog.Infoln("[join] running pre-flight checks before initializing the new control plane instance")
util/system/validators.go:44:		glog.Infof("Validating %s...", v.Name())

remove the these as they are duplicates:

glog.V(1).Info("Validating kernel version")
glog.V(1).Info("Validating kernel config")

k8s-ci-robot · 2018-09-10T16:14:19Z

@Klaven: Adding the "do-not-merge/release-note-label-needed" label because no release-note block was detected, please follow our release note process to remove it.

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.

neolit123 · 2018-09-10T20:14:20Z

cmd/kubeadm/app/util/system/kernel_validator.go

@@ -93,7 +93,7 @@ func (k *KernelValidator) validateKernelVersion(kSpec KernelSpec) error {

 // validateKernelConfig validates the kernel configurations.
 func (k *KernelValidator) validateKernelConfig(kSpec KernelSpec) error {
-	glog.V(1).Info("Validating kernel config")
+	fmt.Printf("[%s] Validating kernel config\n", k.Name())


just remove this one.

Klaven · 2018-09-11T16:28:35Z

Attached is what the kubeadm init looks like now with the updates.

neolit123 · 2018-09-11T17:11:23Z

@Klaven
thank your the update and the persistence.
both the diff and the stdout look good to me.

please squash the commits into a single one and force push to your remote branch.

/release-note-none

…beadm init where glog was used and glog and was inconsistent with the rest of kubeadm init logging. Updated logging in join.go and validators.go to use fmt.print style logging for init log messages. removed redundant log message

Klaven · 2018-09-11T20:34:02Z

@neolit123 I have squashed and pushed the commit. Please let me know if there is anything else you would like me to do with this PR.

neolit123 · 2018-09-17T21:19:54Z

sorry for the delay.
too many things.

/ok-to-test

/assign @fabriziopandini @timothysc

timothysc

This doesn't seem like the right approach here. Ideally we want to convert * to use glog not the other way, and anything that is too noisy should just have an increased verbosity.

timothysc · 2018-09-18T01:17:42Z

cmd/kubeadm/app/util/system/kernel_validator.go

@@ -78,7 +78,6 @@ func (k *KernelValidator) Validate(spec SysSpec) (error, error) {

 // validateKernelVersion validates the kernel version.
 func (k *KernelValidator) validateKernelVersion(kSpec KernelSpec) error {
-	glog.V(1).Info("Validating kernel version")


You could just bump they verbosity to debug levels

i think this is just duplicate output,.

timothysc · 2018-09-18T01:18:20Z

cmd/kubeadm/app/cmd/join.go

@@ -331,7 +331,7 @@ func (j *Join) Run(out io.Writer) error {
 		}

 		// run kubeadm init preflight checks for checking all the prequisites
-		glog.Infoln("[join] running pre-flight checks before initializing the new control plane instance")
+		fmt.Printf("[join] running pre-flight checks before initializing the new control plane instance\n")


@Klaven
it should be a fmt.Println instead of fmt.Printf(.....\n). please fix this.

@timothysc
in the case control plane join this glog.Infoln() would introduce the glog formatting with time / FILE, LINE, etc. i think Lucas' original idea was to have the default kubeadm output glog-free.
@chuckha can confirm.

IIRC @chuckha had set a option to disable the glog premable.
Right now I'd like to switch it all to glog and provide uniformity there.

It's too late in the cycle to hit 1.12 w/cleanup work so we'll have to punt until 1.13 and try to provide better clarity on goals. Ideally, we move it all to glog, strip out unnecessary details by default and provide more verbose logs with verbosity levels.

It's impossible to disable glog preamble. What @timothysc is remembering is me changing all debug calls to be glog.V(n) calls and all user output to use fmt.Println/f.

I don't want kubeadm to switch entirely to glog for the user output, it would make parsing the token out of kubeadm init even worse.

The rules for kubeadm:

Does the user need to see it? yes => use fmt.Print no => use glog.V(1).Infoln/Debugln.

Never use glog without using the .V(n) feature.

timothysc

/approve
/lgtm

k8s-ci-robot · 2018-09-26T01:48:50Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: Klaven, timothysc

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:

~~cmd/kubeadm/OWNERS~~ [timothysc]

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

fejta-bot · 2018-09-26T05:00:46Z

/retest
This bot automatically retries jobs that failed/flaked on approved PRs (send feedback to fejta).

Review the full test history for this PR.

Silence the bot with an /lgtm cancel comment for consistent failures.

fejta-bot · 2018-09-26T08:09:47Z

/retest
This bot automatically retries jobs that failed/flaked on approved PRs (send feedback to fejta).

Review the full test history for this PR.

Silence the bot with an /lgtm cancel comment for consistent failures.

k8s-ci-robot added release-note Denotes a PR that will be considered when it comes time to generate release notes. size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Sep 10, 2018

k8s-ci-robot requested review from chuckha and kad September 10, 2018 04:10

k8s-ci-robot assigned neolit123 Sep 10, 2018

Klaven mentioned this pull request Sep 10, 2018

Inconsistent logging during kubeadm init kubernetes/kubeadm#883

Closed

neolit123 reviewed Sep 10, 2018

View reviewed changes

k8s-ci-robot added kind/cleanup Categorizes issue or PR as related to cleaning up code, process, or technical debt. and removed needs-kind Indicates a PR lacks a `kind/foo` label and requires one. labels Sep 10, 2018

k8s-ci-robot added do-not-merge/release-note-label-needed Indicates that a PR should not merge because it's missing one of the release note labels. and removed release-note Denotes a PR that will be considered when it comes time to generate release notes. labels Sep 10, 2018

neolit123 reviewed Sep 10, 2018

View reviewed changes

k8s-ci-robot added release-note-none Denotes a PR that doesn't merit a release note. and removed do-not-merge/release-note-label-needed Indicates that a PR should not merge because it's missing one of the release note labels. labels Sep 11, 2018

Klaven force-pushed the kubeadm_883 branch from b1c6bfc to a5356e5 Compare September 11, 2018 20:31

k8s-ci-robot assigned fabriziopandini and timothysc Sep 17, 2018

k8s-ci-robot removed the needs-ok-to-test Indicates a PR that requires an org member to verify it is safe to test. label Sep 17, 2018

timothysc reviewed Sep 18, 2018

View reviewed changes

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Sep 26, 2018

timothysc approved these changes Sep 26, 2018

View reviewed changes

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Sep 26, 2018

k8s-ci-robot merged commit 8c1fe2e into kubernetes:master Sep 26, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

kubeadm 883 Updated logging to be consistent. #68455

kubeadm 883 Updated logging to be consistent. #68455

Klaven commented Sep 10, 2018 •

edited

Loading

Klaven commented Sep 10, 2018

neolit123 Sep 10, 2018 •

edited

Loading

neolit123 Sep 10, 2018

neolit123 commented Sep 10, 2018 •

edited

Loading

neolit123 commented Sep 10, 2018 •

edited

Loading

Klaven commented Sep 10, 2018

neolit123 commented Sep 10, 2018

neolit123 commented Sep 10, 2018

k8s-ci-robot commented Sep 10, 2018

neolit123 Sep 10, 2018

Klaven commented Sep 11, 2018

neolit123 commented Sep 11, 2018

Klaven commented Sep 11, 2018

neolit123 commented Sep 17, 2018

timothysc left a comment

timothysc Sep 18, 2018

neolit123 Sep 18, 2018

timothysc Sep 18, 2018

neolit123 Sep 18, 2018

timothysc Sep 18, 2018

chuckha Sep 18, 2018

neolit123 Sep 18, 2018

timothysc left a comment

k8s-ci-robot commented Sep 26, 2018

fejta-bot commented Sep 26, 2018

fejta-bot commented Sep 26, 2018

kubeadm 883 Updated logging to be consistent. #68455

kubeadm 883 Updated logging to be consistent. #68455

Conversation

Klaven commented Sep 10, 2018 • edited Loading

Klaven commented Sep 10, 2018

neolit123 Sep 10, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

neolit123 commented Sep 10, 2018 • edited Loading

neolit123 commented Sep 10, 2018 • edited Loading

Klaven commented Sep 10, 2018

neolit123 commented Sep 10, 2018

neolit123 commented Sep 10, 2018

k8s-ci-robot commented Sep 10, 2018

Choose a reason for hiding this comment

Klaven commented Sep 11, 2018

neolit123 commented Sep 11, 2018

Klaven commented Sep 11, 2018

neolit123 commented Sep 17, 2018

timothysc 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

timothysc left a comment

Choose a reason for hiding this comment

k8s-ci-robot commented Sep 26, 2018

fejta-bot commented Sep 26, 2018

fejta-bot commented Sep 26, 2018

Klaven commented Sep 10, 2018 •

edited

Loading

neolit123 Sep 10, 2018 •

edited

Loading

neolit123 commented Sep 10, 2018 •

edited

Loading

neolit123 commented Sep 10, 2018 •

edited

Loading