Initial Logging Output Update (#2246)

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

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)
 }

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)

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))

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") {

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)
 	}
 }
 

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:
 	}

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 {

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")

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

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
 			}
 

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():

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 == "" {

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
 }

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
 	}
 

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)
 		}
 	}

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
 	}

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)