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.

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

fix: don't panic when logs waits for more than 5 seconds #1777

Closed
wants to merge 14 commits into from
Closed
Changes from 6 commits
Commits
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
58 changes: 34 additions & 24 deletions docker.go
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ const (
ReaperDefault = "reaper_default" // Default network name when bridge is not available
packagePath = "github.com/testcontainers/testcontainers-go"

logStoppedForOutOfSyncMessage = "Stopping log consumer: Headers out of sync"
logRestartedForOutOfSyncMessage = "headers out of sync, will retry"
)

// DockerContainer represents a container started using Docker
Expand All @@ -66,7 +66,7 @@ type DockerContainer struct {
terminationSignal chan bool
consumers []LogConsumer
raw *types.ContainerJSON
stopProducer chan bool
stopProducer context.CancelFunc
logger Logging
lifecycleHooks []ContainerLifecycleHooks
}
Expand Down Expand Up @@ -615,9 +615,9 @@ func (c *DockerContainer) StartLogProducer(ctx context.Context) error {
return errors.New("log producer already started")
}

c.stopProducer = make(chan bool)
ctx, c.stopProducer = context.WithCancel(ctx)

go func(stop <-chan bool) {
go func() {
since := ""
// if the socket is closed we will make additional logs request with updated Since timestamp
BEGIN:
Expand All @@ -628,26 +628,30 @@ func (c *DockerContainer) StartLogProducer(ctx context.Context) error {
Since: since,
}

ctx, cancel := context.WithTimeout(ctx, time.Second*5)
defer cancel()

r, err := c.provider.client.ContainerLogs(ctx, c.GetContainerID(), options)
if err != nil {
// if we can't get the logs, panic, we can't return an error to anything
// from within this goroutine
panic(err)
// if we can't get the logs, retry in one second.
if ctx.Err() != nil {
// context done.
return
}
c.logger.Printf("cannot get logs for container %q: %v", c.ID, err)
time.Sleep(1 * time.Second)
mdelapenya marked this conversation as resolved.
Show resolved Hide resolved
mdelapenya marked this conversation as resolved.
Show resolved Hide resolved
goto BEGIN
}
defer c.provider.Close()

for {
select {
case <-stop:
if ctx.Err() != nil {
err := r.Close()
if err != nil {
// we can't close the read closer, this should never happen
panic(err)
}
return
}
mdelapenya marked this conversation as resolved.
Show resolved Hide resolved
select {
case <-ctx.Done():
continue
default:
h := make([]byte, 8)
_, err := io.ReadFull(r, h)
Expand All @@ -658,13 +662,15 @@ func (c *DockerContainer) StartLogProducer(ctx context.Context) error {
since = fmt.Sprintf("%d.%09d", now.Unix(), int64(now.Nanosecond()))
goto BEGIN
}
if errors.Is(err, context.DeadlineExceeded) {
// Probably safe to continue here
if errors.Is(err, context.DeadlineExceeded) || errors.Is(err, context.Canceled) {
// If the outer context is done, loop will exit in the next iteration.
continue
}
mdelapenya marked this conversation as resolved.
Show resolved Hide resolved
_, _ = fmt.Fprintf(os.Stderr, "container log error: %+v. %s", err, logStoppedForOutOfSyncMessage)
_, _ = fmt.Fprintf(os.Stderr, "read log header: %+v. %s", err, logRestartedForOutOfSyncMessage)
// if we would continue here, the next header-read will result into random data...
return
// we need to restart the whole request.
time.Sleep(1 * time.Second)
goto BEGIN
}

count := binary.BigEndian.Uint32(h[4:])
Expand All @@ -686,13 +692,16 @@ func (c *DockerContainer) StartLogProducer(ctx context.Context) error {
if err != nil {
// TODO: add-logger: use logger to log out this error
_, _ = fmt.Fprintf(os.Stderr, "error occurred reading log with known length %s", err.Error())
if errors.Is(err, context.DeadlineExceeded) {
// Probably safe to continue here

if errors.Is(err, context.DeadlineExceeded) || errors.Is(err, context.Canceled) {
mdelapenya marked this conversation as resolved.
Show resolved Hide resolved
// If the outer context is done, loop will exit in the next iteration.
continue
}
// we can not continue here as the next read most likely will not be the next header
_, _ = fmt.Fprintln(os.Stderr, logStoppedForOutOfSyncMessage)
return
// if we would continue here, the next header-read will result into random data...
// we need to restart the whole request.
_, _ = fmt.Fprintf(os.Stderr, "read log message: %+v. %s", err, logRestartedForOutOfSyncMessage)
time.Sleep(1 * time.Second)
mdelapenya marked this conversation as resolved.
Show resolved Hide resolved
goto BEGIN
}
for _, c := range c.consumers {
c.Accept(Log{
Expand All @@ -702,7 +711,7 @@ func (c *DockerContainer) StartLogProducer(ctx context.Context) error {
}
}
}
}(c.stopProducer)
}()

return nil
}
Expand All @@ -711,7 +720,8 @@ func (c *DockerContainer) StartLogProducer(ctx context.Context) error {
// and sending them to each added LogConsumer
func (c *DockerContainer) StopLogProducer() error {
if c.stopProducer != nil {
c.stopProducer <- true
// Cancel the producer's context.
c.stopProducer()
c.stopProducer = nil
}
return nil
Expand Down
Loading