Kubernetes defaults to using the klog logging library, which is managed by the k8s.io/component-base/logs library and is a forked version of glog. This fork was created because glog had several issues, especially when running in containers, and was not easy to test. As a result, Kubernetes maintains its own version of klog.
In Kubernetes version 1.18, it used version v1.0.0 of klog. In this version, the --add_dir_header option didn’t work as expected. This issue was fixed in https://github.com/kubernetes/klog/pull/101, but it persisted in Kubernetes 1.18. Subsequent minor releases of Kubernetes did not update the klog version.
This article is based on Kubernetes version 1.18.6. Please visit the source code reading repository for more details.
In the kubelet, the main function directly calls k8s.io/component-base/logs’s InitLogs() to initialize the logs and uses defer to execute FlushLogs() when the program exits.
cmd\kubelet\kubelet.go
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
import (
"math/rand"
"os"
"time"
"k8s.io/component-base/logs"
_ "k8s.io/component-base/metrics/prometheus/restclient"
_ "k8s.io/component-base/metrics/prometheus/version" // for version metric registration
"k8s.io/kubernetes/cmd/kubelet/app"
)
func main() {
rand.Seed(time.Now().UnixNano())
command := app.NewKubeletCommand()
logs.InitLogs()
defer logs.FlushLogs()
if err := command.Execute(); err != nil {
os.Exit(1)
}
}
|
This module also loads the klog module, which has its own init() function.
Global variable logFlushFreq registers the command line option --log-flush-frequency, and init() initializes klog.
1
2
3
4
5
6
7
|
const logFlushFreqFlagName = "log-flush-frequency"
var logFlushFreq = pflag.Duration(logFlushFreqFlagName, 5*time.Second, "Maximum number of seconds between log flushes")
func init() {
klog.InitFlags(flag.CommandLine)
}
|
This module sets default values for command line options and uses goroutines for periodic log flushing.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
// init sets up the defaults and runs flushDaemon.
func init() {
logging.stderrThreshold = errorLog // Default stderrThreshold is ERROR.
logging.setVState(0, nil, false)
logging.logDir = ""
logging.logFile = ""
logging.logFileMaxSizeMB = 1800
logging.toStderr = true
logging.alsoToStderr = false
logging.skipHeaders = false
logging.addDirHeader = false
logging.skipLogHeaders = false
go logging.flushDaemon()
}
|
flushDaemon() runs lockAndFlushAll() every 5 seconds.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
|
const flushInterval = 5 * time.Second
// flushDaemon periodically flushes the log file buffers.
func (l *loggingT) flushDaemon() {
for range time.NewTicker(flushInterval).C {
l.lockAndFlushAll()
}
}
// lockAndFlushAll is like flushAll but locks l.mu first.
func (l *loggingT) lockAndFlushAll() {
l.mu.Lock()
l.flushAll()
l.mu.Unlock()
}
// flushAll flushes all the logs and attempts to "sync" their data to disk.
// l.mu is held.
func (l *loggingT) flushAll() {
// Flush from fatal down, in case there's trouble flushing.
for s := fatalLog; s >= infoLog; s-- {
file := l.file[s]
if file != nil {
file.Flush() // ignore error
file.Sync() // ignore error
}
}
}
|
This registers the klog command line options.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
// InitFlags is for explicitly initializing the flags.
func InitFlags(flagset *flag.FlagSet) {
if flagset == nil {
flagset = flag.CommandLine
}
flagset.StringVar(&logging.logDir, "log_dir", logging.logDir, "If non-empty, write log files in this directory")
flagset.StringVar(&logging.logFile, "log_file", logging.logFile, "If non-empty, use this log file")
flagset.Uint64Var(&logging.logFileMaxSizeMB, "log_file_max_size", logging.logFileMaxSizeMB,
"Defines the maximum size a log file can grow to. Unit is megabytes. "+
"If the value is 0, the maximum file size is unlimited.")
flagset.BoolVar(&logging.toStderr, "logtostderr", logging.toStderr, "log to standard error instead of files")
flagset.BoolVar(&logging.alsoToStderr, "alsologtostderr", logging.alsoToStderr, "log to standard error as well as files")
flagset.Var(&logging.verbosity, "v", "number for the log level verbosity")
flagset.BoolVar(&logging.skipHeaders, "add_dir_header", logging.addDirHeader, "If true, adds the file directory to the header")
flagset.BoolVar(&logging.skipHeaders, "skip_headers", logging.skipHeaders, "If true, avoid header prefixes in the log messages")
flagset.BoolVar(&logging.skipLogHeaders, "skip_log_headers", logging.skipLogHeaders, "If true, avoid headers when opening log files")
flagset.Var(&logging.stderrThreshold, "stderrthreshold", "logs at or above this threshold go to stderr")
flagset.Var(&logging.vmodule, "vmodule", "comma-separated list of pattern=N settings for file-filtered logging")
flagset.Var(&logging.traceLocation, "log_backtrace_at", "when logging hits line file:N, emit a stack trace")
}
|
Compatibility with the system log library - if the system’s log library is used to write logs, it is ultimately recorded using klog. It sets the log library to pass the original logs to klog without any processing.
For example, if log.Print is used to record logs, it will ultimately call the Write method of KlogWriter to log the message.
Why is it necessary to be compatible with the system log library?
It might be due to historical reasons, as some external libraries used for logging might rely on the system’s log library.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
// Write implements the io.Writer interface.
func (writer KlogWriter) Write(data []byte) (n int, err error) {
klog.InfoDepth(1, string(data))
return len(data), nil
}
// InitLogs initializes logs the way we want for kubernetes.
func InitLogs() {
// Compatibility with log for logging, but effectively using klog.
log.SetOutput(KlogWriter{})
// Set log output format to empty; log formatting is determined by klog
log.SetFlags(0)
// The default glog flush interval is 5 seconds.
go wait.Forever(klog.Flush, *logFlushFreq)
}
|
klog.Flush() - executes log flushing. Here, it executes the same method lockAndFlushAll() as the goroutine started by the klog initialization above. So, kubelet starts two goroutines to flush logs. This might seem redundant, but it ensures logs are flushed consistently.
1
2
3
4
|
// Flush flushes all pending log I/O.
func Flush() {
logging.lockAndFlushAll()
}
|
4 Registering Klog Command-Line Options Again
When executing addKlogFlags(fs), klog.InitFlag is executed again.
Why is klog.InitFlag executed again?
If you look closely, you’ll notice that when it’s executed again, it uses a newly created flagset - flag.NewFlagSet(os.Args[0], flag.ExitOnError) (not flag.CommandLine). In other words, it re-registers command-line options in this flagset and then adds them to kubelet’s pflagset. The options registered with flag.CommandLine are not used, which can be seen as wasteful.
Based on commit messages, it seems that addKlogFlags was added when klog was upgraded to version 0.3.0 - related pull request. It’s possible that klog was upgraded to version 1.0.0, but the kubelet code wasn’t updated accordingly.
cmd\kubelet\app\options\globalflags.go
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
|
// AddGlobalFlags explicitly registers flags that libraries (glog, verflag, etc.) register
// against the global flagsets from "flag" and "github.com/spf13/pflag".
// We do this in order to prevent unwanted flags from leaking into the Kubelet's flagset.
func AddGlobalFlags(fs *pflag.FlagSet) {
addKlogFlags(fs)
addCadvisorFlags(fs)
addCredentialProviderFlags(fs)
verflag.AddFlags(fs)
logs.AddFlags(fs)
}
// addKlogFlags adds flags from k8s.io/klog
func addKlogFlags(fs *pflag.FlagSet) {
local := flag.NewFlagSet(os.Args[0], flag.ExitOnError)
klog.InitFlags(local)
fs.AddGoFlagSet(local)
}
|
Flushing logs on program exit ensures that logs are not lost.
1
2
3
4
|
// FlushLogs flushes logs immediately.
func FlushLogs() {
klog.Flush()
}
|
The logging aspect of Kubernetes has continuously evolved, and there might be some historical baggage, but ultimately, it works. In Kubernetes version 1.20, klog was upgraded to version 2.4.0, offering better support for structured logging.
This analysis doesn’t delve into the klog source code. Perhaps, it can be analyzed in detail in the future. Kubernetes is indeed vast, and it’s a challenge to explore it thoroughly before it undergoes further changes. 😅
