From ba70c41cce76fcae70867754cdf390501a8cef1b Mon Sep 17 00:00:00 2001 From: Brian Downs Date: Mon, 21 Sep 2020 09:56:03 -0700 Subject: [PATCH] Initial Logging Output Update (#2246) This attempts to update logging statements to make them consistent through out the code base. It also adds additional context to messages where possible, simplifies messages, and updates level where necessary. --- pkg/agent/config/config.go | 4 ++-- pkg/agent/containerd/containerd.go | 1 + pkg/agent/flannel/setup.go | 5 +++-- pkg/agent/proxy/apiproxy.go | 2 +- pkg/agent/run.go | 2 +- pkg/agent/syssetup/setup.go | 6 +++--- pkg/agent/tunnel/tunnel.go | 4 ++-- pkg/cli/agent/agent.go | 2 +- pkg/cli/server/server.go | 5 +++-- pkg/cloudprovider/instances.go | 4 ++-- pkg/cluster/managed.go | 2 +- pkg/deploy/controller.go | 2 +- pkg/etcd/etcd.go | 14 +++++++------- pkg/netutil/iface.go | 2 +- pkg/node/controller.go | 2 +- pkg/rootlessports/controller.go | 2 +- pkg/server/auth.go | 13 ++++++++++--- pkg/server/server.go | 14 +++++++------- 18 files changed, 48 insertions(+), 38 deletions(-) diff --git a/pkg/agent/config/config.go b/pkg/agent/config/config.go index 1487f97bdf..2ab43ccfaf 100644 --- a/pkg/agent/config/config.go +++ b/pkg/agent/config/config.go @@ -39,7 +39,7 @@ func Get(ctx context.Context, agent cmds.Agent, proxy proxy.Proxy) *config.Node for { agentConfig, err := get(&agent, proxy) if err != nil { - logrus.Error(err) + logrus.Errorf("Failed to retrieve agent config: %v", err) select { case <-time.After(5 * time.Second): continue @@ -286,7 +286,7 @@ func locateOrGenerateResolvConf(envInfo *cmds.Agent) string { tmpConf := filepath.Join(os.TempDir(), version.Program+"-resolv.conf") if err := ioutil.WriteFile(tmpConf, []byte("nameserver 8.8.8.8\n"), 0444); err != nil { - logrus.Error(err) + logrus.Errorf("Failed to write %s: %v", tmpConf, err) return "" } return tmpConf diff --git a/pkg/agent/containerd/containerd.go b/pkg/agent/containerd/containerd.go index 11b8cd4b98..d4d152c379 100644 --- a/pkg/agent/containerd/containerd.go +++ b/pkg/agent/containerd/containerd.go @@ -105,6 +105,7 @@ func Run(ctx context.Context, cfg *config.Node) error { case <-time.After(time.Second): } } + logrus.Info("Containerd is now running") return preloadImages(ctx, cfg) } diff --git a/pkg/agent/flannel/setup.go b/pkg/agent/flannel/setup.go index f6bac73cc4..9ed7f12a03 100644 --- a/pkg/agent/flannel/setup.go +++ b/pkg/agent/flannel/setup.go @@ -86,12 +86,13 @@ func Run(ctx context.Context, nodeConfig *config.Node, nodes v1.NodeInterface) e break } if err == nil { - logrus.Infof("waiting for node %s CIDR not assigned yet", nodeName) + logrus.Info("Waiting for node " + nodeName + " CIDR not assigned yet") } else { - logrus.Infof("waiting for node %s: %v", nodeName, err) + logrus.Infof("Waiting for node %s: %v", nodeName, err) } time.Sleep(2 * time.Second) } + logrus.Info("Node CIDR assigned for: " + nodeName) go func() { err := flannel(ctx, nodeConfig.FlannelIface, nodeConfig.FlannelConf, nodeConfig.AgentConfig.KubeConfigKubelet) diff --git a/pkg/agent/proxy/apiproxy.go b/pkg/agent/proxy/apiproxy.go index 5b6d3b8469..e818f2774c 100644 --- a/pkg/agent/proxy/apiproxy.go +++ b/pkg/agent/proxy/apiproxy.go @@ -87,7 +87,7 @@ func (p *proxy) setSupervisorPort(addresses []string) []string { for _, address := range addresses { h, _, err := sysnet.SplitHostPort(address) if err != nil { - logrus.Errorf("failed to parse address %s, dropping: %v", address, err) + logrus.Errorf("Failed to parse address %s, dropping: %v", address, err) continue } newAddresses = append(newAddresses, sysnet.JoinHostPort(h, p.supervisorPort)) diff --git a/pkg/agent/run.go b/pkg/agent/run.go index c5baa36899..c02fee8fda 100644 --- a/pkg/agent/run.go +++ b/pkg/agent/run.go @@ -177,7 +177,7 @@ func validate() error { } if !strings.Contains(string(cgroups), "cpuset") { - logrus.Warn("Failed to find cpuset cgroup, you may need to add \"cgroup_enable=cpuset\" to your linux cmdline (/boot/cmdline.txt on a Raspberry Pi)") + logrus.Warn(`Failed to find cpuset cgroup, you may need to add "cgroup_enable=cpuset" to your linux cmdline (/boot/cmdline.txt on a Raspberry Pi)`) } if !strings.Contains(string(cgroups), "memory") { diff --git a/pkg/agent/syssetup/setup.go b/pkg/agent/syssetup/setup.go index 91955ec328..d0c3fe2e53 100644 --- a/pkg/agent/syssetup/setup.go +++ b/pkg/agent/syssetup/setup.go @@ -12,18 +12,18 @@ import ( func loadKernelModule(moduleName string) { if _, err := os.Stat("/sys/module/" + moduleName); err == nil { - logrus.Infof("module %s was already loaded", moduleName) + logrus.Info("Module " + moduleName + " was already loaded") return } if err := exec.Command("modprobe", moduleName).Run(); err != nil { - logrus.Warnf("failed to start %s module", moduleName) + logrus.Warn("Failed to start " + moduleName + " module") } } func enableSystemControl(file string) { if err := ioutil.WriteFile(file, []byte("1"), 0640); err != nil { - logrus.Warnf("failed to write value 1 at %s: %v", file, err) + logrus.Warnf("Failed to write value 1 at "+file+": %v", err) } } diff --git a/pkg/agent/tunnel/tunnel.go b/pkg/agent/tunnel/tunnel.go index d25f4a05aa..11cfa137d7 100644 --- a/pkg/agent/tunnel/tunnel.go +++ b/pkg/agent/tunnel/tunnel.go @@ -96,7 +96,7 @@ func Setup(ctx context.Context, config *config.Node, proxy proxy.Proxy) error { ResourceVersion: "0", }) if err != nil { - logrus.Errorf("Unable to watch for tunnel endpoints: %v", err) + logrus.Warnf("Unable to watch for tunnel endpoints: %v", err) continue connect } watching: @@ -151,7 +151,7 @@ func Setup(ctx context.Context, config *config.Node, proxy proxy.Proxy) error { select { case <-ctx.Done(): - logrus.Error("tunnel context canceled while waiting for connection") + logrus.Error("Tunnel context canceled while waiting for connection") return ctx.Err() case <-wait: } diff --git a/pkg/cli/agent/agent.go b/pkg/cli/agent/agent.go index 3bed674b78..90c3dd7137 100644 --- a/pkg/cli/agent/agent.go +++ b/pkg/cli/agent/agent.go @@ -54,7 +54,7 @@ func Run(ctx *cli.Context) error { cmds.AgentConfig.NodeIP = netutil.GetIPFromInterface(cmds.AgentConfig.FlannelIface) } - logrus.Infof("Starting "+version.Program+" agent %s", ctx.App.Version) + logrus.Info("Starting " + version.Program + " agent " + ctx.App.Version) dataDir, err := datadir.LocalHome(cmds.AgentConfig.DataDir, cmds.AgentConfig.Rootless) if err != nil { diff --git a/pkg/cli/server/server.go b/pkg/cli/server/server.go index 6eb6c933ed..501b04e1ed 100644 --- a/pkg/cli/server/server.go +++ b/pkg/cli/server/server.go @@ -231,7 +231,7 @@ func run(app *cli.Context, cfg *cmds.Server) error { return errors.Wrap(err, "Invalid tls-cipher-suites") } - logrus.Info("Starting "+version.Program+" ", app.App.Version) + logrus.Info("Starting " + version.Program + " " + app.App.Version) notifySocket := os.Getenv("NOTIFY_SOCKET") os.Unsetenv("NOTIFY_SOCKET") @@ -242,7 +242,8 @@ func run(app *cli.Context, cfg *cmds.Server) error { go func() { <-serverConfig.ControlConfig.Runtime.APIServerReady - logrus.Info("" + version.Program + " is up and running") + logrus.Info("Kube API server is now running") + logrus.Info(version.Program + " is up and running") if notifySocket != "" { os.Setenv("NOTIFY_SOCKET", notifySocket) systemd.SdNotify(true, "READY=1\n") diff --git a/pkg/cloudprovider/instances.go b/pkg/cloudprovider/instances.go index 0343404af6..34a13d2a10 100644 --- a/pkg/cloudprovider/instances.go +++ b/pkg/cloudprovider/instances.go @@ -63,7 +63,7 @@ func (k *k3s) NodeAddresses(ctx context.Context, name types.NodeName) ([]corev1. if node.Labels[InternalIPLabel] != "" { addresses = append(addresses, corev1.NodeAddress{Type: corev1.NodeInternalIP, Address: node.Labels[InternalIPLabel]}) } else { - logrus.Infof("couldn't find node internal ip label on node %s", name) + logrus.Infof("Couldn't find node internal ip label on node %s", name) } // check external address @@ -75,7 +75,7 @@ func (k *k3s) NodeAddresses(ctx context.Context, name types.NodeName) ([]corev1. if node.Labels[HostnameLabel] != "" { addresses = append(addresses, corev1.NodeAddress{Type: corev1.NodeHostName, Address: node.Labels[HostnameLabel]}) } else { - logrus.Infof("couldn't find node hostname label on node %s", name) + logrus.Infof("Couldn't find node hostname label on node %s", name) } return addresses, nil diff --git a/pkg/cluster/managed.go b/pkg/cluster/managed.go index 56d296d1ca..9e7682cc8c 100644 --- a/pkg/cluster/managed.go +++ b/pkg/cluster/managed.go @@ -25,7 +25,7 @@ func (c *Cluster) testClusterDB(ctx context.Context) (<-chan struct{}, error) { if err := c.managedDB.Test(ctx, c.clientAccessInfo); err != nil { logrus.Infof("Failed to test data store connection: %v", err) } else { - logrus.Infof("Data store connection OK") + logrus.Info(c.managedDB.EndpointName() + " data store connection OK") return } diff --git a/pkg/deploy/controller.go b/pkg/deploy/controller.go index 785ab5879e..17662703b2 100644 --- a/pkg/deploy/controller.go +++ b/pkg/deploy/controller.go @@ -70,7 +70,7 @@ func (w *watcher) start(ctx context.Context) { if err := w.listFiles(force); err == nil { force = false } else { - logrus.Errorf("failed to process config: %v", err) + logrus.Errorf("Failed to process config: %v", err) } select { case <-ctx.Done(): diff --git a/pkg/etcd/etcd.go b/pkg/etcd/etcd.go index 1279f499ff..b979a418ea 100644 --- a/pkg/etcd/etcd.go +++ b/pkg/etcd/etcd.go @@ -134,7 +134,7 @@ func (e *ETCD) Reset(ctx context.Context, clientAccessInfo *clientaccess.Info) e } if len(members.Members) == 1 && members.Members[0].Name == e.name { - logrus.Infof("etcd is running, restart without --cluster-reset flag now. Backup and delete ${datadir}/server/db on each peer etcd server and rejoin the nodes") + logrus.Infof("Etcd is running, restart without --cluster-reset flag now. Backup and delete ${datadir}/server/db on each peer etcd server and rejoin the nodes") os.Exit(0) } } @@ -211,7 +211,7 @@ func (e *ETCD) join(ctx context.Context, clientAccessInfo *clientaccess.Info) er members, err := client.MemberList(ctx) if err != nil { - logrus.Errorf("failed to get member list from cluster, will assume this member is already added") + logrus.Errorf("Failed to get member list from etcd cluster. Will assume this member is already added") members = &etcd.MemberListResponse{ Members: append(memberList.Members, &etcdserverpb.Member{ Name: e.name, @@ -552,14 +552,14 @@ func (e *ETCD) snapshot(ctx context.Context) { logrus.Infof("Snapshot retention check") snapshotDir, err := snapshotDir(e.config) if err != nil { - logrus.Errorf("failed to get the snapshot dir: %v", err) + logrus.Errorf("Failed to get the snapshot dir: %v", err) return } logrus.Infof("Taking etcd snapshot at %s", snapshotTime.String()) sManager := snapshot.NewV3(nil) tlsConfig, err := toTLSConfig(e.runtime) if err != nil { - logrus.Errorf("failed to get tls config for etcd: %v", err) + logrus.Errorf("Failed to get tls config for etcd: %v", err) return } etcdConfig := etcd.Config{ @@ -570,11 +570,11 @@ func (e *ETCD) snapshot(ctx context.Context) { snapshotPath := filepath.Join(snapshotDir, snapshotPrefix+strconv.Itoa(int(snapshotTime.Unix()))) if err := sManager.Save(ctx, etcdConfig, snapshotPath); err != nil { - logrus.Errorf("failed to save snapshot %s: %v", snapshotPath, err) + logrus.Errorf("Failed to save snapshot %s: %v", snapshotPath, err) return } if err := snapshotRetention(e.config.EtcdSnapshotRetention, snapshotDir); err != nil { - logrus.Errorf("failed to apply snapshot retention: %v", err) + logrus.Errorf("Failed to apply snapshot retention: %v", err) return } } @@ -593,7 +593,7 @@ func (e *ETCD) Restore(ctx context.Context) error { // check the old etcd data dir oldDataDir := dataDir(e.config) + "-old" if s, err := os.Stat(oldDataDir); err == nil && s.IsDir() { - logrus.Infof("etcd already restored from a snapshot. Restart without --snapshot-restore-path flag. Backup and delete ${datadir}/server/db on each peer etcd server and rejoin the nodes") + logrus.Infof("Etcd already restored from a snapshot. Restart without --snapshot-restore-path flag. Backup and delete ${datadir}/server/db on each peer etcd server and rejoin the nodes") os.Exit(0) } else if os.IsNotExist(err) { if e.config.ClusterResetRestorePath == "" { diff --git a/pkg/netutil/iface.go b/pkg/netutil/iface.go index 64de04bc94..abf00a7919 100644 --- a/pkg/netutil/iface.go +++ b/pkg/netutil/iface.go @@ -13,7 +13,7 @@ func GetIPFromInterface(ifaceName string) string { if err != nil { logrus.Warn(errors.Wrap(err, "unable to get global unicast ip from interface name")) } else { - logrus.Infof("found ip %s from iface %s", ip, ifaceName) + logrus.Infof("Found ip %s from iface %s", ip, ifaceName) } return ip } diff --git a/pkg/node/controller.go b/pkg/node/controller.go index 852cae1dfb..6100aaaf07 100644 --- a/pkg/node/controller.go +++ b/pkg/node/controller.go @@ -52,7 +52,7 @@ func (h *handler) updateHosts(node *core.Node, removed bool) (*core.Node, error) } } if nodeAddress == "" { - logrus.Errorf("No InternalIP found for node %s", node.Name) + logrus.Errorf("No InternalIP found for node " + node.Name) return nil, nil } diff --git a/pkg/rootlessports/controller.go b/pkg/rootlessports/controller.go index cf19715b22..1ca441e92e 100644 --- a/pkg/rootlessports/controller.go +++ b/pkg/rootlessports/controller.go @@ -34,7 +34,7 @@ func Register(ctx context.Context, serviceController coreClients.ServiceControll if err == nil { break } else { - logrus.Infof("waiting for rootless API socket %s: %v", rootless.Sock, err) + logrus.Infof("Waiting for rootless API socket %s: %v", rootless.Sock, err) time.Sleep(1 * time.Second) } } diff --git a/pkg/server/auth.go b/pkg/server/auth.go index 34126f438f..ff6eb8bcd6 100644 --- a/pkg/server/auth.go +++ b/pkg/server/auth.go @@ -21,15 +21,22 @@ func hasRole(mustRoles []string, roles []string) bool { } func doAuth(roles []string, serverConfig *config.Control, next http.Handler, rw http.ResponseWriter, req *http.Request) { - if serverConfig == nil || serverConfig.Runtime.Authenticator == nil { - logrus.Errorf("authenticate not initialized") + switch { + case serverConfig == nil: + logrus.Errorf("Authenticate not initialized: serverConfig is nil") rw.WriteHeader(http.StatusUnauthorized) return + case serverConfig.Runtime.Authenticator == nil: + logrus.Errorf("Authenticate not initialized: serverConfig.Runtime.Authenticator is nil") + rw.WriteHeader(http.StatusUnauthorized) + return + default: + // } resp, ok, err := serverConfig.Runtime.Authenticator.AuthenticateRequest(req) if err != nil { - logrus.Errorf("failed to authenticate request: %v", err) + logrus.Errorf("Failed to authenticate request from %s: %v", req.RemoteAddr, err) rw.WriteHeader(http.StatusInternalServerError) return } diff --git a/pkg/server/server.go b/pkg/server/server.go index f0520e8903..92c5836200 100644 --- a/pkg/server/server.go +++ b/pkg/server/server.go @@ -284,7 +284,7 @@ func writeKubeConfig(certs string, config *Config) error { if isSymlink(kubeConfigSymlink) { if err := os.Remove(kubeConfigSymlink); err != nil { - logrus.Errorf("failed to remove kubeconfig symlink") + logrus.Errorf("Failed to remove kubeconfig symlink") } } @@ -301,7 +301,7 @@ func writeKubeConfig(certs string, config *Config) error { if err == nil { util.SetFileModeForPath(kubeConfig, os.FileMode(mode)) } else { - logrus.Errorf("failed to set %s to mode %s: %v", kubeConfig, os.FileMode(mode), err) + logrus.Errorf("Failed to set %s to mode %s: %v", kubeConfig, os.FileMode(mode), err) } } else { util.SetFileModeForPath(kubeConfig, os.FileMode(0600)) @@ -309,7 +309,7 @@ func writeKubeConfig(certs string, config *Config) error { if kubeConfigSymlink != kubeConfig { if err := writeConfigSymlink(kubeConfig, kubeConfigSymlink); err != nil { - logrus.Errorf("failed to write kubeconfig symlink: %v", err) + logrus.Errorf("Failed to write kubeconfig symlink: %v", err) } } @@ -348,7 +348,7 @@ func printToken(httpsPort int, advertiseIP, prefix, cmd string) { if ip == "" { hostIP, err := net.ChooseHostInterface() if err != nil { - logrus.Error(err) + logrus.Errorf("Failed to choose interface: %v", err) } ip = hostIP.String() } @@ -433,7 +433,7 @@ func setMasterRoleLabel(ctx context.Context, nodes v1.NodeClient) error { node.Labels[MasterRoleLabelKey] = "true" _, err = nodes.Update(node) if err == nil { - logrus.Infof("master role label has been set successfully on node: %s", nodeName) + logrus.Infof("Master role label has been set successfully on node: %s", nodeName) break } select { @@ -450,7 +450,7 @@ func setClusterDNSConfig(ctx context.Context, controlConfig *Config, configMap v // check if configmap already exists _, err := configMap.Get("kube-system", "cluster-dns", metav1.GetOptions{}) if err == nil { - logrus.Infof("cluster dns configmap already exists") + logrus.Infof("Cluster dns configmap already exists") return nil } clusterDNS := controlConfig.ControlConfig.ClusterDNS @@ -472,7 +472,7 @@ func setClusterDNSConfig(ctx context.Context, controlConfig *Config, configMap v for { _, err = configMap.Create(c) if err == nil { - logrus.Infof("cluster dns configmap has been set successfully") + logrus.Infof("Cluster dns configmap has been set successfully") break } logrus.Infof("Waiting for master node %s startup: %v", nodeName, err)