From 316a161ce8a786b01e8aca5f00f346e856c78ff6 Mon Sep 17 00:00:00 2001 From: Mahmood Ali Date: Mon, 15 Apr 2019 21:20:09 -0400 Subject: [PATCH 1/2] open fifo on background goroutine --- drivers/docker/docklog/docker_logger.go | 77 +++++++++++++++++-------- 1 file changed, 53 insertions(+), 24 deletions(-) diff --git a/drivers/docker/docklog/docker_logger.go b/drivers/docker/docklog/docker_logger.go index 0567a5e5f16f..4174dd04c2a9 100644 --- a/drivers/docker/docklog/docker_logger.go +++ b/drivers/docker/docklog/docker_logger.go @@ -5,6 +5,7 @@ import ( "io" "math/rand" "strings" + "sync" "time" docker "github.com/fsouza/go-dockerclient" @@ -56,11 +57,12 @@ func NewDockerLogger(logger hclog.Logger) DockerLogger { type dockerLogger struct { logger hclog.Logger - stdout io.WriteCloser - stderr io.WriteCloser - cancelCtx context.CancelFunc + stdout io.WriteCloser + stderr io.WriteCloser + stdLock sync.Mutex - doneCh chan interface{} + cancelCtx context.CancelFunc + doneCh chan interface{} } // Start log monitoring @@ -70,26 +72,18 @@ func (d *dockerLogger) Start(opts *StartOpts) error { return fmt.Errorf("failed to open docker client: %v", err) } - if d.stdout == nil { - stdout, err := fifo.OpenWriter(opts.Stdout) - if err != nil { - return fmt.Errorf("failed to open fifo for path %s: %v", opts.Stdout, err) - } - d.stdout = stdout - } - if d.stderr == nil { - stderr, err := fifo.OpenWriter(opts.Stderr) - if err != nil { - return fmt.Errorf("failed to open fifo for path %s: %v", opts.Stdout, err) - } - d.stderr = stderr - } ctx, cancel := context.WithCancel(context.Background()) d.cancelCtx = cancel go func() { defer close(d.doneCh) + stdout, stderr, err := d.openStreams(opts) + if err != nil { + d.logger.Error("log streaming ended with terminal error", "error", err) + return + } + sinceTime := time.Unix(opts.StartTime, 0) backoff := 0.0 @@ -97,8 +91,8 @@ func (d *dockerLogger) Start(opts *StartOpts) error { logOpts := docker.LogsOptions{ Context: ctx, Container: opts.ContainerID, - OutputStream: d.stdout, - ErrorStream: d.stderr, + OutputStream: stdout, + ErrorStream: stderr, Since: sinceTime.Unix(), Follow: true, Stdout: true, @@ -138,16 +132,51 @@ func (d *dockerLogger) Start(opts *StartOpts) error { } +func (d *dockerLogger) openStreams(opts *StartOpts) (stdout, stderr io.WriteCloser, err error) { + d.stdLock.Lock() + stdoutF, stderrF := d.stdout, d.stderr + d.stdLock.Unlock() + + if stdoutF != nil && stderrF != nil { + return stdoutF, stderrF, nil + } + + if stdoutF == nil { + stdoutF, err = fifo.OpenWriter(opts.Stdout) + if err != nil { + return nil, nil, err + } + } + + if stderrF == nil { + stderrF, err = fifo.OpenWriter(opts.Stderr) + if err != nil { + return nil, nil, err + } + } + + d.stdLock.Lock() + d.stdout, d.stderr = stdoutF, stderrF + d.stdLock.Unlock() + + return stdoutF, stderrF, nil +} + // Stop log monitoring func (d *dockerLogger) Stop() error { if d.cancelCtx != nil { d.cancelCtx() } - if d.stdout != nil { - d.stdout.Close() + + d.stdLock.Lock() + stdout, stderr := d.stdout, d.stderr + d.stdLock.Unlock() + + if stdout != nil { + stdout.Close() } - if d.stderr != nil { - d.stderr.Close() + if stderr != nil { + stderr.Close() } return nil } From 96a54cbbd34c5c41c028466908738299b045f7e3 Mon Sep 17 00:00:00 2001 From: Mahmood Ali Date: Tue, 16 Apr 2019 10:48:25 -0400 Subject: [PATCH 2/2] locking and opening streams in goroutine comment --- drivers/docker/docklog/docker_logger.go | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/drivers/docker/docklog/docker_logger.go b/drivers/docker/docklog/docker_logger.go index 4174dd04c2a9..040ea78c6d5d 100644 --- a/drivers/docker/docklog/docker_logger.go +++ b/drivers/docker/docklog/docker_logger.go @@ -78,7 +78,7 @@ func (d *dockerLogger) Start(opts *StartOpts) error { go func() { defer close(d.doneCh) - stdout, stderr, err := d.openStreams(opts) + stdout, stderr, err := d.openStreams(ctx, opts) if err != nil { d.logger.Error("log streaming ended with terminal error", "error", err) return @@ -132,7 +132,9 @@ func (d *dockerLogger) Start(opts *StartOpts) error { } -func (d *dockerLogger) openStreams(opts *StartOpts) (stdout, stderr io.WriteCloser, err error) { +// openStreams open logger stdout/stderr; should be called in a background goroutine to avoid locking up +// process to avoid locking goroutine process +func (d *dockerLogger) openStreams(ctx context.Context, opts *StartOpts) (stdout, stderr io.WriteCloser, err error) { d.stdLock.Lock() stdoutF, stderrF := d.stdout, d.stderr d.stdLock.Unlock() @@ -141,6 +143,10 @@ func (d *dockerLogger) openStreams(opts *StartOpts) (stdout, stderr io.WriteClos return stdoutF, stderrF, nil } + // opening a fifo may block indefinitely until a reader end opens, so + // we preform open() without holding the stdLock, so Stop and interleave. + // This a defensive measure - logmon (the reader end) should be up and + // started before dockerLogger is started if stdoutF == nil { stdoutF, err = fifo.OpenWriter(opts.Stdout) if err != nil { @@ -155,6 +161,13 @@ func (d *dockerLogger) openStreams(opts *StartOpts) (stdout, stderr io.WriteClos } } + if ctx.Err() != nil { + // Stop was called and don't need files anymore + stdoutF.Close() + stderrF.Close() + return nil, nil, ctx.Err() + } + d.stdLock.Lock() d.stdout, d.stderr = stdoutF, stderrF d.stdLock.Unlock()