diff --git a/cmd/buildkitd/main.go b/cmd/buildkitd/main.go index b7d1ac8f5982..04911246ae8c 100644 --- a/cmd/buildkitd/main.go +++ b/cmd/buildkitd/main.go @@ -14,6 +14,7 @@ import ( "strconv" "strings" "sync" + "time" "github.com/containerd/containerd/defaults" "github.com/containerd/containerd/remotes/docker" @@ -257,6 +258,7 @@ func main() { if cfg.Debug { logrus.SetLevel(logrus.DebugLevel) + bklog.L.Debugf("Debug mode enabled") } if cfg.Trace { logrus.SetLevel(logrus.TraceLevel) @@ -320,12 +322,15 @@ func main() { return nil } + beforeLock := time.Now() lockPath := filepath.Join(root, "buildkitd.lock") lock := flock.New(lockPath) + bklog.L.Infof("before lock: %s", time.Since(beforeLock)) locked, err := lock.TryLock() if err != nil { return errors.Wrapf(err, "could not lock %s", lockPath) } + bklog.L.Infof("after lock: %s", time.Since(beforeLock)) if !locked { return errors.Errorf("could not lock %s, another instance running?", lockPath) } @@ -336,15 +341,19 @@ func main() { // listeners have to be initialized before the controller // https://github.com/moby/buildkit/issues/4618 + beforeListeners := time.Now() listeners, err := newGRPCListeners(cfg.GRPC) if err != nil { return err } + bklog.L.Infof("after listeners: %s", time.Since(beforeListeners)) + beforeController := time.Now() controller, err := newController(ctx, c, &cfg) if err != nil { return err } + bklog.L.Infof("after controller: %s", time.Since(beforeController)) defer controller.Close() healthv1.RegisterHealthServer(server, health.NewServer()) @@ -785,6 +794,7 @@ func newController(ctx context.Context, c *cli.Context, cfg *config.Config) (*co } } + beforeWorkerController := time.Now() wc, err := newWorkerController(c, workerInitializerOpt{ config: cfg, sessionManager: sessionManager, @@ -793,6 +803,7 @@ func newController(ctx context.Context, c *cli.Context, cfg *config.Config) (*co if err != nil { return nil, err } + bklog.L.Infof("after worker controller: %s", time.Since(beforeWorkerController)) frontends := map[string]frontend.Frontend{} if cfg.Frontends.Dockerfile.Enabled == nil || *cfg.Frontends.Dockerfile.Enabled { @@ -870,8 +881,9 @@ func newWorkerController(c *cli.Context, wiOpt workerInitializerOpt) (*worker.Co return nil, err } for _, w := range ws { + beforePlatformCall := time.Now() p := w.Platforms(false) - bklog.L.Infof("found worker %q, labels=%v, platforms=%v", w.ID(), w.Labels(), formatPlatforms(p)) + bklog.L.Infof("found worker %q, labels=%v, platforms=%v, platforms call took %s", w.ID(), w.Labels(), formatPlatforms(p), time.Since(beforePlatformCall)) archutil.WarnIfUnsupported(p) if err = wc.Add(w); err != nil { return nil, err diff --git a/cmd/buildkitd/main_containerd_worker.go b/cmd/buildkitd/main_containerd_worker.go index 3b39083e555c..69be3e8dedfd 100644 --- a/cmd/buildkitd/main_containerd_worker.go +++ b/cmd/buildkitd/main_containerd_worker.go @@ -263,9 +263,11 @@ func applyContainerdFlags(c *cli.Context, cfg *config.Config) error { } func containerdWorkerInitializer(c *cli.Context, common workerInitializerOpt) ([]worker.Worker, error) { + beforeFlags := time.Now() if err := applyContainerdFlags(c, common.config); err != nil { return nil, err } + bklog.L.Infof("after flags: %s", time.Since(beforeFlags)) cfg := common.config.Workers.Containerd @@ -306,6 +308,7 @@ func containerdWorkerInitializer(c *cli.Context, common workerInitializerOpt) ([ var runtime *containerd.RuntimeInfo if cfg.Runtime.Name != "" { + beforeRuntime := time.Now() opts := getRuntimeOptionsType(cfg.Runtime.Name) t, err := toml.TreeFromMap(cfg.Runtime.Options) @@ -322,6 +325,7 @@ func containerdWorkerInitializer(c *cli.Context, common workerInitializerOpt) ([ Path: cfg.Runtime.Path, Options: opts, } + bklog.L.Infof("after runtime setup: %s", time.Since(beforeRuntime)) } workerOpts := containerd.WorkerOptions{ @@ -341,10 +345,14 @@ func containerdWorkerInitializer(c *cli.Context, common workerInitializerOpt) ([ Runtime: runtime, } + beforeWorkerOpt := time.Now() opt, err := containerd.NewWorkerOpt(workerOpts, ctd.WithTimeout(60*time.Second)) if err != nil { return nil, err } + bklog.L.Infof("after worker opt: %s", time.Since(beforeWorkerOpt)) + + beforeGettingOpts := time.Now() opt.GCPolicy = getGCPolicy(cfg.GCConfig, common.config.Root) opt.BuildkitVersion = getBuildkitVersion() opt.RegistryHosts = resolverFunc(common.config) @@ -356,10 +364,15 @@ func containerdWorkerInitializer(c *cli.Context, common workerInitializerOpt) ([ } opt.Platforms = platforms } + bklog.L.Infof("after getting opts: %s", time.Since(beforeGettingOpts)) + + beforeNewWorker := time.Now() w, err := base.NewWorker(context.TODO(), opt) if err != nil { return nil, err } + bklog.L.Infof("after new worker: %s", time.Since(beforeNewWorker)) + return []worker.Worker{w}, nil }