Merge pull request #106123 from pohly/log-go-runner-windows

package log runner as part of Kubernetes releases

cluster/gce/util.sh

@@ -885,15 +885,6 @@ function construct-windows-kubelet-flags {
   # Configure kubelet to run as a windows service.
   flags+=" --windows-service=true"
 
-  # TODO(mtaufen): Configure logging for kubelet running as a service. I haven't
-  # been able to figure out how to direct stdout/stderr into log files when
-  # configuring it to run via sc.exe, so we just manually override logging
-  # config here.
-  flags+=" --log-file=${WINDOWS_LOGS_DIR}\kubelet.log"
-  # klog sets this to true internally, so need to override to false so we
-  # actually log to the file
-  flags+=" --logtostderr=false"
-
   # Configure the file path for host dns configuration
   flags+=" --resolv-conf=${WINDOWS_CNI_DIR}\hostdns.conf"
 
@@ -931,16 +922,6 @@ function construct-windows-kubeproxy-flags {
   # Configure kube-proxy to run as a windows service.
   flags+=" --windows-service=true"
 
-  # TODO(mtaufen): Configure logging for kube-proxy running as a service.
-  # I haven't been able to figure out how to direct stdout/stderr into log
-  # files when configuring it to run via sc.exe, so we just manually
-  # override logging config here.
-  flags+=" --log-file=${WINDOWS_LOGS_DIR}\kube-proxy.log"
-
-  # klog sets this to true internally, so need to override to false
-  # so we actually log to the file
-  flags+=" --logtostderr=false"
-
   # Enabling Windows DSR mode unlocks newer network features and reduces
   # port usage for services.
   # https://techcommunity.microsoft.com/t5/networking-blog/direct-server-return-dsr-in-a-nutshell/ba-p/693710

cluster/gce/windows/k8s-node-setup.psm1

@@ -1256,7 +1256,7 @@ function Start-WorkerServices {
         "A kubelet process is already running, don't know what to do"
   }
   Log-Output "Creating kubelet service"
-  & sc.exe create kubelet binPath= "${env:NODE_DIR}\kubelet.exe ${kubelet_args}" start= demand
+  & sc.exe create kubelet binPath= "${env:NODE_DIR}\kube-log-runner.exe -log-file=${env:LOGS_DIR}\kubelet.log ${env:NODE_DIR}\kubelet.exe ${kubelet_args}" start= demand
   & sc.exe failure kubelet reset= 0 actions= restart/10000
   Log-Output "Starting kubelet service"
   & sc.exe start kubelet
@@ -1270,7 +1270,7 @@ function Start-WorkerServices {
         "A kube-proxy process is already running, don't know what to do"
   }
   Log-Output "Creating kube-proxy service"
-  & sc.exe create kube-proxy binPath= "${env:NODE_DIR}\kube-proxy.exe ${kubeproxy_args}" start= demand
+  & sc.exe create kube-proxy binPath= "${env:NODE_DIR}\kube-log-runner.exe -log-file=${env:LOGS_DIR}\kube-proxy.log ${env:NODE_DIR}\kube-proxy.exe ${kubeproxy_args}" start= demand
   & sc.exe failure kube-proxy reset= 0 actions= restart/10000
   Log-Output "Starting kube-proxy service"
   & sc.exe start kube-proxy

hack/lib/golang.sh

@@ -79,6 +79,7 @@ kube::golang::server_targets() {
     cmd/kubelet
     cmd/kubeadm
     cmd/kube-scheduler
+    vendor/k8s.io/component-base/logs/kube-log-runner
     vendor/k8s.io/kube-aggregator
     vendor/k8s.io/apiextensions-apiserver
     cluster/gce/gci/mounter
@@ -128,6 +129,7 @@ kube::golang::node_targets() {
     cmd/kube-proxy
     cmd/kubeadm
     cmd/kubelet
+    vendor/k8s.io/component-base/logs/kube-log-runner
   )
   echo "${targets[@]}"
 }
@@ -334,6 +336,7 @@ readonly KUBE_STATIC_LIBRARIES=(
   kube-controller-manager
   kube-scheduler
   kube-proxy
+  kube-log-runner
   kubeadm
   kubectl
   kubemark

staging/src/k8s.io/component-base/logs/kube-log-runner/README.md

@@ -0,0 +1,66 @@
+# `kube-log-runner` (formerly known as go-runner)
+
+The `kube-log-runner` is a Go based binary that can run commands and redirect stdout/stderr etc.
+
+Why do we need this?
+
+- Some of our images like kube-apiserver used bash output redirection for
+  collecting logs, so we were not able to switch to distroless images directly
+  for these images. The klog's `--log-file` parameter was supposed to fix this
+  problem, but we ran into trouble with that in scalability CI jobs that never
+  could get root caused and fixed. Using this binary worked.
+
+- Windows services don't have a mechanism for redirecting output of a process.
+
+- Nowadays, the `--log-file` parameter is deprecated for Kubernetes components
+  and should not be used anymore. `kube-log-runner` is a direct replacement.
+
+For example instead of running kube-apiserver like this:
+```bash
+"/bin/sh",
+  "-c",
+  "exec kube-apiserver {{params}} --allow-privileged={{pillar['allow_privileged']}} 1>>/var/log/kube-apiserver.log 2>&1"
+```
+
+Or this:
+```bash
+kube-apiserver {{params}} --allow-privileged={{pillar['allow_privileged']}} --log-file=/var/log/kube-apiserver.log --alsologtostderr=false"
+```
+
+We would use `kube-log-runner` like so:
+```bash
+kube-log-runner -log-file=/var/log/kube-apiserver.log --also-stdout=false \
+   kube-apiserver {{params}} --allow-privileged={{pillar['allow_privileged']}}
+```
+
+The kube-log-runner then ensures that we run the
+`/usr/local/bin/kube-apiserver` with the specified parameters and redirect both
+stdout and stderr ONLY to the log file specified. It will always append to the
+log file.
+
+Possible invocations:
+```bash
+# Merge stderr and stdout, write to stdout (same as 2>&1).
+kube-log-runner echo "hello world"
+
+# Redirect both into log file (same as 1>>/tmp/log 2>&1).
+kube-log-runner -log-file=/tmp/log echo "hello world"
+
+# Copy into log file and print to stdout (same as 2>&1 | tee -a /tmp/log).
+kube-log-runner -log-file=/tmp/log -also-stdout echo "hello world"
+
+# Redirect only stdout into log file (same as 1>>/tmp/log).
+kube-log-runner -log-file=/tmp/log -redirect-stderr=false echo "hello world"
+```
+
+# Container base image
+
+The Kubernetes
+[`k8s.gcr.io/build-image/go-runner`](https://console.cloud.google.com/gcr/images/k8s-artifacts-prod/us/build-image/go-runner)
+image wraps the `gcr.io/distroless/static` image and provides `kube-log-runner`
+under its traditional name as `/go-runner`. It gets maintained in
+https://github.com/kubernetes/release/tree/master/images/build/go-runner.
+
+# Prebuilt binary
+
+The Kubernetes release archives contain kube-log-runner.

staging/src/k8s.io/component-base/logs/kube-log-runner/kube-log-runner.go

@@ -0,0 +1,123 @@
+/*
+Copyright 2020 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 main
+
+import (
+	"flag"
+	"fmt"
+	"io"
+	"log"
+	"os"
+	"os/exec"
+	"os/signal"
+	"strings"
+	"syscall"
+)
+
+var (
+	logFilePath    = flag.String("log-file", "", "If non-empty, save stdout to this file")
+	alsoToStdOut   = flag.Bool("also-stdout", false, "useful with log-file, log to standard output as well as the log file")
+	redirectStderr = flag.Bool("redirect-stderr", true, "treat stderr same as stdout")
+)
+
+func main() {
+	flag.Parse()
+
+	if err := configureAndRun(); err != nil {
+		log.Fatal(err)
+	}
+}
+
+func configureAndRun() error {
+	var (
+		outputStream io.Writer = os.Stdout
+		errStream    io.Writer = os.Stderr
+	)
+
+	args := flag.Args()
+	if len(args) == 0 {
+		return fmt.Errorf("not enough arguments to run")
+	}
+
+	if logFilePath != nil && *logFilePath != "" {
+		logFile, err := os.OpenFile(*logFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
+		if err != nil {
+			return fmt.Errorf("failed to create log file %v: %w", *logFilePath, err)
+		}
+		if *alsoToStdOut {
+			outputStream = io.MultiWriter(os.Stdout, logFile)
+		} else {
+			outputStream = logFile
+		}
+	}
+
+	if *redirectStderr {
+		errStream = outputStream
+	}
+
+	exe := args[0]
+	var exeArgs []string
+	if len(args) > 1 {
+		exeArgs = args[1:]
+	}
+	cmd := exec.Command(exe, exeArgs...)
+	cmd.Stdout = outputStream
+	cmd.Stderr = errStream
+
+	log.Printf("Running command:\n%v", cmdInfo(cmd))
+	err := cmd.Start()
+	if err != nil {
+		return fmt.Errorf("starting command: %w", err)
+	}
+
+	// Handle signals and shutdown process gracefully.
+	go setupSigHandler(cmd.Process)
+	if err := cmd.Wait(); err != nil {
+		return fmt.Errorf("running command: %w", err)
+	}
+	return nil
+}
+
+// cmdInfo generates a useful look at what the command is for printing/debug.
+func cmdInfo(cmd *exec.Cmd) string {
+	return fmt.Sprintf(
+		`Command env: (log-file=%v, also-stdout=%v, redirect-stderr=%v)
+Run from directory: %v
+Executable path: %v
+Args (comma-delimited): %v`, *logFilePath, *alsoToStdOut, *redirectStderr,
+		cmd.Dir, cmd.Path, strings.Join(cmd.Args, ","),
+	)
+}
+
+// setupSigHandler will forward any termination signals to the process
+func setupSigHandler(process *os.Process) {
+	// terminationSignals are signals that cause the program to exit in the
+	// supported platforms (linux, darwin, windows).
+	terminationSignals := []os.Signal{syscall.SIGHUP, syscall.SIGINT, syscall.SIGTERM, syscall.SIGQUIT}
+
+	c := make(chan os.Signal, 1)
+	signal.Notify(c, terminationSignals...)
+
+	// Block until a signal is received.
+	log.Println("Now listening for interrupts")
+	s := <-c
+	log.Printf("Got signal: %v. Sending down to process (PID: %v)", s, process.Pid)
+	if err := process.Signal(s); err != nil {
+		log.Fatalf("Failed to signal process: %v", err)
+	}
+	log.Printf("Signalled process %v successfully.", process.Pid)
+}