Repository: moby/moby (language: go)

Issue:
non-blocking bug in AWSLogs driver code 
### Description

## non-blocking bug in AWSLogs driver code 

### Impact to AWS Customers

**Amazon ECS for EC2 only**. Amazon ECS on Fargate is not affected because as explained below, the log driver is always started in blocking mode and is wrapped by a buffer in non-blocking mode.

This can be seen in the aws/amazon-ecs-shim-loggers-for-containerd code, it initially starts the log driver in blocking mode always:

1. AWSLogs driver options are configured without mode thus using the default blocking mode: https://github.com/aws/amazon-ecs-shim-loggers-for-containerd/blob/4bcb0f7126a3eee95a31d8a93e3b0a0d2f7c3e91/logger/awslogs/logger.go#L132
2. Failure to create group/stream is logged and causes exit: https://github.com/aws/amazon-ecs-shim-loggers-for-containerd/blob/4bcb0f7126a3eee95a31d8a93e3b0a0d2f7c3e91/logger/awslogs/logger.go#L92
3. For non-blocking mode, after the log driver is initialized, it is wrapped by the shim logger implementation of the RingBuffer (largely copied from Docker code base): https://github.com/aws/amazon-ecs-shim-loggers-for-containerd/blob/4bcb0f7126a3eee95a31d8a93e3b0a0d2f7c3e91/logger/awslogs/logger.go#L108

See this comment for testing data on the bug's impact to log loss: https://github.com/moby/moby/issues/45217#issuecomment-1509272084

### Summary

Currently `non-blocking` mode has a bug that can cause unnecessary log loss in the AWSLogs driver and thus may not be safe for customers to use. Unless customers configure a large enough value for both `max-buffer-size` and `awslogs-max-buffered-events`, logs can be lost. As explained in the deep dive section below, setting `awslogs-max-buffered-events` should not be required to prevent log loss. 

This bug occurs because the AWSLogs driver code attempts to [handle the `non-blocking` behavior itself](https://github.com/moby/moby/blob/master/daemon/logger/awslogs/cloudwatchlogs.go#L440-L447) and drops events if its internal buffer is full. However, `non-blocking` mode is supposed to be implemented purely by the Docker [RingBuffer](https://github.com/moby/moby/blob/master/daemon/logger/ring.go#L160) which wraps the log driver. 

When this bug causes log loss, the following message will be logged in the Docker Daemon logs:

```
Mar 02 21:40:55 ip-10-192-11-106.us-west-2.compute.internal dockerd[12093]: 
 time="2023-03-02T21:40:55.527136424Z" 
 level=error msg="Error writing log message" 
 driver=awslogs error=" buffer is full"
```

### Deep Dive Explanation

![AWSLogs buffering (3)](https://user-images.githubusercontent.com/29443996/228090532-73f0a0b0-bfa1-49c0-943a-d8fbeaca2fff.png)


The above diagram shows the series of buffers when the AWSLogs driver is used in `non-blocking` mode. The `non-blocking` feature ensures that the stdout and stderr pipes do not block in the application container. This is achieved via the Docker [RingBuffer](https://github.com/moby/moby/blob/master/daemon/logger/ring.go#L160) which holds messages before the AWSLogs driver code is ready to accept them. While the Docker docs claim the oldest messages are removed when this buffer fills up, it is actually the newest message, see: [moby/moby:45200](https://github.com/moby/moby/issues/45200). The AWSLogs driver ingests the messages via its ingestion buffer which can be configured with `awslogs-max-buffered-events`. They are then moved to its send buffer for the API call to `cloudwatch:PutLogEvents`. 

The non-blocking behavior is implemented in Docker in the [RingBuffer](https://github.com/moby/moby/blob/master/daemon/logger/ring.go#L160). The [RingBuffer](https://github.com/moby/moby/blob/master/daemon/logger/ring.go#L160) holds messages and has a [goroutine which attempts to continually ingest messages into the actual log driver](https://github.com/moby/moby/blob/master/daemon/logger/ring.go#L129). The call to ingest the message into the log driver can/should block until the log driver is ready to uptake the message. 

Unfortunately, the AWSLogs code has a [custom code path for `non-blocking` mode](https://github.com/moby/moby/blob/master/daemon/logger/awslogs/cloudwatchlogs.go#L440-L447) wherein it discards the message if the call to uptake it from the [RingBuffer](https://github.com/moby/moby/blob/master/daemon/logger/ring.go#L160) would block. This means that messages are discarded if the ingestion buffer controlled by `awslogs-max-buffered-events` is full. This is entirely unnecessary and undesirable because the `non-blocking` behavior and discarding of messages is supposed to be implemented solely by the Docker [RingBuffer](https://github.com/moby/moby/blob/master/daemon/logger/ring.go#L160). *None of the other log drivers have custom code paths for `non-blocking` mode.* 


### Solution

Simply remove the lines of code here in the **Docker** upstream code base: https://github.com/moby/moby/blob/master/daemon/logger/awslogs/cloudwatchlogs.go#L440-L447

And test the change.


### Reproduce

See above issue/design doc

### Expected behavior

non-blocking is handled entirely by RingBuffer and not in the AWSLogs Driver code. AWSLogs should not proactively lose logs when its internal buffer is full. 

### docker version

```bash
All.
```


### docker info

```bash
All.
```


### Additional Info

I will work on fixing this. 


Discussion / hints:
Please assign this issue to me, I will be working on fixing it this week/next. 
We are unable to assign but we added the "claimed" label to the issue. Thanks!

Fix patch:
diff --git a/daemon/logger/awslogs/cloudwatchlogs.go b/daemon/logger/awslogs/cloudwatchlogs.go
index 28fc0c2afc506..0caae0a8b8e2e 100644
--- a/daemon/logger/awslogs/cloudwatchlogs.go
+++ b/daemon/logger/awslogs/cloudwatchlogs.go
@@ -73,7 +73,6 @@ type logStream struct {
 	logGroupName       string
 	logCreateGroup     bool
 	logCreateStream    bool
-	logNonBlocking     bool
 	forceFlushInterval time.Duration
 	multilinePattern   *regexp.Regexp
 	client             api
@@ -88,7 +87,6 @@ type logStreamConfig struct {
 	logGroupName       string
 	logCreateGroup     bool
 	logCreateStream    bool
-	logNonBlocking     bool
 	forceFlushInterval time.Duration
 	maxBufferedEvents  int
 	multilinePattern   *regexp.Regexp
@@ -150,12 +148,13 @@ func New(info logger.Info) (logger.Logger, error) {
 		return nil, err
 	}
 
+	logNonBlocking := info.Config["mode"] == "non-blocking"
+
 	containerStream := &logStream{
 		logStreamName:      containerStreamConfig.logStreamName,
 		logGroupName:       containerStreamConfig.logGroupName,
 		logCreateGroup:     containerStreamConfig.logCreateGroup,
 		logCreateStream:    containerStreamConfig.logCreateStream,
-		logNonBlocking:     containerStreamConfig.logNonBlocking,
 		forceFlushInterval: containerStreamConfig.forceFlushInterval,
 		multilinePattern:   containerStreamConfig.multilinePattern,
 		client:             client,
@@ -163,7 +162,7 @@ func New(info logger.Info) (logger.Logger, error) {
 	}
 
 	creationDone := make(chan bool)
-	if containerStream.logNonBlocking {
+	if logNonBlocking {
 		go func() {
 			backoff := 1
 			maxBackoff := 32
@@ -219,8 +218,6 @@ func newStreamConfig(info logger.Info) (*logStreamConfig, error) {
 		}
 	}
 
-	logNonBlocking := info.Config["mode"] == "non-blocking"
-
 	forceFlushInterval := defaultForceFlushInterval
 	if info.Config[forceFlushIntervalKey] != "" {
 		forceFlushIntervalAsInt, err := strconv.Atoi(info.Config[forceFlushIntervalKey])
@@ -259,7 +256,6 @@ func newStreamConfig(info logger.Info) (*logStreamConfig, error) {
 		logGroupName:       logGroupName,
 		logCreateGroup:     logCreateGroup,
 		logCreateStream:    logCreateStream,
-		logNonBlocking:     logNonBlocking,
 		forceFlushInterval: forceFlushInterval,
 		maxBufferedEvents:  maxBufferedEvents,
 		multilinePattern:   multilinePattern,
@@ -437,14 +433,6 @@ func (l *logStream) Log(msg *logger.Message) error {
 	if l.closed {
 		return errors.New("awslogs is closed")
 	}
-	if l.logNonBlocking {
-		select {
-		case l.messages <- msg:
-			return nil
-		default:
-			return errors.New("awslogs buffer is full")
-		}
-	}
 	l.messages <- msg
 	return nil
 }


Test patch:
diff --git a/daemon/logger/awslogs/cloudwatchlogs_test.go b/daemon/logger/awslogs/cloudwatchlogs_test.go
index 1502732d2f78f..b0833c1853a24 100644
--- a/daemon/logger/awslogs/cloudwatchlogs_test.go
+++ b/daemon/logger/awslogs/cloudwatchlogs_test.go
@@ -404,40 +404,16 @@ func TestLogBlocking(t *testing.T) {
 	}
 }
 
-func TestLogNonBlockingBufferEmpty(t *testing.T) {
+func TestLogBufferEmpty(t *testing.T) {
 	mockClient := &mockClient{}
 	stream := &logStream{
-		client:         mockClient,
-		messages:       make(chan *logger.Message, 1),
-		logNonBlocking: true,
+		client:   mockClient,
+		messages: make(chan *logger.Message, 1),
 	}
 	err := stream.Log(&logger.Message{})
 	assert.NilError(t, err)
 }
 
-func TestLogNonBlockingBufferFull(t *testing.T) {
-	mockClient := &mockClient{}
-	stream := &logStream{
-		client:         mockClient,
-		messages:       make(chan *logger.Message, 1),
-		logNonBlocking: true,
-	}
-	stream.messages <- &logger.Message{}
-	errorCh := make(chan error, 1)
-	started := make(chan bool)
-	go func() {
-		started <- true
-		err := stream.Log(&logger.Message{})
-		errorCh <- err
-	}()
-	<-started
-	select {
-	case err := <-errorCh:
-		assert.Check(t, err != nil)
-	case <-time.After(30 * time.Second):
-		t.Fatal("Expected Log call to not block")
-	}
-}
 func TestPublishBatchSuccess(t *testing.T) {
 	mockClient := &mockClient{}
 	stream := &logStream{