From c53198e3437a4af024f4409081d69093ed99807f Mon Sep 17 00:00:00 2001 From: zerodoctor Date: Sat, 7 Oct 2023 00:12:59 -0500 Subject: [PATCH] fix various issues and add more trace logs --- command/daemon/daemon.go | 2 +- engine/convert.go | 1 + engine/engine.go | 46 +++++++++++++++++++++++++++++++++------- go.mod | 2 +- go.sum | 8 ++----- 5 files changed, 43 insertions(+), 16 deletions(-) diff --git a/command/daemon/daemon.go b/command/daemon/daemon.go index db6df8e..afe8446 100644 --- a/command/daemon/daemon.go +++ b/command/daemon/daemon.go @@ -84,7 +84,7 @@ func (c *daemonCommand) run(*kingpin.ParseContext) error { opts := engine.Opts{ HidePull: !config.Podman.Stream, } - engine, err := engine.NewEnv(context.Background(), opts) + engine, err := engine.NewEnv(ctx, opts) if err != nil { logrus.WithError(err). Fatalln("cannot load the podman engine") diff --git a/engine/convert.go b/engine/convert.go index 1703739..2b481d2 100644 --- a/engine/convert.go +++ b/engine/convert.go @@ -109,6 +109,7 @@ func toSpec(spec *Spec, step *Step) *specgen.SpecGenerator { ContainerResourceConfig: resource, } + logrus.Debugf("creating [config=%+v]", config) return config } diff --git a/engine/engine.go b/engine/engine.go index b2812b6..493acac 100644 --- a/engine/engine.go +++ b/engine/engine.go @@ -29,7 +29,7 @@ import ( // TODO: figure out what to do about this global const UNIX_SOCK string = "unix:///run/podman/podman.sock" -// Opts configures the Docker engine. +// Opts configures the Podman engine. type Opts struct { HidePull bool } @@ -43,22 +43,33 @@ type Podman struct { // New returns a new engine. func New(conn context.Context, opts Opts) *Podman { return &Podman{ + conn: conn, hidePull: opts.HidePull, } } // NewEnv returns a new Engine from the environment. func NewEnv(ctx context.Context, opts Opts) (*Podman, error) { + logger.FromContext(ctx).Tracef("connecting to podman.socket... [sock=%s]", UNIX_SOCK) + conn, err := bindings.NewConnection(ctx, UNIX_SOCK) return New(conn, opts), err } +func (e *Podman) Ping(ctx context.Context) error { + // podman has "/_ping" but apperently + // its should only be used when initializing a connection + return nil +} + // Setup the pipeline environment. func (e *Podman) Setup(ctx context.Context, specv runtime.Spec) error { spec := specv.(*Spec) + logger.FromContext(ctx).Tracef("setup pipeline... [spec=%+v]", spec) // creates the default temporary (local) volumes // that are mounted into each container step. + logger.FromContext(ctx).Tracef("setup volumes...") for _, vol := range spec.Volumes { if vol.EmptyDir == nil { continue @@ -74,6 +85,9 @@ func (e *Podman) Setup(ctx context.Context, specv runtime.Spec) error { &volumes.CreateOptions{}, ) if err != nil { + logger.FromContext(ctx). + WithError(err). + Errorf("failed to create volume [error=%s]") return errors.TrimExtraInfo(err) } } @@ -85,8 +99,8 @@ func (e *Podman) Setup(ctx context.Context, specv runtime.Spec) error { driver = "nat" } + logger.FromContext(ctx).Tracef("setup networks...") _, err := network.Create(e.conn, &types.Network{ - ID: spec.Network.ID, Driver: driver, Options: spec.Network.Options, Labels: spec.Network.Labels, @@ -136,8 +150,9 @@ func (e *Podman) Destroy(ctx context.Context, specv runtime.Spec) error { } // stop all containers + logger.FromContext(ctx).Tracef("stopping containers...") for _, step := range append(spec.Steps, spec.Internal...) { - if err := containers.Kill(ctx, step.ID, &containers.KillOptions{Signal: toPtr("9")}); err != nil { + if err := containers.Kill(e.conn, step.ID, &containers.KillOptions{Signal: toPtr("9")}); err != nil { logger.FromContext(ctx). WithError(err). WithField("container", step.ID). @@ -146,6 +161,7 @@ func (e *Podman) Destroy(ctx context.Context, specv runtime.Spec) error { } // cleanup all containers + logger.FromContext(ctx).Tracef("cleaning containers...") for _, step := range append(spec.Steps, spec.Internal...) { if _, err := containers.Remove(e.conn, step.ID, &removeOpts); err != nil { logger.FromContext(ctx). @@ -156,6 +172,7 @@ func (e *Podman) Destroy(ctx context.Context, specv runtime.Spec) error { } // cleanup all volumes + logger.FromContext(ctx).Tracef("cleaning volumes...") for _, vol := range spec.Volumes { if vol.EmptyDir == nil { continue @@ -174,6 +191,7 @@ func (e *Podman) Destroy(ctx context.Context, specv runtime.Spec) error { } } + logger.FromContext(ctx).Tracef("cleaning networks...") if _, err := network.Remove(e.conn, spec.Network.ID, &network.RemoveOptions{}); err != nil { logger.FromContext(ctx). WithError(err). @@ -194,15 +212,19 @@ func (e *Podman) Run(ctx context.Context, specv runtime.Spec, stepv runtime.Step step := stepv.(*Step) // create the container + logger.FromContext(ctx).Tracef("creating container...") err := e.create(ctx, spec, step, output) if err != nil { return nil, errors.TrimExtraInfo(err) } + // start the container + logger.FromContext(ctx).Tracef("starting container...") err = e.start(ctx, step.ID) if err != nil { return nil, errors.TrimExtraInfo(err) } + // this is an experimental feature that closes logging as the last step var allowDeferTailLog = os.Getenv("DRONE_DEFER_TAIL_LOG") == "true" if allowDeferTailLog { @@ -216,6 +238,7 @@ func (e *Podman) Run(ctx context.Context, specv runtime.Spec, stepv runtime.Step } defer logs.Close() } else { + logger.FromContext(ctx).Tracef("tail logging...") err = e.tail(ctx, step.ID, output) if err != nil { return nil, errors.TrimExtraInfo(err) @@ -237,6 +260,8 @@ func (e *Podman) create(ctx context.Context, spec *Spec, step *Step, output io.W pullopts.Password = &step.Auth.Password } + logger.FromContext(ctx).Tracef("pulling image...") + // Read(p []byte) (n int, err error) // automatically pull the latest version of the image if requested // by the process configuration, or if the image is :latest @@ -260,7 +285,8 @@ func (e *Podman) create(ctx context.Context, spec *Spec, step *Step, output io.W // automatically pull and try to re-create the image if the // failure is caused because the image does not exist. - if step.Pull != PullNever { + if err != nil && step.Pull != PullNever { + logger.FromContext(ctx).Tracef("pulling image...") rc, pullerr := images.Pull(e.conn, step.Image, &pullopts) if pullerr != nil { return pullerr @@ -282,6 +308,7 @@ func (e *Podman) create(ctx context.Context, spec *Spec, step *Step, output io.W // attach the container to user-defined networks. // primarily used to attach global user-defined networks. + logger.FromContext(ctx).Tracef("attaching network to container...") if step.Network == "" { for _, net := range step.Networks { err = network.Connect(e.conn, net, step.ID, &types.PerNetworkOptions{ @@ -298,6 +325,7 @@ func (e *Podman) create(ctx context.Context, spec *Spec, step *Step, output io.W // helper function emulates the `docker start` command. func (e *Podman) start(ctx context.Context, id string) error { + logger.FromContext(ctx).Tracef("starting containers from base function...") return containers.Start(e.conn, id, &containers.StartOptions{}) } @@ -327,11 +355,11 @@ func (e *Podman) waitRetry(ctx context.Context, id string) (*runtime.State, erro // helper function emulates the `docker wait` command, blocking // until the container stops and returning the exit code. func (e *Podman) wait(ctx context.Context, id string) (*runtime.State, error) { - containers.Wait(ctx, id, &containers.WaitOptions{ + containers.Wait(e.conn, id, &containers.WaitOptions{ Conditions: []string{"created", "exited", "dead", "removing", "removed"}, }) - info, err := containers.Inspect(ctx, id, &containers.InspectOptions{}) + info, err := containers.Inspect(e.conn, id, &containers.InspectOptions{}) if err != nil { return nil, err } @@ -355,7 +383,7 @@ func (e *Podman) deferTail(ctx context.Context, id string, output io.Writer) (lo out := make(chan string, 512) error := make(chan string, 512) - err = containers.Logs(ctx, id, &opts, out, error) + err = containers.Logs(e.conn, id, &opts, out, error) if err != nil { logger.FromContext(ctx). WithError(err). @@ -364,6 +392,7 @@ func (e *Podman) deferTail(ctx context.Context, id string, output io.Writer) (lo return nil, err } + logger.FromContext(ctx).Debugf("wrapping logs into reader [id=%s]", id) logs = NewChansReadClose(ctx, out, error) io.Copy(output, logs) @@ -382,11 +411,12 @@ func (e *Podman) tail(ctx context.Context, id string, output io.Writer) error { out := make(chan string, 100) error := make(chan string, 100) - err := containers.Logs(ctx, id, &opts, out, error) + err := containers.Logs(e.conn, id, &opts, out, error) if err != nil { return err } + logger.FromContext(ctx).Debugf("starting log goroutine [id=%s]...", id) go func() { logs := NewChansReadClose(ctx, out, error) io.Copy(output, logs) diff --git a/go.mod b/go.mod index 06d3a9e..a2c5992 100644 --- a/go.mod +++ b/go.mod @@ -5,7 +5,7 @@ go 1.20 require ( github.com/buildkite/yaml v2.1.0+incompatible github.com/containers/common v0.56.0 - github.com/containers/podman/v4 v4.7.0 + github.com/containers/podman/v4 v4.7.1 github.com/dchest/uniuri v1.2.0 github.com/docker/distribution v2.8.3+incompatible github.com/docker/docker v24.0.6+incompatible diff --git a/go.sum b/go.sum index f7dca18..7404867 100644 --- a/go.sum +++ b/go.sum @@ -258,8 +258,8 @@ github.com/containers/ocicrypt v1.1.0/go.mod h1:b8AOe0YR67uU8OqfVNcznfFpAzu3rdgU github.com/containers/ocicrypt v1.1.1/go.mod h1:Dm55fwWm1YZAjYRaJ94z2mfZikIyIN4B0oB3dj3jFxY= github.com/containers/ocicrypt v1.1.8 h1:saSBF0/8DyPUjzcxMVzL2OBUWCkvRvqIm75pu0ADSZk= github.com/containers/ocicrypt v1.1.8/go.mod h1:jM362hyBtbwLMWzXQZTlkjKGAQf/BN/LFMtH0FIRt34= -github.com/containers/podman/v4 v4.7.0 h1:KjawmmazJHyQfck5sFLzQ/KI+JtsnnoGI+d+qfiPvaY= -github.com/containers/podman/v4 v4.7.0/go.mod h1:FJPqIhiwdklJenJskZyoNd1ZNin6kvY6zL9Rypaajxs= +github.com/containers/podman/v4 v4.7.1 h1:tMhVDvvCIMU64UZVSo2EfLG7ff0/GDHkDg7An2rJ0ZA= +github.com/containers/podman/v4 v4.7.1/go.mod h1:FJPqIhiwdklJenJskZyoNd1ZNin6kvY6zL9Rypaajxs= github.com/containers/psgo v1.8.0 h1:2loGekmGAxM9ir5OsXWEfGwFxorMPYnc6gEDsGFQvhY= github.com/containers/psgo v1.8.0/go.mod h1:T8ZxnX3Ur4RvnhxFJ7t8xJ1F48RhiZB4rSrOaR/qGHc= github.com/containers/storage v1.43.0/go.mod h1:uZ147thiIFGdVTjMmIw19knttQnUCl3y9zjreHrg11s= @@ -286,7 +286,6 @@ github.com/coreos/pkg v0.0.0-20160727233714-3ac0863d7acf/go.mod h1:E3G3o1h8I7cfc github.com/coreos/pkg v0.0.0-20180928190104-399ea9e2e55f/go.mod h1:E3G3o1h8I7cfcXa63jLwjI0eiQQMgzzUDFVpN/nH/eA= github.com/cpuguy83/go-md2man/v2 v2.0.0-20190314233015-f79a8a8ca69d/go.mod h1:maD7wRr/U5Z6m/iR4s+kqSMx2CaBsrgA7czyZG/E6dU= github.com/cpuguy83/go-md2man/v2 v2.0.0/go.mod h1:maD7wRr/U5Z6m/iR4s+kqSMx2CaBsrgA7czyZG/E6dU= -github.com/cpuguy83/go-md2man/v2 v2.0.2/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o= github.com/creack/pty v1.1.7/go.mod h1:lj5s0c3V2DBrqTV7llrYr5NG6My20zk30Fl46Y7DoTY= github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= github.com/creack/pty v1.1.18 h1:n56/Zwd5o6whRC5PMGretI4IdRLlmBXYNjScPaBgsbY= @@ -691,7 +690,6 @@ github.com/mitchellh/mapstructure v1.4.1/go.mod h1:bFUtVrKA4DC2yAKiSyO/QUcy7e+RR github.com/mitchellh/mapstructure v1.5.0 h1:jeMsZIYE/09sWLaz43PL7Gy6RuMjD2eJVyuac5Z2hdY= github.com/mitchellh/mapstructure v1.5.0/go.mod h1:bFUtVrKA4DC2yAKiSyO/QUcy7e+RRV2QTWOzhPopBRo= github.com/mitchellh/osext v0.0.0-20151018003038-5e2d6d41470f/go.mod h1:OkQIRizQZAeMln+1tSwduZz7+Af5oFlKirV/MSYes2A= -github.com/mndrix/tap-go v0.0.0-20171203230836-629fa407e90b/go.mod h1:pzzDgJWZ34fGzaAZGFW22KVZDfyrYW+QABMrWnJBnSs= github.com/moby/locker v1.0.1/go.mod h1:S7SDdo5zpBK84bzzVlKr2V0hz+7x9hWbYC/kq7oQppc= github.com/moby/sys/mountinfo v0.4.0/go.mod h1:rEr8tzG/lsIZHBtN/JjGG+LMYx9eXgW2JI+6q0qou+A= github.com/moby/sys/mountinfo v0.4.1/go.mod h1:rEr8tzG/lsIZHBtN/JjGG+LMYx9eXgW2JI+6q0qou+A= @@ -844,7 +842,6 @@ github.com/rogpeppe/go-internal v1.2.2/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFR github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4= github.com/rogpeppe/go-internal v1.9.0 h1:73kH8U+JUqXU8lRuOHeVHaa/SZPifC7BkcraZVejAe8= github.com/russross/blackfriday/v2 v2.0.1/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= -github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/safchain/ethtool v0.0.0-20190326074333-42ed695e3de8/go.mod h1:Z0q5wiBQGYcxhMZ6gUqHn6pYNLypFAvaL3UvgZLR0U4= github.com/satori/go.uuid v1.2.0/go.mod h1:dA0hQrYB0VpLJoorglMZABFdXlWrHn1NEOzdhQKdks0= github.com/sclevine/spec v1.2.0/go.mod h1:W4J29eT/Kzv7/b9IWLB055Z+qvVC9vt0Arko24q7p+U= @@ -965,7 +962,6 @@ github.com/xeipuuv/gojsonreference v0.0.0-20180127040603-bd5ef7bd5415 h1:EzJWgHo github.com/xeipuuv/gojsonreference v0.0.0-20180127040603-bd5ef7bd5415/go.mod h1:GwrjFmJcFw6At/Gs6z4yjiIwzuJ1/+UwLxMQDVQXShQ= github.com/xeipuuv/gojsonschema v0.0.0-20180618132009-1d523034197f/go.mod h1:5yf86TLmAcydyeJq5YvxkGPE2fm/u4myDekKRoLuqhs= github.com/xeipuuv/gojsonschema v1.2.0 h1:LhYJRs+L4fBtjZUfuSZIKGeVu0QRy8e5Xi7D17UxZ74= -github.com/xeipuuv/gojsonschema v1.2.0/go.mod h1:anYRn/JVcOK2ZgGU+IjEV4nwlhoK5sQluxsYJ78Id3Y= github.com/xiang90/probing v0.0.0-20190116061207-43a291ad63a2/go.mod h1:UETIi67q53MR2AWcXfiuqkDkRtnGDLqkBTpCHuJHxtU= github.com/xordataexchange/crypt v0.0.3-0.20170626215501-b2862e3d0a77/go.mod h1:aYKd//L2LvnjZzWKhF00oedf4jCCReLcmhLdhm1A27Q= github.com/youmark/pkcs8 v0.0.0-20181117223130-1be2e3e5546d/go.mod h1:rHwXgn7JulP+udvsHwJoVG1YGAP6VLg4y9I5dyZdqmA=