From 732a1a78e2b045b3ecee58973cafc778d3bd03b8 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Wed, 1 Mar 2023 15:00:18 +0100 Subject: [PATCH 1/6] internal/libdocker: get container output through logs API --- internal/libdocker/container.go | 120 +++++++++++++++++++++----------- 1 file changed, 80 insertions(+), 40 deletions(-) diff --git a/internal/libdocker/container.go b/internal/libdocker/container.go index 849bd7bae4..451165507a 100644 --- a/internal/libdocker/container.go +++ b/internal/libdocker/container.go @@ -331,49 +331,47 @@ func (b *ContainerBackend) uploadFiles(ctx context.Context, id string, files map // starts executing the container and returns the CloseWaiter to allow the caller // to wait for termination. func (b *ContainerBackend) runContainer(ctx context.Context, logger log15.Logger, id string, opts libhive.ContainerOptions) (docker.CloseWaiter, error) { - var ( - outStream io.Writer - errStream io.Writer - closer = newFileCloser(logger) - ) - + var closer *fileCloser + var err error switch { case opts.Output != nil && opts.LogFile != "": return nil, fmt.Errorf("can't use LogFile and Output options at the same time") - case opts.Output != nil: - outStream = opts.Output - closer.addFile(opts.Output) + closer, err = b.attachIO(ctx, logger, id, opts) + case opts.LogFile != "": + closer, err = b.attachLogs(ctx, logger, id, opts) + } + if err != nil { + if closer != nil { + closer.Close() + } + return nil, err + } - // If console logging is requested, dump stderr there. - if b.config.ContainerOutput != nil { - prefixer := newLinePrefixWriter(b.config.ContainerOutput, fmt.Sprintf("[%s] ", id[:8])) - closer.addFile(prefixer) - errStream = prefixer + logger.Debug("starting container") + if err := b.client.StartContainerWithContext(id, nil, ctx); err != nil { + closer.Close() + logger.Error("failed to start container", "err", err) + return nil, err + } + return closer, nil +} - // outStream = io.MultiWriter(outStream, prefixer) - } +func (b *ContainerBackend) attachIO(ctx context.Context, logger log15.Logger, id string, opts libhive.ContainerOptions) (*fileCloser, error) { + var ( + outStream io.Writer + errStream io.Writer + closer = newFileCloser(logger) + ) + closer.addFile(opts.Output) + outStream = opts.Output - case opts.LogFile != "": - // Redirect container output to logfile. - if err := os.MkdirAll(filepath.Dir(opts.LogFile), 0755); err != nil { - return nil, err - } - log, err := os.OpenFile(opts.LogFile, os.O_WRONLY|os.O_CREATE|os.O_SYNC|os.O_TRUNC, 0644) - if err != nil { - return nil, err - } - closer.addFile(log) - outStream = log - - // If console logging was requested, tee the output and tag it with the container id. - if b.config.ContainerOutput != nil { - prefixer := newLinePrefixWriter(b.config.ContainerOutput, fmt.Sprintf("[%s] ", id[:8])) - closer.addFile(prefixer) - outStream = io.MultiWriter(log, prefixer) - } - // In LogFile mode, stderr is redirected to stdout. - errStream = outStream + // If console logging is requested, dump stderr there. + if b.config.ContainerOutput != nil { + prefixer := newLinePrefixWriter(b.config.ContainerOutput, fmt.Sprintf("[%s] ", id[:8])) + closer.addFile(prefixer) + errStream = prefixer + // outStream = io.MultiWriter(outStream, prefixer) } // Configure the streams and attach. @@ -401,16 +399,58 @@ func (b *ContainerBackend) runContainer(ctx context.Context, logger log15.Logger return nil, err } closer.w = waiter + return closer, nil +} - logger.Debug("starting container") - if err := b.client.StartContainerWithContext(id, nil, ctx); err != nil { - closer.Close() - logger.Error("failed to start container", "err", err) +func (b *ContainerBackend) attachLogs(ctx context.Context, logger log15.Logger, id string, opts libhive.ContainerOptions) (*fileCloser, error) { + if opts.Input != nil { + return nil, fmt.Errorf("container input is not supported in logFile mode") + } + if err := os.MkdirAll(filepath.Dir(opts.LogFile), 0755); err != nil { + return nil, err + } + log, err := os.OpenFile(opts.LogFile, os.O_WRONLY|os.O_CREATE|os.O_TRUNC, 0644) + if err != nil { return nil, err } + + closer := new(fileCloser) + closer.addFile(log) + logopt := docker.LogsOptions{ + Context: ctx, + Container: id, + Timestamps: true, + Follow: true, + OutputStream: log, + ErrorStream: log, + } + var wg wgCloseWaiter + wg.Add(1) + go func() { + defer wg.Done() + wg.err = b.client.Logs(logopt) + if err != nil { + logger.Error("client log stream failed", "err", err) + } + }() + closer.w = &wg return closer, nil } +type wgCloseWaiter struct { + sync.WaitGroup + err error +} + +func (w *wgCloseWaiter) Wait() error { + w.WaitGroup.Wait() + return w.err +} + +func (w *wgCloseWaiter) Close() error { + return nil +} + // fileCloser wraps a docker.CloseWaiter and closes all io.Closer instances held in it, // after it is done waiting. type fileCloser struct { From 2fe8b0364157be124aeab54d6ffb90c38933e147 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Wed, 1 Mar 2023 14:42:26 +0000 Subject: [PATCH 2/6] internal/libdocker: attach to container after starting it --- internal/libdocker/container.go | 27 ++++++++++++++++----------- 1 file changed, 16 insertions(+), 11 deletions(-) diff --git a/internal/libdocker/container.go b/internal/libdocker/container.go index 451165507a..1e80cc5ec3 100644 --- a/internal/libdocker/container.go +++ b/internal/libdocker/container.go @@ -331,6 +331,12 @@ func (b *ContainerBackend) uploadFiles(ctx context.Context, id string, files map // starts executing the container and returns the CloseWaiter to allow the caller // to wait for termination. func (b *ContainerBackend) runContainer(ctx context.Context, logger log15.Logger, id string, opts libhive.ContainerOptions) (docker.CloseWaiter, error) { + logger.Debug("starting container") + if err := b.client.StartContainerWithContext(id, nil, ctx); err != nil { + logger.Error("failed to start container", "err", err) + return nil, err + } + var closer *fileCloser var err error switch { @@ -347,13 +353,6 @@ func (b *ContainerBackend) runContainer(ctx context.Context, logger log15.Logger } return nil, err } - - logger.Debug("starting container") - if err := b.client.StartContainerWithContext(id, nil, ctx); err != nil { - closer.Close() - logger.Error("failed to start container", "err", err) - return nil, err - } return closer, nil } @@ -416,21 +415,27 @@ func (b *ContainerBackend) attachLogs(ctx context.Context, logger log15.Logger, closer := new(fileCloser) closer.addFile(log) + logopt := docker.LogsOptions{ Context: ctx, Container: id, - Timestamps: true, - Follow: true, OutputStream: log, ErrorStream: log, + Follow: true, + Timestamps: true, + Stdout: true, + Stderr: true, } var wg wgCloseWaiter wg.Add(1) go func() { + logger.Debug("reading container logs") defer wg.Done() - wg.err = b.client.Logs(logopt) + err := b.client.Logs(logopt) if err != nil { - logger.Error("client log stream failed", "err", err) + wg.err = err + logger.Error("container log stream failed", "err", err) + return } }() closer.w = &wg From 1c714e08284ffd54e4a1a3cfec1b32aa1819b7ff Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Wed, 1 Mar 2023 14:42:45 +0000 Subject: [PATCH 3/6] internal/libdocker: flush log file --- internal/libdocker/container.go | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/internal/libdocker/container.go b/internal/libdocker/container.go index 1e80cc5ec3..7859b42cf1 100644 --- a/internal/libdocker/container.go +++ b/internal/libdocker/container.go @@ -456,6 +456,10 @@ func (w *wgCloseWaiter) Close() error { return nil } +type flusher interface { + Flush() error +} + // fileCloser wraps a docker.CloseWaiter and closes all io.Closer instances held in it, // after it is done waiting. type fileCloser struct { @@ -488,6 +492,9 @@ func (w *fileCloser) addFile(c io.Closer) { func (w *fileCloser) closeFiles() { w.closeOnce.Do(func() { for _, closer := range w.closers { + if f, ok := closer.(flusher); ok { + f.Flush() + } if err := closer.Close(); err != nil { w.logger.Error("failed to close fd", "err", err) } From 89ac011e8e03b3f82867e13d114a49e4da488194 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Wed, 1 Mar 2023 14:44:25 +0000 Subject: [PATCH 4/6] internal/libdocker: remove context in logs request --- internal/libdocker/container.go | 1 - 1 file changed, 1 deletion(-) diff --git a/internal/libdocker/container.go b/internal/libdocker/container.go index 7859b42cf1..55972e5b76 100644 --- a/internal/libdocker/container.go +++ b/internal/libdocker/container.go @@ -417,7 +417,6 @@ func (b *ContainerBackend) attachLogs(ctx context.Context, logger log15.Logger, closer.addFile(log) logopt := docker.LogsOptions{ - Context: ctx, Container: id, OutputStream: log, ErrorStream: log, From fb7725048671719649c4da3d6400099689198823 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Wed, 1 Mar 2023 14:45:56 +0000 Subject: [PATCH 5/6] internal/libdocker: remove log timestamps (for now) --- internal/libdocker/container.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/libdocker/container.go b/internal/libdocker/container.go index 55972e5b76..d621ff1274 100644 --- a/internal/libdocker/container.go +++ b/internal/libdocker/container.go @@ -421,9 +421,9 @@ func (b *ContainerBackend) attachLogs(ctx context.Context, logger log15.Logger, OutputStream: log, ErrorStream: log, Follow: true, - Timestamps: true, Stdout: true, Stderr: true, + // Timestamps: true, } var wg wgCloseWaiter wg.Add(1) From 9158713371e48a74e16f666c49c7484cd724e90e Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Thu, 2 Mar 2023 11:50:04 +0100 Subject: [PATCH 6/6] internal/libdocker: configure log buffering --- internal/libdocker/container.go | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/internal/libdocker/container.go b/internal/libdocker/container.go index d621ff1274..658f8fe907 100644 --- a/internal/libdocker/container.go +++ b/internal/libdocker/container.go @@ -98,6 +98,16 @@ func (b *ContainerBackend) CreateContainer(ctx context.Context, imageName string // but it's probably best to give Docker the info as early as possible. createOpts.Config.AttachStdout = true } + if opt.LogFile != "" { + createOpts.HostConfig = &docker.HostConfig{ + LogConfig: docker.LogConfig{ + Config: map[string]string{ + "mode": "non-blocking", + "max-buffer-size": "4m", + }, + }, + } + } c, err := b.client.CreateContainer(createOpts) if err != nil {