Merge pull request #1831 from SvenDowideit/label-init-stages

give init stages a label so the log tells us what is starting, not what number it is.

config/data_funcs.go

@@ -10,16 +10,29 @@ import (
 )
 
 type CfgFunc func(*CloudConfig) (*CloudConfig, error)
+type CfgFuncData struct {
+	Name string
+	Func CfgFunc
+}
+type CfgFuncs []CfgFuncData
 
-func ChainCfgFuncs(cfg *CloudConfig, cfgFuncs ...CfgFunc) (*CloudConfig, error) {
-	for i, cfgFunc := range cfgFuncs {
-		log.Debugf("[%d/%d] Starting", i+1, len(cfgFuncs))
+func ChainCfgFuncs(cfg *CloudConfig, cfgFuncs CfgFuncs) (*CloudConfig, error) {
+	len := len(cfgFuncs)
+	for c, d := range cfgFuncs {
+		i := c + 1
+		name := d.Name
+		cfgFunc := d.Func
+		if cfg == nil {
+			log.Infof("[%d/%d] Starting %s WITH NIL cfg", i, len, name)
+		} else {
+			log.Infof("[%d/%d] Starting %s", i, len, name)
+		}
 		var err error
 		if cfg, err = cfgFunc(cfg); err != nil {
-			log.Errorf("Failed [%d/%d] %s", i+1, len(cfgFuncs), err)
+			log.Errorf("Failed [%d/%d] %s: %s", i, len, name, err)
 			return cfg, err
 		}
-		log.Debugf("[%d/%d] Done %d%%", i+1, len(cfgFuncs), ((i + 1) * 100 / len(cfgFuncs)))
+		log.Debugf("[%d/%d] Done %s", i, len, name)
 	}
 	return cfg, nil
 }

init/bootstrap.go

@@ -68,8 +68,10 @@ func bootstrap(cfg *config.CloudConfig) error {
 	defer stopDocker(c)
 
 	_, err = config.ChainCfgFuncs(cfg,
-		loadImages,
-		bootstrapServices)
+		[]config.CfgFuncData{
+			config.CfgFuncData{"bootstrap loadImages", loadImages},
+			config.CfgFuncData{"bootstrap Services", bootstrapServices},
+		})
 	return err
 }
 
@@ -82,7 +84,9 @@ func runCloudInitServices(cfg *config.CloudConfig) error {
 	defer stopDocker(c)
 
 	_, err = config.ChainCfgFuncs(cfg,
-		loadImages,
-		runCloudInitServiceSet)
+		[]config.CfgFuncData{
+			config.CfgFuncData{"cloudinit loadImages", loadImages},
+			config.CfgFuncData{"cloudinit Services", runCloudInitServiceSet},
+		})
 	return err
 }

init/init.go

@@ -90,7 +90,8 @@ func sysInit(c *config.CloudConfig) (*config.CloudConfig, error) {
 }
 
 func MainInit() {
-	// TODO: log.InitLogger()
+	log.InitLogger()
+	log.Infof("MainInit() start")
 	if err := RunInit(); err != nil {
 		log.Fatal(err)
 	}
@@ -223,19 +224,19 @@ func RunInit() error {
 
 	configFiles := make(map[string][]byte)
 
-	initFuncs := []config.CfgFunc{
-		func(c *config.CloudConfig) (*config.CloudConfig, error) {
+	initFuncs := []config.CfgFuncData{
+		config.CfgFuncData{"preparefs", func(c *config.CloudConfig) (*config.CloudConfig, error) {
 			return c, dfs.PrepareFs(&mountConfig)
-		},
-		func(c *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"save init cmdline", func(c *config.CloudConfig) (*config.CloudConfig, error) {
 			// will this be passed to cloud-init-save?
 			cmdLineArgs := strings.Join(os.Args, " ")
 			config.SaveInitCmdline(cmdLineArgs)
 
 			return c, nil
-		},
-		mountOem,
-		func(_ *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"mount OEM", mountOem},
+		config.CfgFuncData{"debug save cfg", func(_ *config.CloudConfig) (*config.CloudConfig, error) {
 			cfg := config.LoadConfig()
 
 			if cfg.Rancher.Debug {
@@ -248,9 +249,9 @@ func RunInit() error {
 			}
 
 			return cfg, nil
-		},
-		loadModules,
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"load modules", loadModules},
+		config.CfgFuncData{"b2d env", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 			if util.ResolveDevice("LABEL=B2D_STATE") != "" {
 				boot2DockerEnvironment = true
 				cfg.Rancher.State.Dev = "LABEL=B2D_STATE"
@@ -286,23 +287,23 @@ func RunInit() error {
 			}
 
 			return config.LoadConfig(), nil
-		},
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"mount and bootstrap", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 			var err error
 			cfg, shouldSwitchRoot, err = tryMountAndBootstrap(cfg)
 			if err != nil {
 				return nil, err
 			}
 			return cfg, nil
-		},
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"cloud-init", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 
 			cfg.Rancher.CloudInit.Datasources = config.LoadConfigWithPrefix(state).Rancher.CloudInit.Datasources
 			if err := config.Set("rancher.cloud_init.datasources", cfg.Rancher.CloudInit.Datasources); err != nil {
 				log.Error(err)
 			}
 
-			log.Debug("init: runCloudInitServices()")
+			log.Debug("init, runCloudInitServices()")
 			if err := runCloudInitServices(cfg); err != nil {
 				log.Error(err)
 			}
@@ -311,8 +312,8 @@ func RunInit() error {
 			cfg = config.LoadConfig()
 
 			return cfg, nil
-		},
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"read cfg files", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 			filesToCopy := []string{
 				config.CloudConfigInitFile,
 				config.CloudConfigBootFile,
@@ -328,8 +329,8 @@ func RunInit() error {
 				configFiles[name] = content
 			}
 			return cfg, nil
-		},
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"switchroot", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 			if !shouldSwitchRoot {
 				return cfg, nil
 			}
@@ -338,9 +339,9 @@ func RunInit() error {
 				return cfg, err
 			}
 			return cfg, nil
-		},
-		mountOem,
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"mount OEM2", mountOem},
+		config.CfgFuncData{"write cfg files", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 			for name, content := range configFiles {
 				if err := os.MkdirAll(filepath.Dir(name), os.ModeDir|0700); err != nil {
 					log.Error(err)
@@ -356,8 +357,8 @@ func RunInit() error {
 				log.Error(err)
 			}
 			return cfg, nil
-		},
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"b2d Env", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 			if boot2DockerEnvironment {
 				if err := config.Set("rancher.state.dev", cfg.Rancher.State.Dev); err != nil {
 					log.Errorf("Failed to update rancher.state.dev: %v", err)
@@ -368,21 +369,21 @@ func RunInit() error {
 			}
 
 			return config.LoadConfig(), nil
-		},
-		func(c *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"preparefs2", func(c *config.CloudConfig) (*config.CloudConfig, error) {
 			return c, dfs.PrepareFs(&mountConfig)
-		},
-		loadModules,
-		func(c *config.CloudConfig) (*config.CloudConfig, error) {
+		}},
+		config.CfgFuncData{"load modules2", loadModules},
+		config.CfgFuncData{"set proxy env", func(c *config.CloudConfig) (*config.CloudConfig, error) {
 			network.SetProxyEnvironmentVariables(c)
 			return c, nil
-		},
-		initializeSelinux,
-		setupSharedRoot,
-		sysInit,
+		}},
+		config.CfgFuncData{"init SELinux", initializeSelinux},
+		config.CfgFuncData{"setupSharedRoot", setupSharedRoot},
+		config.CfgFuncData{"sysinit", sysInit},
 	}
 
-	cfg, err := config.ChainCfgFuncs(nil, initFuncs...)
+	cfg, err := config.ChainCfgFuncs(nil, initFuncs)
 	if err != nil {
 		return err
 	}

init/sysinit.go

@@ -101,8 +101,9 @@ func SysInit() error {
 	}
 
 	_, err := config.ChainCfgFuncs(cfg,
-		loadImages,
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+		[]config.CfgFuncData{
+			config.CfgFuncData{"loadImages", loadImages},
+			config.CfgFuncData{"start project", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 				p, err := compose.GetProject(cfg, false, true)
 				if err != nil {
 					return cfg, err
@@ -113,14 +114,14 @@ func SysInit() error {
 					},
 					Log: cfg.Rancher.Log,
 				})
-		},
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+			}},
+			config.CfgFuncData{"sync", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 				syscall.Sync()
 				return cfg, nil
-		},
-		func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
+			}},
+			config.CfgFuncData{"banner", func(cfg *config.CloudConfig) (*config.CloudConfig, error) {
 				log.Infof("RancherOS %s started", config.Version)
 				return cfg, nil
-		})
+			}}})
 	return err
 }

main.go

@@ -1,6 +1,9 @@
 package main
 
 import (
+	"fmt"
+	"os"
+
 	"github.com/containernetworking/cni/plugins/ipam/host-local"
 	"github.com/containernetworking/cni/plugins/main/bridge"
 	"github.com/docker/docker/docker"
@@ -42,6 +45,18 @@ var entrypoints = map[string]func(){
 }
 
 func main() {
+	if 0 == 1 {
+		// TODO: move this into a "dev/debug +build"
+		fmt.Fprintf(os.Stderr, "ros main(%s) ppid:%d - print to stdio\n", os.Args[0], os.Getppid())
+
+		filename := "/dev/kmsg"
+		f, err := os.OpenFile(filename, os.O_WRONLY, 0644)
+		if err == nil {
+			fmt.Fprintf(f, "ros main(%s) ppid:%d - print to %s\n", os.Args[0], os.Getppid(), filename)
+		}
+		f.Close()
+	}
+
 	for name, f := range entrypoints {
 		reexec.Register(name, f)
 	}