Queue Proxy Probe doesn't include an informative error message

[dprotaso]

What version of Knative?

HEAD

Expected Behavior

When the readiness probe fails the event includes an informative message

Actual Behavior

The probe's logger shouldn't dump logs to stdout as this is reserved for informing the user

Readiness probe failed: {"level":"info","ts":"2020-02-11T14:27:52.903Z","caller":"logging/config.go:108","msg":"Successfully created the logger."}

Steps to Reproduce the Problem

The default logger shouldn't be initialized & used when the probing

serving/cmd/queue/main.go

Lines 350 to 374 in afbd55a

	// Setup the logger.
	logger, _ = pkglogging.NewLogger(env.ServingLoggingConfig, env.ServingLoggingLevel)
	logger = logger.Named("queueproxy")
	defer flush(logger)
	logger = logger.With(
	zap.String(logkey.Key, types.NamespacedName{
	Namespace: env.ServingNamespace,
	Name: env.ServingRevision,
	}.String()),
	zap.String(logkey.Pod, env.ServingPod))
	if err := validateEnv(env); err != nil {
	logger.Fatal(err.Error())
	}
	// If this is set, we run as a standalone binary to probe the queue-proxy.
	if *readinessProbeTimeout >= 0 {
	if err := probeQueueHealthPath(logger, env.QueueServingPort, *readinessProbeTimeout, env); err != nil {
	// used instead of the logger to produce a concise event message
	fmt.Fprintln(os.Stderr, err)
	os.Exit(1)
	}
	os.Exit(0)
	}

[markusthoemmes]

I agree. Let's move that block above again and just use a default log.Fatalf(...) instead of a proper logger for the validateEnv error handling.

/kind good-first-issue
/good-first-issue

[knative-prow-robot]

@markusthoemmes:
This request has been marked as suitable for new contributors.

Please ensure the request meets the requirements listed here.

If this request no longer meets these requirements, the label can be removed
by commenting with the /remove-good-first-issue command.

In response to this:

I agree. Let's move that block above again and just use a default log.Fatalf(...) instead of a proper logger for the validateEnv error handling.

/kind good-first-issue
/good-first-issue

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.

[vagababov]

There's a comment to why it is so. Do we want to ask the authors for why?

[dprotaso]

@vagababov which author you referring to?

[vagababov]

/me rolls up sleeves and opens blame view
recent change points to @nimakaviani but he just relocated the code, which was I think added here
#4148, so @joshrider

[markusthoemmes]

The point is, we want the clear log output that Josh put in in the first place by not using the logger. That was broken by the move of the logic recently. We can just undo that move as described above.

[dprotaso]

Using & initializing the logger while the queue proxy is probing will result in json appearing in the k8s event which isn't user friendly

serving-tests            18m         Warning   Unhealthy                      pod/call-to-public-service-kpshoeih-hhncq-deployment-b8fcb9c46cmhv7           Readiness probe failed: {"level":"info","ts":"2020-02-10T15:38:51.113Z","caller":"logging/config.go:108","msg":"Successfully created the logger."}
{"level":"info","ts":"2020-02-10T15:38:51.113Z","caller":"logging/config.go:109","msg":"Logging level set to debug"}

[vagababov]

eh, I see. IT's the opposite.