Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

buildkitd: add logs to track boot info #1

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open

buildkitd: add logs to track boot info #1

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 13 additions & 1 deletion cmd/buildkitd/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ import (
"strconv"
"strings"
"sync"
"time"

"github.com/containerd/containerd/defaults"
"github.com/containerd/containerd/remotes/docker"
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
}
Expand All @@ -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())
Expand Down Expand Up @@ -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,
Expand All @@ -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 {
Expand Down Expand Up @@ -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
Expand Down
13 changes: 13 additions & 0 deletions cmd/buildkitd/main_containerd_worker.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand Down Expand Up @@ -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)
Expand All @@ -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{
Expand All @@ -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)
Expand All @@ -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
}

Expand Down