github.com/jwhonce/docker@v0.6.7-0.20190327063223-da823cf3a5a3/daemon/logger/awslogs/cloudwatchlogs_test.go (about)

     1  package awslogs // import "github.com/docker/docker/daemon/logger/awslogs"
     2  
     3  import (
     4  	"errors"
     5  	"fmt"
     6  	"io/ioutil"
     7  	"net/http"
     8  	"net/http/httptest"
     9  	"os"
    10  	"reflect"
    11  	"regexp"
    12  	"runtime"
    13  	"strconv"
    14  	"strings"
    15  	"testing"
    16  	"time"
    17  
    18  	"github.com/aws/aws-sdk-go/aws"
    19  	"github.com/aws/aws-sdk-go/aws/awserr"
    20  	"github.com/aws/aws-sdk-go/aws/request"
    21  	"github.com/aws/aws-sdk-go/service/cloudwatchlogs"
    22  	"github.com/docker/docker/daemon/logger"
    23  	"github.com/docker/docker/daemon/logger/loggerutils"
    24  	"github.com/docker/docker/dockerversion"
    25  	"gotest.tools/assert"
    26  	is "gotest.tools/assert/cmp"
    27  )
    28  
    29  const (
    30  	groupName         = "groupName"
    31  	streamName        = "streamName"
    32  	sequenceToken     = "sequenceToken"
    33  	nextSequenceToken = "nextSequenceToken"
    34  	logline           = "this is a log line\r"
    35  	multilineLogline  = "2017-01-01 01:01:44 This is a multiline log entry\r"
    36  )
    37  
    38  // Generates i multi-line events each with j lines
    39  func (l *logStream) logGenerator(lineCount int, multilineCount int) {
    40  	for i := 0; i < multilineCount; i++ {
    41  		l.Log(&logger.Message{
    42  			Line:      []byte(multilineLogline),
    43  			Timestamp: time.Time{},
    44  		})
    45  		for j := 0; j < lineCount; j++ {
    46  			l.Log(&logger.Message{
    47  				Line:      []byte(logline),
    48  				Timestamp: time.Time{},
    49  			})
    50  		}
    51  	}
    52  }
    53  
    54  func testEventBatch(events []wrappedEvent) *eventBatch {
    55  	batch := newEventBatch()
    56  	for _, event := range events {
    57  		eventlen := len([]byte(*event.inputLogEvent.Message))
    58  		batch.add(event, eventlen)
    59  	}
    60  	return batch
    61  }
    62  
    63  func TestNewStreamConfig(t *testing.T) {
    64  	tests := []struct {
    65  		logStreamName      string
    66  		logGroupName       string
    67  		logCreateGroup     string
    68  		logNonBlocking     string
    69  		forceFlushInterval string
    70  		maxBufferedEvents  string
    71  		datetimeFormat     string
    72  		multilinePattern   string
    73  		shouldErr          bool
    74  		testName           string
    75  	}{
    76  		{"", groupName, "", "", "", "", "", "", false, "defaults"},
    77  		{"", groupName, "invalid create group", "", "", "", "", "", true, "invalid create group"},
    78  		{"", groupName, "", "", "invalid flush interval", "", "", "", true, "invalid flush interval"},
    79  		{"", groupName, "", "", "", "invalid max buffered events", "", "", true, "invalid max buffered events"},
    80  		{"", groupName, "", "", "", "", "", "n{1001}", true, "invalid multiline pattern"},
    81  		{"", groupName, "", "", "15", "", "", "", false, "flush interval at 15"},
    82  		{"", groupName, "", "", "", "1024", "", "", false, "max buffered events at 1024"},
    83  	}
    84  
    85  	for _, tc := range tests {
    86  		t.Run(tc.testName, func(t *testing.T) {
    87  			cfg := map[string]string{
    88  				logGroupKey:           tc.logGroupName,
    89  				logCreateGroupKey:     tc.logCreateGroup,
    90  				"mode":                tc.logNonBlocking,
    91  				forceFlushIntervalKey: tc.forceFlushInterval,
    92  				maxBufferedEventsKey:  tc.maxBufferedEvents,
    93  				logStreamKey:          tc.logStreamName,
    94  				datetimeFormatKey:     tc.datetimeFormat,
    95  				multilinePatternKey:   tc.multilinePattern,
    96  			}
    97  
    98  			info := logger.Info{
    99  				Config: cfg,
   100  			}
   101  			logStreamConfig, err := newStreamConfig(info)
   102  			if tc.shouldErr {
   103  				assert.Check(t, err != nil, "Expected an error")
   104  			} else {
   105  				assert.Check(t, err == nil, "Unexpected error")
   106  				assert.Check(t, logStreamConfig.logGroupName == tc.logGroupName, "Unexpected logGroupName")
   107  				if tc.forceFlushInterval != "" {
   108  					forceFlushIntervalAsInt, _ := strconv.Atoi(info.Config[forceFlushIntervalKey])
   109  					assert.Check(t, logStreamConfig.forceFlushInterval == time.Duration(forceFlushIntervalAsInt)*time.Second, "Unexpected forceFlushInterval")
   110  				}
   111  				if tc.maxBufferedEvents != "" {
   112  					maxBufferedEvents, _ := strconv.Atoi(info.Config[maxBufferedEventsKey])
   113  					assert.Check(t, logStreamConfig.maxBufferedEvents == maxBufferedEvents, "Unexpected maxBufferedEvents")
   114  				}
   115  			}
   116  		})
   117  	}
   118  }
   119  
   120  func TestNewAWSLogsClientUserAgentHandler(t *testing.T) {
   121  	info := logger.Info{
   122  		Config: map[string]string{
   123  			regionKey: "us-east-1",
   124  		},
   125  	}
   126  
   127  	client, err := newAWSLogsClient(info)
   128  	assert.NilError(t, err)
   129  
   130  	realClient, ok := client.(*cloudwatchlogs.CloudWatchLogs)
   131  	assert.Check(t, ok, "Could not cast client to cloudwatchlogs.CloudWatchLogs")
   132  
   133  	buildHandlerList := realClient.Handlers.Build
   134  	request := &request.Request{
   135  		HTTPRequest: &http.Request{
   136  			Header: http.Header{},
   137  		},
   138  	}
   139  	buildHandlerList.Run(request)
   140  	expectedUserAgentString := fmt.Sprintf("Docker %s (%s) %s/%s (%s; %s; %s)",
   141  		dockerversion.Version, runtime.GOOS, aws.SDKName, aws.SDKVersion, runtime.Version(), runtime.GOOS, runtime.GOARCH)
   142  	userAgent := request.HTTPRequest.Header.Get("User-Agent")
   143  	if userAgent != expectedUserAgentString {
   144  		t.Errorf("Wrong User-Agent string, expected \"%s\" but was \"%s\"",
   145  			expectedUserAgentString, userAgent)
   146  	}
   147  }
   148  
   149  func TestNewAWSLogsClientAWSLogsEndpoint(t *testing.T) {
   150  	endpoint := "mock-endpoint"
   151  	info := logger.Info{
   152  		Config: map[string]string{
   153  			regionKey:   "us-east-1",
   154  			endpointKey: endpoint,
   155  		},
   156  	}
   157  
   158  	client, err := newAWSLogsClient(info)
   159  	assert.NilError(t, err)
   160  
   161  	realClient, ok := client.(*cloudwatchlogs.CloudWatchLogs)
   162  	assert.Check(t, ok, "Could not cast client to cloudwatchlogs.CloudWatchLogs")
   163  
   164  	endpointWithScheme := realClient.Endpoint
   165  	expectedEndpointWithScheme := "https://" + endpoint
   166  	assert.Equal(t, endpointWithScheme, expectedEndpointWithScheme, "Wrong endpoint")
   167  }
   168  
   169  func TestNewAWSLogsClientRegionDetect(t *testing.T) {
   170  	info := logger.Info{
   171  		Config: map[string]string{},
   172  	}
   173  
   174  	mockMetadata := newMockMetadataClient()
   175  	newRegionFinder = func() regionFinder {
   176  		return mockMetadata
   177  	}
   178  	mockMetadata.regionResult <- &regionResult{
   179  		successResult: "us-east-1",
   180  	}
   181  
   182  	_, err := newAWSLogsClient(info)
   183  	assert.NilError(t, err)
   184  }
   185  
   186  func TestCreateSuccess(t *testing.T) {
   187  	mockClient := newMockClient()
   188  	stream := &logStream{
   189  		client:        mockClient,
   190  		logGroupName:  groupName,
   191  		logStreamName: streamName,
   192  	}
   193  	mockClient.createLogStreamResult <- &createLogStreamResult{}
   194  
   195  	err := stream.create()
   196  
   197  	if err != nil {
   198  		t.Errorf("Received unexpected err: %v\n", err)
   199  	}
   200  	argument := <-mockClient.createLogStreamArgument
   201  	if argument.LogGroupName == nil {
   202  		t.Fatal("Expected non-nil LogGroupName")
   203  	}
   204  	if *argument.LogGroupName != groupName {
   205  		t.Errorf("Expected LogGroupName to be %s", groupName)
   206  	}
   207  	if argument.LogStreamName == nil {
   208  		t.Fatal("Expected non-nil LogStreamName")
   209  	}
   210  	if *argument.LogStreamName != streamName {
   211  		t.Errorf("Expected LogStreamName to be %s", streamName)
   212  	}
   213  }
   214  
   215  func TestCreateLogGroupSuccess(t *testing.T) {
   216  	mockClient := newMockClient()
   217  	stream := &logStream{
   218  		client:         mockClient,
   219  		logGroupName:   groupName,
   220  		logStreamName:  streamName,
   221  		logCreateGroup: true,
   222  	}
   223  	mockClient.createLogGroupResult <- &createLogGroupResult{}
   224  	mockClient.createLogStreamResult <- &createLogStreamResult{}
   225  
   226  	err := stream.create()
   227  
   228  	if err != nil {
   229  		t.Errorf("Received unexpected err: %v\n", err)
   230  	}
   231  	argument := <-mockClient.createLogStreamArgument
   232  	if argument.LogGroupName == nil {
   233  		t.Fatal("Expected non-nil LogGroupName")
   234  	}
   235  	if *argument.LogGroupName != groupName {
   236  		t.Errorf("Expected LogGroupName to be %s", groupName)
   237  	}
   238  	if argument.LogStreamName == nil {
   239  		t.Fatal("Expected non-nil LogStreamName")
   240  	}
   241  	if *argument.LogStreamName != streamName {
   242  		t.Errorf("Expected LogStreamName to be %s", streamName)
   243  	}
   244  }
   245  
   246  func TestCreateError(t *testing.T) {
   247  	mockClient := newMockClient()
   248  	stream := &logStream{
   249  		client: mockClient,
   250  	}
   251  	mockClient.createLogStreamResult <- &createLogStreamResult{
   252  		errorResult: errors.New("Error"),
   253  	}
   254  
   255  	err := stream.create()
   256  
   257  	if err == nil {
   258  		t.Fatal("Expected non-nil err")
   259  	}
   260  }
   261  
   262  func TestCreateAlreadyExists(t *testing.T) {
   263  	mockClient := newMockClient()
   264  	stream := &logStream{
   265  		client: mockClient,
   266  	}
   267  	mockClient.createLogStreamResult <- &createLogStreamResult{
   268  		errorResult: awserr.New(resourceAlreadyExistsCode, "", nil),
   269  	}
   270  
   271  	err := stream.create()
   272  
   273  	assert.NilError(t, err)
   274  }
   275  
   276  func TestLogClosed(t *testing.T) {
   277  	mockClient := newMockClient()
   278  	stream := &logStream{
   279  		client: mockClient,
   280  		closed: true,
   281  	}
   282  	err := stream.Log(&logger.Message{})
   283  	if err == nil {
   284  		t.Fatal("Expected non-nil error")
   285  	}
   286  }
   287  
   288  func TestLogBlocking(t *testing.T) {
   289  	mockClient := newMockClient()
   290  	stream := &logStream{
   291  		client:   mockClient,
   292  		messages: make(chan *logger.Message),
   293  	}
   294  
   295  	errorCh := make(chan error, 1)
   296  	started := make(chan bool)
   297  	go func() {
   298  		started <- true
   299  		err := stream.Log(&logger.Message{})
   300  		errorCh <- err
   301  	}()
   302  	<-started
   303  	select {
   304  	case err := <-errorCh:
   305  		t.Fatal("Expected stream.Log to block: ", err)
   306  	default:
   307  		break
   308  	}
   309  	select {
   310  	case <-stream.messages:
   311  		break
   312  	default:
   313  		t.Fatal("Expected to be able to read from stream.messages but was unable to")
   314  	}
   315  	select {
   316  	case err := <-errorCh:
   317  		assert.NilError(t, err)
   318  
   319  	case <-time.After(30 * time.Second):
   320  		t.Fatal("timed out waiting for read")
   321  	}
   322  }
   323  
   324  func TestLogNonBlockingBufferEmpty(t *testing.T) {
   325  	mockClient := newMockClient()
   326  	stream := &logStream{
   327  		client:         mockClient,
   328  		messages:       make(chan *logger.Message, 1),
   329  		logNonBlocking: true,
   330  	}
   331  	err := stream.Log(&logger.Message{})
   332  	assert.NilError(t, err)
   333  }
   334  
   335  func TestLogNonBlockingBufferFull(t *testing.T) {
   336  	mockClient := newMockClient()
   337  	stream := &logStream{
   338  		client:         mockClient,
   339  		messages:       make(chan *logger.Message, 1),
   340  		logNonBlocking: true,
   341  	}
   342  	stream.messages <- &logger.Message{}
   343  	errorCh := make(chan error)
   344  	started := make(chan bool)
   345  	go func() {
   346  		started <- true
   347  		err := stream.Log(&logger.Message{})
   348  		errorCh <- err
   349  	}()
   350  	<-started
   351  	select {
   352  	case err := <-errorCh:
   353  		if err == nil {
   354  			t.Fatal("Expected non-nil error")
   355  		}
   356  	case <-time.After(30 * time.Second):
   357  		t.Fatal("Expected Log call to not block")
   358  	}
   359  }
   360  func TestPublishBatchSuccess(t *testing.T) {
   361  	mockClient := newMockClient()
   362  	stream := &logStream{
   363  		client:        mockClient,
   364  		logGroupName:  groupName,
   365  		logStreamName: streamName,
   366  		sequenceToken: aws.String(sequenceToken),
   367  	}
   368  	mockClient.putLogEventsResult <- &putLogEventsResult{
   369  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   370  			NextSequenceToken: aws.String(nextSequenceToken),
   371  		},
   372  	}
   373  	events := []wrappedEvent{
   374  		{
   375  			inputLogEvent: &cloudwatchlogs.InputLogEvent{
   376  				Message: aws.String(logline),
   377  			},
   378  		},
   379  	}
   380  
   381  	stream.publishBatch(testEventBatch(events))
   382  	if stream.sequenceToken == nil {
   383  		t.Fatal("Expected non-nil sequenceToken")
   384  	}
   385  	if *stream.sequenceToken != nextSequenceToken {
   386  		t.Errorf("Expected sequenceToken to be %s, but was %s", nextSequenceToken, *stream.sequenceToken)
   387  	}
   388  	argument := <-mockClient.putLogEventsArgument
   389  	if argument == nil {
   390  		t.Fatal("Expected non-nil PutLogEventsInput")
   391  	}
   392  	if argument.SequenceToken == nil {
   393  		t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken")
   394  	}
   395  	if *argument.SequenceToken != sequenceToken {
   396  		t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", sequenceToken, *argument.SequenceToken)
   397  	}
   398  	if len(argument.LogEvents) != 1 {
   399  		t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents))
   400  	}
   401  	if argument.LogEvents[0] != events[0].inputLogEvent {
   402  		t.Error("Expected event to equal input")
   403  	}
   404  }
   405  
   406  func TestPublishBatchError(t *testing.T) {
   407  	mockClient := newMockClient()
   408  	stream := &logStream{
   409  		client:        mockClient,
   410  		logGroupName:  groupName,
   411  		logStreamName: streamName,
   412  		sequenceToken: aws.String(sequenceToken),
   413  	}
   414  	mockClient.putLogEventsResult <- &putLogEventsResult{
   415  		errorResult: errors.New("Error"),
   416  	}
   417  
   418  	events := []wrappedEvent{
   419  		{
   420  			inputLogEvent: &cloudwatchlogs.InputLogEvent{
   421  				Message: aws.String(logline),
   422  			},
   423  		},
   424  	}
   425  
   426  	stream.publishBatch(testEventBatch(events))
   427  	if stream.sequenceToken == nil {
   428  		t.Fatal("Expected non-nil sequenceToken")
   429  	}
   430  	if *stream.sequenceToken != sequenceToken {
   431  		t.Errorf("Expected sequenceToken to be %s, but was %s", sequenceToken, *stream.sequenceToken)
   432  	}
   433  }
   434  
   435  func TestPublishBatchInvalidSeqSuccess(t *testing.T) {
   436  	mockClient := newMockClientBuffered(2)
   437  	stream := &logStream{
   438  		client:        mockClient,
   439  		logGroupName:  groupName,
   440  		logStreamName: streamName,
   441  		sequenceToken: aws.String(sequenceToken),
   442  	}
   443  	mockClient.putLogEventsResult <- &putLogEventsResult{
   444  		errorResult: awserr.New(invalidSequenceTokenCode, "use token token", nil),
   445  	}
   446  	mockClient.putLogEventsResult <- &putLogEventsResult{
   447  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   448  			NextSequenceToken: aws.String(nextSequenceToken),
   449  		},
   450  	}
   451  
   452  	events := []wrappedEvent{
   453  		{
   454  			inputLogEvent: &cloudwatchlogs.InputLogEvent{
   455  				Message: aws.String(logline),
   456  			},
   457  		},
   458  	}
   459  
   460  	stream.publishBatch(testEventBatch(events))
   461  	if stream.sequenceToken == nil {
   462  		t.Fatal("Expected non-nil sequenceToken")
   463  	}
   464  	if *stream.sequenceToken != nextSequenceToken {
   465  		t.Errorf("Expected sequenceToken to be %s, but was %s", nextSequenceToken, *stream.sequenceToken)
   466  	}
   467  
   468  	argument := <-mockClient.putLogEventsArgument
   469  	if argument == nil {
   470  		t.Fatal("Expected non-nil PutLogEventsInput")
   471  	}
   472  	if argument.SequenceToken == nil {
   473  		t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken")
   474  	}
   475  	if *argument.SequenceToken != sequenceToken {
   476  		t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", sequenceToken, *argument.SequenceToken)
   477  	}
   478  	if len(argument.LogEvents) != 1 {
   479  		t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents))
   480  	}
   481  	if argument.LogEvents[0] != events[0].inputLogEvent {
   482  		t.Error("Expected event to equal input")
   483  	}
   484  
   485  	argument = <-mockClient.putLogEventsArgument
   486  	if argument == nil {
   487  		t.Fatal("Expected non-nil PutLogEventsInput")
   488  	}
   489  	if argument.SequenceToken == nil {
   490  		t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken")
   491  	}
   492  	if *argument.SequenceToken != "token" {
   493  		t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", "token", *argument.SequenceToken)
   494  	}
   495  	if len(argument.LogEvents) != 1 {
   496  		t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents))
   497  	}
   498  	if argument.LogEvents[0] != events[0].inputLogEvent {
   499  		t.Error("Expected event to equal input")
   500  	}
   501  }
   502  
   503  func TestPublishBatchAlreadyAccepted(t *testing.T) {
   504  	mockClient := newMockClient()
   505  	stream := &logStream{
   506  		client:        mockClient,
   507  		logGroupName:  groupName,
   508  		logStreamName: streamName,
   509  		sequenceToken: aws.String(sequenceToken),
   510  	}
   511  	mockClient.putLogEventsResult <- &putLogEventsResult{
   512  		errorResult: awserr.New(dataAlreadyAcceptedCode, "use token token", nil),
   513  	}
   514  
   515  	events := []wrappedEvent{
   516  		{
   517  			inputLogEvent: &cloudwatchlogs.InputLogEvent{
   518  				Message: aws.String(logline),
   519  			},
   520  		},
   521  	}
   522  
   523  	stream.publishBatch(testEventBatch(events))
   524  	if stream.sequenceToken == nil {
   525  		t.Fatal("Expected non-nil sequenceToken")
   526  	}
   527  	if *stream.sequenceToken != "token" {
   528  		t.Errorf("Expected sequenceToken to be %s, but was %s", "token", *stream.sequenceToken)
   529  	}
   530  
   531  	argument := <-mockClient.putLogEventsArgument
   532  	if argument == nil {
   533  		t.Fatal("Expected non-nil PutLogEventsInput")
   534  	}
   535  	if argument.SequenceToken == nil {
   536  		t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken")
   537  	}
   538  	if *argument.SequenceToken != sequenceToken {
   539  		t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", sequenceToken, *argument.SequenceToken)
   540  	}
   541  	if len(argument.LogEvents) != 1 {
   542  		t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents))
   543  	}
   544  	if argument.LogEvents[0] != events[0].inputLogEvent {
   545  		t.Error("Expected event to equal input")
   546  	}
   547  }
   548  
   549  func TestCollectBatchSimple(t *testing.T) {
   550  	mockClient := newMockClient()
   551  	stream := &logStream{
   552  		client:        mockClient,
   553  		logGroupName:  groupName,
   554  		logStreamName: streamName,
   555  		sequenceToken: aws.String(sequenceToken),
   556  		messages:      make(chan *logger.Message),
   557  	}
   558  	mockClient.putLogEventsResult <- &putLogEventsResult{
   559  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   560  			NextSequenceToken: aws.String(nextSequenceToken),
   561  		},
   562  	}
   563  	ticks := make(chan time.Time)
   564  	newTicker = func(_ time.Duration) *time.Ticker {
   565  		return &time.Ticker{
   566  			C: ticks,
   567  		}
   568  	}
   569  	d := make(chan bool)
   570  	close(d)
   571  	go stream.collectBatch(d)
   572  
   573  	stream.Log(&logger.Message{
   574  		Line:      []byte(logline),
   575  		Timestamp: time.Time{},
   576  	})
   577  
   578  	ticks <- time.Time{}
   579  	stream.Close()
   580  
   581  	argument := <-mockClient.putLogEventsArgument
   582  	if argument == nil {
   583  		t.Fatal("Expected non-nil PutLogEventsInput")
   584  	}
   585  	if len(argument.LogEvents) != 1 {
   586  		t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents))
   587  	}
   588  	if *argument.LogEvents[0].Message != logline {
   589  		t.Errorf("Expected message to be %s but was %s", logline, *argument.LogEvents[0].Message)
   590  	}
   591  }
   592  
   593  func TestCollectBatchTicker(t *testing.T) {
   594  	mockClient := newMockClient()
   595  	stream := &logStream{
   596  		client:        mockClient,
   597  		logGroupName:  groupName,
   598  		logStreamName: streamName,
   599  		sequenceToken: aws.String(sequenceToken),
   600  		messages:      make(chan *logger.Message),
   601  	}
   602  	mockClient.putLogEventsResult <- &putLogEventsResult{
   603  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   604  			NextSequenceToken: aws.String(nextSequenceToken),
   605  		},
   606  	}
   607  	ticks := make(chan time.Time)
   608  	newTicker = func(_ time.Duration) *time.Ticker {
   609  		return &time.Ticker{
   610  			C: ticks,
   611  		}
   612  	}
   613  
   614  	d := make(chan bool)
   615  	close(d)
   616  	go stream.collectBatch(d)
   617  
   618  	stream.Log(&logger.Message{
   619  		Line:      []byte(logline + " 1"),
   620  		Timestamp: time.Time{},
   621  	})
   622  	stream.Log(&logger.Message{
   623  		Line:      []byte(logline + " 2"),
   624  		Timestamp: time.Time{},
   625  	})
   626  
   627  	ticks <- time.Time{}
   628  
   629  	// Verify first batch
   630  	argument := <-mockClient.putLogEventsArgument
   631  	if argument == nil {
   632  		t.Fatal("Expected non-nil PutLogEventsInput")
   633  	}
   634  	if len(argument.LogEvents) != 2 {
   635  		t.Errorf("Expected LogEvents to contain 2 elements, but contains %d", len(argument.LogEvents))
   636  	}
   637  	if *argument.LogEvents[0].Message != logline+" 1" {
   638  		t.Errorf("Expected message to be %s but was %s", logline+" 1", *argument.LogEvents[0].Message)
   639  	}
   640  	if *argument.LogEvents[1].Message != logline+" 2" {
   641  		t.Errorf("Expected message to be %s but was %s", logline+" 2", *argument.LogEvents[0].Message)
   642  	}
   643  
   644  	stream.Log(&logger.Message{
   645  		Line:      []byte(logline + " 3"),
   646  		Timestamp: time.Time{},
   647  	})
   648  
   649  	ticks <- time.Time{}
   650  	argument = <-mockClient.putLogEventsArgument
   651  	if argument == nil {
   652  		t.Fatal("Expected non-nil PutLogEventsInput")
   653  	}
   654  	if len(argument.LogEvents) != 1 {
   655  		t.Errorf("Expected LogEvents to contain 1 elements, but contains %d", len(argument.LogEvents))
   656  	}
   657  	if *argument.LogEvents[0].Message != logline+" 3" {
   658  		t.Errorf("Expected message to be %s but was %s", logline+" 3", *argument.LogEvents[0].Message)
   659  	}
   660  
   661  	stream.Close()
   662  
   663  }
   664  
   665  func TestCollectBatchMultilinePattern(t *testing.T) {
   666  	mockClient := newMockClient()
   667  	multilinePattern := regexp.MustCompile("xxxx")
   668  	stream := &logStream{
   669  		client:           mockClient,
   670  		logGroupName:     groupName,
   671  		logStreamName:    streamName,
   672  		multilinePattern: multilinePattern,
   673  		sequenceToken:    aws.String(sequenceToken),
   674  		messages:         make(chan *logger.Message),
   675  	}
   676  	mockClient.putLogEventsResult <- &putLogEventsResult{
   677  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   678  			NextSequenceToken: aws.String(nextSequenceToken),
   679  		},
   680  	}
   681  	ticks := make(chan time.Time)
   682  	newTicker = func(_ time.Duration) *time.Ticker {
   683  		return &time.Ticker{
   684  			C: ticks,
   685  		}
   686  	}
   687  
   688  	d := make(chan bool)
   689  	close(d)
   690  	go stream.collectBatch(d)
   691  
   692  	stream.Log(&logger.Message{
   693  		Line:      []byte(logline),
   694  		Timestamp: time.Now(),
   695  	})
   696  	stream.Log(&logger.Message{
   697  		Line:      []byte(logline),
   698  		Timestamp: time.Now(),
   699  	})
   700  	stream.Log(&logger.Message{
   701  		Line:      []byte("xxxx " + logline),
   702  		Timestamp: time.Now(),
   703  	})
   704  
   705  	ticks <- time.Now()
   706  
   707  	// Verify single multiline event
   708  	argument := <-mockClient.putLogEventsArgument
   709  	assert.Check(t, argument != nil, "Expected non-nil PutLogEventsInput")
   710  	assert.Check(t, is.Equal(1, len(argument.LogEvents)), "Expected single multiline event")
   711  	assert.Check(t, is.Equal(logline+"\n"+logline+"\n", *argument.LogEvents[0].Message), "Received incorrect multiline message")
   712  
   713  	stream.Close()
   714  
   715  	// Verify single event
   716  	argument = <-mockClient.putLogEventsArgument
   717  	assert.Check(t, argument != nil, "Expected non-nil PutLogEventsInput")
   718  	assert.Check(t, is.Equal(1, len(argument.LogEvents)), "Expected single multiline event")
   719  	assert.Check(t, is.Equal("xxxx "+logline+"\n", *argument.LogEvents[0].Message), "Received incorrect multiline message")
   720  }
   721  
   722  func BenchmarkCollectBatch(b *testing.B) {
   723  	for i := 0; i < b.N; i++ {
   724  		mockClient := newMockClient()
   725  		stream := &logStream{
   726  			client:        mockClient,
   727  			logGroupName:  groupName,
   728  			logStreamName: streamName,
   729  			sequenceToken: aws.String(sequenceToken),
   730  			messages:      make(chan *logger.Message),
   731  		}
   732  		mockClient.putLogEventsResult <- &putLogEventsResult{
   733  			successResult: &cloudwatchlogs.PutLogEventsOutput{
   734  				NextSequenceToken: aws.String(nextSequenceToken),
   735  			},
   736  		}
   737  		ticks := make(chan time.Time)
   738  		newTicker = func(_ time.Duration) *time.Ticker {
   739  			return &time.Ticker{
   740  				C: ticks,
   741  			}
   742  		}
   743  
   744  		d := make(chan bool)
   745  		close(d)
   746  		go stream.collectBatch(d)
   747  		stream.logGenerator(10, 100)
   748  		ticks <- time.Time{}
   749  		stream.Close()
   750  	}
   751  }
   752  
   753  func BenchmarkCollectBatchMultilinePattern(b *testing.B) {
   754  	for i := 0; i < b.N; i++ {
   755  		mockClient := newMockClient()
   756  		multilinePattern := regexp.MustCompile(`\d{4}-(?:0[1-9]|1[0-2])-(?:0[1-9]|[1,2][0-9]|3[0,1]) (?:[0,1][0-9]|2[0-3]):[0-5][0-9]:[0-5][0-9]`)
   757  		stream := &logStream{
   758  			client:           mockClient,
   759  			logGroupName:     groupName,
   760  			logStreamName:    streamName,
   761  			multilinePattern: multilinePattern,
   762  			sequenceToken:    aws.String(sequenceToken),
   763  			messages:         make(chan *logger.Message),
   764  		}
   765  		mockClient.putLogEventsResult <- &putLogEventsResult{
   766  			successResult: &cloudwatchlogs.PutLogEventsOutput{
   767  				NextSequenceToken: aws.String(nextSequenceToken),
   768  			},
   769  		}
   770  		ticks := make(chan time.Time)
   771  		newTicker = func(_ time.Duration) *time.Ticker {
   772  			return &time.Ticker{
   773  				C: ticks,
   774  			}
   775  		}
   776  		d := make(chan bool)
   777  		close(d)
   778  		go stream.collectBatch(d)
   779  		stream.logGenerator(10, 100)
   780  		ticks <- time.Time{}
   781  		stream.Close()
   782  	}
   783  }
   784  
   785  func TestCollectBatchMultilinePatternMaxEventAge(t *testing.T) {
   786  	mockClient := newMockClient()
   787  	multilinePattern := regexp.MustCompile("xxxx")
   788  	stream := &logStream{
   789  		client:           mockClient,
   790  		logGroupName:     groupName,
   791  		logStreamName:    streamName,
   792  		multilinePattern: multilinePattern,
   793  		sequenceToken:    aws.String(sequenceToken),
   794  		messages:         make(chan *logger.Message),
   795  	}
   796  	mockClient.putLogEventsResult <- &putLogEventsResult{
   797  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   798  			NextSequenceToken: aws.String(nextSequenceToken),
   799  		},
   800  	}
   801  	ticks := make(chan time.Time)
   802  	newTicker = func(_ time.Duration) *time.Ticker {
   803  		return &time.Ticker{
   804  			C: ticks,
   805  		}
   806  	}
   807  
   808  	d := make(chan bool)
   809  	close(d)
   810  	go stream.collectBatch(d)
   811  
   812  	stream.Log(&logger.Message{
   813  		Line:      []byte(logline),
   814  		Timestamp: time.Now(),
   815  	})
   816  
   817  	// Log an event 1 second later
   818  	stream.Log(&logger.Message{
   819  		Line:      []byte(logline),
   820  		Timestamp: time.Now().Add(time.Second),
   821  	})
   822  
   823  	// Fire ticker defaultForceFlushInterval seconds later
   824  	ticks <- time.Now().Add(defaultForceFlushInterval + time.Second)
   825  
   826  	// Verify single multiline event is flushed after maximum event buffer age (defaultForceFlushInterval)
   827  	argument := <-mockClient.putLogEventsArgument
   828  	assert.Check(t, argument != nil, "Expected non-nil PutLogEventsInput")
   829  	assert.Check(t, is.Equal(1, len(argument.LogEvents)), "Expected single multiline event")
   830  	assert.Check(t, is.Equal(logline+"\n"+logline+"\n", *argument.LogEvents[0].Message), "Received incorrect multiline message")
   831  
   832  	// Log an event 1 second later
   833  	stream.Log(&logger.Message{
   834  		Line:      []byte(logline),
   835  		Timestamp: time.Now().Add(time.Second),
   836  	})
   837  
   838  	// Fire ticker another defaultForceFlushInterval seconds later
   839  	ticks <- time.Now().Add(2*defaultForceFlushInterval + time.Second)
   840  
   841  	// Verify the event buffer is truly flushed - we should only receive a single event
   842  	argument = <-mockClient.putLogEventsArgument
   843  	assert.Check(t, argument != nil, "Expected non-nil PutLogEventsInput")
   844  	assert.Check(t, is.Equal(1, len(argument.LogEvents)), "Expected single multiline event")
   845  	assert.Check(t, is.Equal(logline+"\n", *argument.LogEvents[0].Message), "Received incorrect multiline message")
   846  	stream.Close()
   847  }
   848  
   849  func TestCollectBatchMultilinePatternNegativeEventAge(t *testing.T) {
   850  	mockClient := newMockClient()
   851  	multilinePattern := regexp.MustCompile("xxxx")
   852  	stream := &logStream{
   853  		client:           mockClient,
   854  		logGroupName:     groupName,
   855  		logStreamName:    streamName,
   856  		multilinePattern: multilinePattern,
   857  		sequenceToken:    aws.String(sequenceToken),
   858  		messages:         make(chan *logger.Message),
   859  	}
   860  	mockClient.putLogEventsResult <- &putLogEventsResult{
   861  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   862  			NextSequenceToken: aws.String(nextSequenceToken),
   863  		},
   864  	}
   865  	ticks := make(chan time.Time)
   866  	newTicker = func(_ time.Duration) *time.Ticker {
   867  		return &time.Ticker{
   868  			C: ticks,
   869  		}
   870  	}
   871  
   872  	d := make(chan bool)
   873  	close(d)
   874  	go stream.collectBatch(d)
   875  
   876  	stream.Log(&logger.Message{
   877  		Line:      []byte(logline),
   878  		Timestamp: time.Now(),
   879  	})
   880  
   881  	// Log an event 1 second later
   882  	stream.Log(&logger.Message{
   883  		Line:      []byte(logline),
   884  		Timestamp: time.Now().Add(time.Second),
   885  	})
   886  
   887  	// Fire ticker in past to simulate negative event buffer age
   888  	ticks <- time.Now().Add(-time.Second)
   889  
   890  	// Verify single multiline event is flushed with a negative event buffer age
   891  	argument := <-mockClient.putLogEventsArgument
   892  	assert.Check(t, argument != nil, "Expected non-nil PutLogEventsInput")
   893  	assert.Check(t, is.Equal(1, len(argument.LogEvents)), "Expected single multiline event")
   894  	assert.Check(t, is.Equal(logline+"\n"+logline+"\n", *argument.LogEvents[0].Message), "Received incorrect multiline message")
   895  
   896  	stream.Close()
   897  }
   898  
   899  func TestCollectBatchMultilinePatternMaxEventSize(t *testing.T) {
   900  	mockClient := newMockClient()
   901  	multilinePattern := regexp.MustCompile("xxxx")
   902  	stream := &logStream{
   903  		client:           mockClient,
   904  		logGroupName:     groupName,
   905  		logStreamName:    streamName,
   906  		multilinePattern: multilinePattern,
   907  		sequenceToken:    aws.String(sequenceToken),
   908  		messages:         make(chan *logger.Message),
   909  	}
   910  	mockClient.putLogEventsResult <- &putLogEventsResult{
   911  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   912  			NextSequenceToken: aws.String(nextSequenceToken),
   913  		},
   914  	}
   915  	ticks := make(chan time.Time)
   916  	newTicker = func(_ time.Duration) *time.Ticker {
   917  		return &time.Ticker{
   918  			C: ticks,
   919  		}
   920  	}
   921  
   922  	d := make(chan bool)
   923  	close(d)
   924  	go stream.collectBatch(d)
   925  
   926  	// Log max event size
   927  	longline := strings.Repeat("A", maximumBytesPerEvent)
   928  	stream.Log(&logger.Message{
   929  		Line:      []byte(longline),
   930  		Timestamp: time.Now(),
   931  	})
   932  
   933  	// Log short event
   934  	shortline := strings.Repeat("B", 100)
   935  	stream.Log(&logger.Message{
   936  		Line:      []byte(shortline),
   937  		Timestamp: time.Now(),
   938  	})
   939  
   940  	// Fire ticker
   941  	ticks <- time.Now().Add(defaultForceFlushInterval)
   942  
   943  	// Verify multiline events
   944  	// We expect a maximum sized event with no new line characters and a
   945  	// second short event with a new line character at the end
   946  	argument := <-mockClient.putLogEventsArgument
   947  	assert.Check(t, argument != nil, "Expected non-nil PutLogEventsInput")
   948  	assert.Check(t, is.Equal(2, len(argument.LogEvents)), "Expected two events")
   949  	assert.Check(t, is.Equal(longline, *argument.LogEvents[0].Message), "Received incorrect multiline message")
   950  	assert.Check(t, is.Equal(shortline+"\n", *argument.LogEvents[1].Message), "Received incorrect multiline message")
   951  	stream.Close()
   952  }
   953  
   954  func TestCollectBatchClose(t *testing.T) {
   955  	mockClient := newMockClient()
   956  	stream := &logStream{
   957  		client:        mockClient,
   958  		logGroupName:  groupName,
   959  		logStreamName: streamName,
   960  		sequenceToken: aws.String(sequenceToken),
   961  		messages:      make(chan *logger.Message),
   962  	}
   963  	mockClient.putLogEventsResult <- &putLogEventsResult{
   964  		successResult: &cloudwatchlogs.PutLogEventsOutput{
   965  			NextSequenceToken: aws.String(nextSequenceToken),
   966  		},
   967  	}
   968  	var ticks = make(chan time.Time)
   969  	newTicker = func(_ time.Duration) *time.Ticker {
   970  		return &time.Ticker{
   971  			C: ticks,
   972  		}
   973  	}
   974  
   975  	d := make(chan bool)
   976  	close(d)
   977  	go stream.collectBatch(d)
   978  
   979  	stream.Log(&logger.Message{
   980  		Line:      []byte(logline),
   981  		Timestamp: time.Time{},
   982  	})
   983  
   984  	// no ticks
   985  	stream.Close()
   986  
   987  	argument := <-mockClient.putLogEventsArgument
   988  	if argument == nil {
   989  		t.Fatal("Expected non-nil PutLogEventsInput")
   990  	}
   991  	if len(argument.LogEvents) != 1 {
   992  		t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents))
   993  	}
   994  	if *argument.LogEvents[0].Message != logline {
   995  		t.Errorf("Expected message to be %s but was %s", logline, *argument.LogEvents[0].Message)
   996  	}
   997  }
   998  
   999  func TestEffectiveLen(t *testing.T) {
  1000  	tests := []struct {
  1001  		str            string
  1002  		effectiveBytes int
  1003  	}{
  1004  		{"Hello", 5},
  1005  		{string([]byte{1, 2, 3, 4}), 4},
  1006  		{"🙃", 4},
  1007  		{string([]byte{0xFF, 0xFF, 0xFF, 0xFF}), 12},
  1008  		{"He\xff\xffo", 9},
  1009  		{"", 0},
  1010  	}
  1011  	for i, tc := range tests {
  1012  		t.Run(fmt.Sprintf("%d/%s", i, tc.str), func(t *testing.T) {
  1013  			assert.Equal(t, tc.effectiveBytes, effectiveLen(tc.str))
  1014  		})
  1015  	}
  1016  }
  1017  
  1018  func TestFindValidSplit(t *testing.T) {
  1019  	tests := []struct {
  1020  		str               string
  1021  		maxEffectiveBytes int
  1022  		splitOffset       int
  1023  		effectiveBytes    int
  1024  	}{
  1025  		{"", 10, 0, 0},
  1026  		{"Hello", 6, 5, 5},
  1027  		{"Hello", 2, 2, 2},
  1028  		{"Hello", 0, 0, 0},
  1029  		{"🙃", 3, 0, 0},
  1030  		{"🙃", 4, 4, 4},
  1031  		{string([]byte{'a', 0xFF}), 2, 1, 1},
  1032  		{string([]byte{'a', 0xFF}), 4, 2, 4},
  1033  	}
  1034  	for i, tc := range tests {
  1035  		t.Run(fmt.Sprintf("%d/%s", i, tc.str), func(t *testing.T) {
  1036  			splitOffset, effectiveBytes := findValidSplit(tc.str, tc.maxEffectiveBytes)
  1037  			assert.Equal(t, tc.splitOffset, splitOffset, "splitOffset")
  1038  			assert.Equal(t, tc.effectiveBytes, effectiveBytes, "effectiveBytes")
  1039  			t.Log(tc.str[:tc.splitOffset])
  1040  			t.Log(tc.str[tc.splitOffset:])
  1041  		})
  1042  	}
  1043  }
  1044  
  1045  func TestProcessEventEmoji(t *testing.T) {
  1046  	stream := &logStream{}
  1047  	batch := &eventBatch{}
  1048  	bytes := []byte(strings.Repeat("🙃", maximumBytesPerEvent/4+1))
  1049  	stream.processEvent(batch, bytes, 0)
  1050  	assert.Equal(t, 2, len(batch.batch), "should be two events in the batch")
  1051  	assert.Equal(t, strings.Repeat("🙃", maximumBytesPerEvent/4), aws.StringValue(batch.batch[0].inputLogEvent.Message))
  1052  	assert.Equal(t, "🙃", aws.StringValue(batch.batch[1].inputLogEvent.Message))
  1053  }
  1054  
  1055  func TestCollectBatchLineSplit(t *testing.T) {
  1056  	mockClient := newMockClient()
  1057  	stream := &logStream{
  1058  		client:        mockClient,
  1059  		logGroupName:  groupName,
  1060  		logStreamName: streamName,
  1061  		sequenceToken: aws.String(sequenceToken),
  1062  		messages:      make(chan *logger.Message),
  1063  	}
  1064  	mockClient.putLogEventsResult <- &putLogEventsResult{
  1065  		successResult: &cloudwatchlogs.PutLogEventsOutput{
  1066  			NextSequenceToken: aws.String(nextSequenceToken),
  1067  		},
  1068  	}
  1069  	var ticks = make(chan time.Time)
  1070  	newTicker = func(_ time.Duration) *time.Ticker {
  1071  		return &time.Ticker{
  1072  			C: ticks,
  1073  		}
  1074  	}
  1075  
  1076  	d := make(chan bool)
  1077  	close(d)
  1078  	go stream.collectBatch(d)
  1079  
  1080  	longline := strings.Repeat("A", maximumBytesPerEvent)
  1081  	stream.Log(&logger.Message{
  1082  		Line:      []byte(longline + "B"),
  1083  		Timestamp: time.Time{},
  1084  	})
  1085  
  1086  	// no ticks
  1087  	stream.Close()
  1088  
  1089  	argument := <-mockClient.putLogEventsArgument
  1090  	if argument == nil {
  1091  		t.Fatal("Expected non-nil PutLogEventsInput")
  1092  	}
  1093  	if len(argument.LogEvents) != 2 {
  1094  		t.Errorf("Expected LogEvents to contain 2 elements, but contains %d", len(argument.LogEvents))
  1095  	}
  1096  	if *argument.LogEvents[0].Message != longline {
  1097  		t.Errorf("Expected message to be %s but was %s", longline, *argument.LogEvents[0].Message)
  1098  	}
  1099  	if *argument.LogEvents[1].Message != "B" {
  1100  		t.Errorf("Expected message to be %s but was %s", "B", *argument.LogEvents[1].Message)
  1101  	}
  1102  }
  1103  
  1104  func TestCollectBatchLineSplitWithBinary(t *testing.T) {
  1105  	mockClient := newMockClient()
  1106  	stream := &logStream{
  1107  		client:        mockClient,
  1108  		logGroupName:  groupName,
  1109  		logStreamName: streamName,
  1110  		sequenceToken: aws.String(sequenceToken),
  1111  		messages:      make(chan *logger.Message),
  1112  	}
  1113  	mockClient.putLogEventsResult <- &putLogEventsResult{
  1114  		successResult: &cloudwatchlogs.PutLogEventsOutput{
  1115  			NextSequenceToken: aws.String(nextSequenceToken),
  1116  		},
  1117  	}
  1118  	var ticks = make(chan time.Time)
  1119  	newTicker = func(_ time.Duration) *time.Ticker {
  1120  		return &time.Ticker{
  1121  			C: ticks,
  1122  		}
  1123  	}
  1124  
  1125  	d := make(chan bool)
  1126  	close(d)
  1127  	go stream.collectBatch(d)
  1128  
  1129  	longline := strings.Repeat("\xFF", maximumBytesPerEvent/3) // 0xFF is counted as the 3-byte utf8.RuneError
  1130  	stream.Log(&logger.Message{
  1131  		Line:      []byte(longline + "\xFD"),
  1132  		Timestamp: time.Time{},
  1133  	})
  1134  
  1135  	// no ticks
  1136  	stream.Close()
  1137  
  1138  	argument := <-mockClient.putLogEventsArgument
  1139  	if argument == nil {
  1140  		t.Fatal("Expected non-nil PutLogEventsInput")
  1141  	}
  1142  	if len(argument.LogEvents) != 2 {
  1143  		t.Errorf("Expected LogEvents to contain 2 elements, but contains %d", len(argument.LogEvents))
  1144  	}
  1145  	if *argument.LogEvents[0].Message != longline {
  1146  		t.Errorf("Expected message to be %s but was %s", longline, *argument.LogEvents[0].Message)
  1147  	}
  1148  	if *argument.LogEvents[1].Message != "\xFD" {
  1149  		t.Errorf("Expected message to be %s but was %s", "\xFD", *argument.LogEvents[1].Message)
  1150  	}
  1151  }
  1152  
  1153  func TestCollectBatchMaxEvents(t *testing.T) {
  1154  	mockClient := newMockClientBuffered(1)
  1155  	stream := &logStream{
  1156  		client:        mockClient,
  1157  		logGroupName:  groupName,
  1158  		logStreamName: streamName,
  1159  		sequenceToken: aws.String(sequenceToken),
  1160  		messages:      make(chan *logger.Message),
  1161  	}
  1162  	mockClient.putLogEventsResult <- &putLogEventsResult{
  1163  		successResult: &cloudwatchlogs.PutLogEventsOutput{
  1164  			NextSequenceToken: aws.String(nextSequenceToken),
  1165  		},
  1166  	}
  1167  	var ticks = make(chan time.Time)
  1168  	newTicker = func(_ time.Duration) *time.Ticker {
  1169  		return &time.Ticker{
  1170  			C: ticks,
  1171  		}
  1172  	}
  1173  
  1174  	d := make(chan bool)
  1175  	close(d)
  1176  	go stream.collectBatch(d)
  1177  
  1178  	line := "A"
  1179  	for i := 0; i <= maximumLogEventsPerPut; i++ {
  1180  		stream.Log(&logger.Message{
  1181  			Line:      []byte(line),
  1182  			Timestamp: time.Time{},
  1183  		})
  1184  	}
  1185  
  1186  	// no ticks
  1187  	stream.Close()
  1188  
  1189  	argument := <-mockClient.putLogEventsArgument
  1190  	if argument == nil {
  1191  		t.Fatal("Expected non-nil PutLogEventsInput")
  1192  	}
  1193  	if len(argument.LogEvents) != maximumLogEventsPerPut {
  1194  		t.Errorf("Expected LogEvents to contain %d elements, but contains %d", maximumLogEventsPerPut, len(argument.LogEvents))
  1195  	}
  1196  
  1197  	argument = <-mockClient.putLogEventsArgument
  1198  	if argument == nil {
  1199  		t.Fatal("Expected non-nil PutLogEventsInput")
  1200  	}
  1201  	if len(argument.LogEvents) != 1 {
  1202  		t.Errorf("Expected LogEvents to contain %d elements, but contains %d", 1, len(argument.LogEvents))
  1203  	}
  1204  }
  1205  
  1206  func TestCollectBatchMaxTotalBytes(t *testing.T) {
  1207  	expectedPuts := 2
  1208  	mockClient := newMockClientBuffered(expectedPuts)
  1209  	stream := &logStream{
  1210  		client:        mockClient,
  1211  		logGroupName:  groupName,
  1212  		logStreamName: streamName,
  1213  		sequenceToken: aws.String(sequenceToken),
  1214  		messages:      make(chan *logger.Message),
  1215  	}
  1216  	for i := 0; i < expectedPuts; i++ {
  1217  		mockClient.putLogEventsResult <- &putLogEventsResult{
  1218  			successResult: &cloudwatchlogs.PutLogEventsOutput{
  1219  				NextSequenceToken: aws.String(nextSequenceToken),
  1220  			},
  1221  		}
  1222  	}
  1223  
  1224  	var ticks = make(chan time.Time)
  1225  	newTicker = func(_ time.Duration) *time.Ticker {
  1226  		return &time.Ticker{
  1227  			C: ticks,
  1228  		}
  1229  	}
  1230  
  1231  	d := make(chan bool)
  1232  	close(d)
  1233  	go stream.collectBatch(d)
  1234  
  1235  	numPayloads := maximumBytesPerPut / (maximumBytesPerEvent + perEventBytes)
  1236  	// maxline is the maximum line that could be submitted after
  1237  	// accounting for its overhead.
  1238  	maxline := strings.Repeat("A", maximumBytesPerPut-(perEventBytes*numPayloads))
  1239  	// This will be split and batched up to the `maximumBytesPerPut'
  1240  	// (+/- `maximumBytesPerEvent'). This /should/ be aligned, but
  1241  	// should also tolerate an offset within that range.
  1242  	stream.Log(&logger.Message{
  1243  		Line:      []byte(maxline[:len(maxline)/2]),
  1244  		Timestamp: time.Time{},
  1245  	})
  1246  	stream.Log(&logger.Message{
  1247  		Line:      []byte(maxline[len(maxline)/2:]),
  1248  		Timestamp: time.Time{},
  1249  	})
  1250  	stream.Log(&logger.Message{
  1251  		Line:      []byte("B"),
  1252  		Timestamp: time.Time{},
  1253  	})
  1254  
  1255  	// no ticks, guarantee batch by size (and chan close)
  1256  	stream.Close()
  1257  
  1258  	argument := <-mockClient.putLogEventsArgument
  1259  	if argument == nil {
  1260  		t.Fatal("Expected non-nil PutLogEventsInput")
  1261  	}
  1262  
  1263  	// Should total to the maximum allowed bytes.
  1264  	eventBytes := 0
  1265  	for _, event := range argument.LogEvents {
  1266  		eventBytes += len(*event.Message)
  1267  	}
  1268  	eventsOverhead := len(argument.LogEvents) * perEventBytes
  1269  	payloadTotal := eventBytes + eventsOverhead
  1270  	// lowestMaxBatch allows the payload to be offset if the messages
  1271  	// don't lend themselves to align with the maximum event size.
  1272  	lowestMaxBatch := maximumBytesPerPut - maximumBytesPerEvent
  1273  
  1274  	if payloadTotal > maximumBytesPerPut {
  1275  		t.Errorf("Expected <= %d bytes but was %d", maximumBytesPerPut, payloadTotal)
  1276  	}
  1277  	if payloadTotal < lowestMaxBatch {
  1278  		t.Errorf("Batch to be no less than %d but was %d", lowestMaxBatch, payloadTotal)
  1279  	}
  1280  
  1281  	argument = <-mockClient.putLogEventsArgument
  1282  	if len(argument.LogEvents) != 1 {
  1283  		t.Errorf("Expected LogEvents to contain 1 elements, but contains %d", len(argument.LogEvents))
  1284  	}
  1285  	message := *argument.LogEvents[len(argument.LogEvents)-1].Message
  1286  	if message[len(message)-1:] != "B" {
  1287  		t.Errorf("Expected message to be %s but was %s", "B", message[len(message)-1:])
  1288  	}
  1289  }
  1290  
  1291  func TestCollectBatchMaxTotalBytesWithBinary(t *testing.T) {
  1292  	expectedPuts := 2
  1293  	mockClient := newMockClientBuffered(expectedPuts)
  1294  	stream := &logStream{
  1295  		client:        mockClient,
  1296  		logGroupName:  groupName,
  1297  		logStreamName: streamName,
  1298  		sequenceToken: aws.String(sequenceToken),
  1299  		messages:      make(chan *logger.Message),
  1300  	}
  1301  	for i := 0; i < expectedPuts; i++ {
  1302  		mockClient.putLogEventsResult <- &putLogEventsResult{
  1303  			successResult: &cloudwatchlogs.PutLogEventsOutput{
  1304  				NextSequenceToken: aws.String(nextSequenceToken),
  1305  			},
  1306  		}
  1307  	}
  1308  
  1309  	var ticks = make(chan time.Time)
  1310  	newTicker = func(_ time.Duration) *time.Ticker {
  1311  		return &time.Ticker{
  1312  			C: ticks,
  1313  		}
  1314  	}
  1315  
  1316  	d := make(chan bool)
  1317  	close(d)
  1318  	go stream.collectBatch(d)
  1319  
  1320  	// maxline is the maximum line that could be submitted after
  1321  	// accounting for its overhead.
  1322  	maxline := strings.Repeat("\xFF", (maximumBytesPerPut-perEventBytes)/3) // 0xFF is counted as the 3-byte utf8.RuneError
  1323  	// This will be split and batched up to the `maximumBytesPerPut'
  1324  	// (+/- `maximumBytesPerEvent'). This /should/ be aligned, but
  1325  	// should also tolerate an offset within that range.
  1326  	stream.Log(&logger.Message{
  1327  		Line:      []byte(maxline),
  1328  		Timestamp: time.Time{},
  1329  	})
  1330  	stream.Log(&logger.Message{
  1331  		Line:      []byte("B"),
  1332  		Timestamp: time.Time{},
  1333  	})
  1334  
  1335  	// no ticks, guarantee batch by size (and chan close)
  1336  	stream.Close()
  1337  
  1338  	argument := <-mockClient.putLogEventsArgument
  1339  	if argument == nil {
  1340  		t.Fatal("Expected non-nil PutLogEventsInput")
  1341  	}
  1342  
  1343  	// Should total to the maximum allowed bytes.
  1344  	eventBytes := 0
  1345  	for _, event := range argument.LogEvents {
  1346  		eventBytes += effectiveLen(*event.Message)
  1347  	}
  1348  	eventsOverhead := len(argument.LogEvents) * perEventBytes
  1349  	payloadTotal := eventBytes + eventsOverhead
  1350  	// lowestMaxBatch allows the payload to be offset if the messages
  1351  	// don't lend themselves to align with the maximum event size.
  1352  	lowestMaxBatch := maximumBytesPerPut - maximumBytesPerEvent
  1353  
  1354  	if payloadTotal > maximumBytesPerPut {
  1355  		t.Errorf("Expected <= %d bytes but was %d", maximumBytesPerPut, payloadTotal)
  1356  	}
  1357  	if payloadTotal < lowestMaxBatch {
  1358  		t.Errorf("Batch to be no less than %d but was %d", lowestMaxBatch, payloadTotal)
  1359  	}
  1360  
  1361  	argument = <-mockClient.putLogEventsArgument
  1362  	message := *argument.LogEvents[len(argument.LogEvents)-1].Message
  1363  	if message[len(message)-1:] != "B" {
  1364  		t.Errorf("Expected message to be %s but was %s", "B", message[len(message)-1:])
  1365  	}
  1366  }
  1367  
  1368  func TestCollectBatchWithDuplicateTimestamps(t *testing.T) {
  1369  	mockClient := newMockClient()
  1370  	stream := &logStream{
  1371  		client:        mockClient,
  1372  		logGroupName:  groupName,
  1373  		logStreamName: streamName,
  1374  		sequenceToken: aws.String(sequenceToken),
  1375  		messages:      make(chan *logger.Message),
  1376  	}
  1377  	mockClient.putLogEventsResult <- &putLogEventsResult{
  1378  		successResult: &cloudwatchlogs.PutLogEventsOutput{
  1379  			NextSequenceToken: aws.String(nextSequenceToken),
  1380  		},
  1381  	}
  1382  	ticks := make(chan time.Time)
  1383  	newTicker = func(_ time.Duration) *time.Ticker {
  1384  		return &time.Ticker{
  1385  			C: ticks,
  1386  		}
  1387  	}
  1388  
  1389  	d := make(chan bool)
  1390  	close(d)
  1391  	go stream.collectBatch(d)
  1392  
  1393  	var expectedEvents []*cloudwatchlogs.InputLogEvent
  1394  	times := maximumLogEventsPerPut
  1395  	timestamp := time.Now()
  1396  	for i := 0; i < times; i++ {
  1397  		line := fmt.Sprintf("%d", i)
  1398  		if i%2 == 0 {
  1399  			timestamp.Add(1 * time.Nanosecond)
  1400  		}
  1401  		stream.Log(&logger.Message{
  1402  			Line:      []byte(line),
  1403  			Timestamp: timestamp,
  1404  		})
  1405  		expectedEvents = append(expectedEvents, &cloudwatchlogs.InputLogEvent{
  1406  			Message:   aws.String(line),
  1407  			Timestamp: aws.Int64(timestamp.UnixNano() / int64(time.Millisecond)),
  1408  		})
  1409  	}
  1410  
  1411  	ticks <- time.Time{}
  1412  	stream.Close()
  1413  
  1414  	argument := <-mockClient.putLogEventsArgument
  1415  	if argument == nil {
  1416  		t.Fatal("Expected non-nil PutLogEventsInput")
  1417  	}
  1418  	if len(argument.LogEvents) != times {
  1419  		t.Errorf("Expected LogEvents to contain %d elements, but contains %d", times, len(argument.LogEvents))
  1420  	}
  1421  	for i := 0; i < times; i++ {
  1422  		if !reflect.DeepEqual(*argument.LogEvents[i], *expectedEvents[i]) {
  1423  			t.Errorf("Expected event to be %v but was %v", *expectedEvents[i], *argument.LogEvents[i])
  1424  		}
  1425  	}
  1426  }
  1427  
  1428  func TestParseLogOptionsMultilinePattern(t *testing.T) {
  1429  	info := logger.Info{
  1430  		Config: map[string]string{
  1431  			multilinePatternKey: "^xxxx",
  1432  		},
  1433  	}
  1434  
  1435  	multilinePattern, err := parseMultilineOptions(info)
  1436  	assert.Check(t, err, "Received unexpected error")
  1437  	assert.Check(t, multilinePattern.MatchString("xxxx"), "No multiline pattern match found")
  1438  }
  1439  
  1440  func TestParseLogOptionsDatetimeFormat(t *testing.T) {
  1441  	datetimeFormatTests := []struct {
  1442  		format string
  1443  		match  string
  1444  	}{
  1445  		{"%d/%m/%y %a %H:%M:%S%L %Z", "31/12/10 Mon 08:42:44.345 NZDT"},
  1446  		{"%Y-%m-%d %A %I:%M:%S.%f%p%z", "2007-12-04 Monday 08:42:44.123456AM+1200"},
  1447  		{"%b|%b|%b|%b|%b|%b|%b|%b|%b|%b|%b|%b", "Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec"},
  1448  		{"%B|%B|%B|%B|%B|%B|%B|%B|%B|%B|%B|%B", "January|February|March|April|May|June|July|August|September|October|November|December"},
  1449  		{"%A|%A|%A|%A|%A|%A|%A", "Monday|Tuesday|Wednesday|Thursday|Friday|Saturday|Sunday"},
  1450  		{"%a|%a|%a|%a|%a|%a|%a", "Mon|Tue|Wed|Thu|Fri|Sat|Sun"},
  1451  		{"Day of the week: %w, Day of the year: %j", "Day of the week: 4, Day of the year: 091"},
  1452  	}
  1453  	for _, dt := range datetimeFormatTests {
  1454  		t.Run(dt.match, func(t *testing.T) {
  1455  			info := logger.Info{
  1456  				Config: map[string]string{
  1457  					datetimeFormatKey: dt.format,
  1458  				},
  1459  			}
  1460  			multilinePattern, err := parseMultilineOptions(info)
  1461  			assert.Check(t, err, "Received unexpected error")
  1462  			assert.Check(t, multilinePattern.MatchString(dt.match), "No multiline pattern match found")
  1463  		})
  1464  	}
  1465  }
  1466  
  1467  func TestValidateLogOptionsDatetimeFormatAndMultilinePattern(t *testing.T) {
  1468  	cfg := map[string]string{
  1469  		multilinePatternKey: "^xxxx",
  1470  		datetimeFormatKey:   "%Y-%m-%d",
  1471  		logGroupKey:         groupName,
  1472  	}
  1473  	conflictingLogOptionsError := "you cannot configure log opt 'awslogs-datetime-format' and 'awslogs-multiline-pattern' at the same time"
  1474  
  1475  	err := ValidateLogOpt(cfg)
  1476  	assert.Check(t, err != nil, "Expected an error")
  1477  	assert.Check(t, is.Equal(err.Error(), conflictingLogOptionsError), "Received invalid error")
  1478  }
  1479  
  1480  func TestValidateLogOptionsForceFlushIntervalSeconds(t *testing.T) {
  1481  	tests := []struct {
  1482  		input     string
  1483  		shouldErr bool
  1484  	}{
  1485  		{"0", true},
  1486  		{"-1", true},
  1487  		{"a", true},
  1488  		{"10", false},
  1489  	}
  1490  
  1491  	for _, tc := range tests {
  1492  		t.Run(tc.input, func(t *testing.T) {
  1493  			cfg := map[string]string{
  1494  				forceFlushIntervalKey: tc.input,
  1495  				logGroupKey:           groupName,
  1496  			}
  1497  
  1498  			err := ValidateLogOpt(cfg)
  1499  			if tc.shouldErr {
  1500  				expectedErr := "must specify a positive integer for log opt 'awslogs-force-flush-interval-seconds': " + tc.input
  1501  				assert.Error(t, err, expectedErr)
  1502  			} else {
  1503  				assert.NilError(t, err)
  1504  			}
  1505  		})
  1506  	}
  1507  }
  1508  
  1509  func TestValidateLogOptionsMaxBufferedEvents(t *testing.T) {
  1510  	tests := []struct {
  1511  		input     string
  1512  		shouldErr bool
  1513  	}{
  1514  		{"0", true},
  1515  		{"-1", true},
  1516  		{"a", true},
  1517  		{"10", false},
  1518  	}
  1519  
  1520  	for _, tc := range tests {
  1521  		t.Run(tc.input, func(t *testing.T) {
  1522  			cfg := map[string]string{
  1523  				maxBufferedEventsKey: tc.input,
  1524  				logGroupKey:          groupName,
  1525  			}
  1526  
  1527  			err := ValidateLogOpt(cfg)
  1528  			if tc.shouldErr {
  1529  				expectedErr := "must specify a positive integer for log opt 'awslogs-max-buffered-events': " + tc.input
  1530  				assert.Error(t, err, expectedErr)
  1531  			} else {
  1532  				assert.NilError(t, err)
  1533  			}
  1534  		})
  1535  	}
  1536  }
  1537  
  1538  func TestCreateTagSuccess(t *testing.T) {
  1539  	mockClient := newMockClient()
  1540  	info := logger.Info{
  1541  		ContainerName: "/test-container",
  1542  		ContainerID:   "container-abcdefghijklmnopqrstuvwxyz01234567890",
  1543  		Config:        map[string]string{"tag": "{{.Name}}/{{.FullID}}"},
  1544  	}
  1545  	logStreamName, e := loggerutils.ParseLogTag(info, loggerutils.DefaultTemplate)
  1546  	if e != nil {
  1547  		t.Errorf("Error generating tag: %q", e)
  1548  	}
  1549  	stream := &logStream{
  1550  		client:        mockClient,
  1551  		logGroupName:  groupName,
  1552  		logStreamName: logStreamName,
  1553  	}
  1554  	mockClient.createLogStreamResult <- &createLogStreamResult{}
  1555  
  1556  	err := stream.create()
  1557  
  1558  	assert.NilError(t, err)
  1559  	argument := <-mockClient.createLogStreamArgument
  1560  
  1561  	if *argument.LogStreamName != "test-container/container-abcdefghijklmnopqrstuvwxyz01234567890" {
  1562  		t.Errorf("Expected LogStreamName to be %s", "test-container/container-abcdefghijklmnopqrstuvwxyz01234567890")
  1563  	}
  1564  }
  1565  
  1566  func BenchmarkUnwrapEvents(b *testing.B) {
  1567  	events := make([]wrappedEvent, maximumLogEventsPerPut)
  1568  	for i := 0; i < maximumLogEventsPerPut; i++ {
  1569  		mes := strings.Repeat("0", maximumBytesPerEvent)
  1570  		events[i].inputLogEvent = &cloudwatchlogs.InputLogEvent{
  1571  			Message: &mes,
  1572  		}
  1573  	}
  1574  
  1575  	b.ResetTimer()
  1576  	for i := 0; i < b.N; i++ {
  1577  		res := unwrapEvents(events)
  1578  		assert.Check(b, is.Len(res, maximumLogEventsPerPut))
  1579  	}
  1580  }
  1581  
  1582  func TestNewAWSLogsClientCredentialEndpointDetect(t *testing.T) {
  1583  	// required for the cloudwatchlogs client
  1584  	os.Setenv("AWS_REGION", "us-west-2")
  1585  	defer os.Unsetenv("AWS_REGION")
  1586  
  1587  	credsResp := `{
  1588  		"AccessKeyId" :    "test-access-key-id",
  1589  		"SecretAccessKey": "test-secret-access-key"
  1590  		}`
  1591  
  1592  	expectedAccessKeyID := "test-access-key-id"
  1593  	expectedSecretAccessKey := "test-secret-access-key"
  1594  
  1595  	testServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
  1596  		w.Header().Set("Content-Type", "application/json")
  1597  		fmt.Fprintln(w, credsResp)
  1598  	}))
  1599  	defer testServer.Close()
  1600  
  1601  	// set the SDKEndpoint in the driver
  1602  	newSDKEndpoint = testServer.URL
  1603  
  1604  	info := logger.Info{
  1605  		Config: map[string]string{},
  1606  	}
  1607  
  1608  	info.Config["awslogs-credentials-endpoint"] = "/creds"
  1609  
  1610  	c, err := newAWSLogsClient(info)
  1611  	assert.Check(t, err)
  1612  
  1613  	client := c.(*cloudwatchlogs.CloudWatchLogs)
  1614  
  1615  	creds, err := client.Config.Credentials.Get()
  1616  	assert.Check(t, err)
  1617  
  1618  	assert.Check(t, is.Equal(expectedAccessKeyID, creds.AccessKeyID))
  1619  	assert.Check(t, is.Equal(expectedSecretAccessKey, creds.SecretAccessKey))
  1620  }
  1621  
  1622  func TestNewAWSLogsClientCredentialEnvironmentVariable(t *testing.T) {
  1623  	// required for the cloudwatchlogs client
  1624  	os.Setenv("AWS_REGION", "us-west-2")
  1625  	defer os.Unsetenv("AWS_REGION")
  1626  
  1627  	expectedAccessKeyID := "test-access-key-id"
  1628  	expectedSecretAccessKey := "test-secret-access-key"
  1629  
  1630  	os.Setenv("AWS_ACCESS_KEY_ID", expectedAccessKeyID)
  1631  	defer os.Unsetenv("AWS_ACCESS_KEY_ID")
  1632  
  1633  	os.Setenv("AWS_SECRET_ACCESS_KEY", expectedSecretAccessKey)
  1634  	defer os.Unsetenv("AWS_SECRET_ACCESS_KEY")
  1635  
  1636  	info := logger.Info{
  1637  		Config: map[string]string{},
  1638  	}
  1639  
  1640  	c, err := newAWSLogsClient(info)
  1641  	assert.Check(t, err)
  1642  
  1643  	client := c.(*cloudwatchlogs.CloudWatchLogs)
  1644  
  1645  	creds, err := client.Config.Credentials.Get()
  1646  	assert.Check(t, err)
  1647  
  1648  	assert.Check(t, is.Equal(expectedAccessKeyID, creds.AccessKeyID))
  1649  	assert.Check(t, is.Equal(expectedSecretAccessKey, creds.SecretAccessKey))
  1650  }
  1651  
  1652  func TestNewAWSLogsClientCredentialSharedFile(t *testing.T) {
  1653  	// required for the cloudwatchlogs client
  1654  	os.Setenv("AWS_REGION", "us-west-2")
  1655  	defer os.Unsetenv("AWS_REGION")
  1656  
  1657  	expectedAccessKeyID := "test-access-key-id"
  1658  	expectedSecretAccessKey := "test-secret-access-key"
  1659  
  1660  	contentStr := `
  1661  	[default]
  1662  	aws_access_key_id = "test-access-key-id"
  1663  	aws_secret_access_key =  "test-secret-access-key"
  1664  	`
  1665  	content := []byte(contentStr)
  1666  
  1667  	tmpfile, err := ioutil.TempFile("", "example")
  1668  	defer os.Remove(tmpfile.Name()) // clean up
  1669  	assert.Check(t, err)
  1670  
  1671  	_, err = tmpfile.Write(content)
  1672  	assert.Check(t, err)
  1673  
  1674  	err = tmpfile.Close()
  1675  	assert.Check(t, err)
  1676  
  1677  	os.Unsetenv("AWS_ACCESS_KEY_ID")
  1678  	os.Unsetenv("AWS_SECRET_ACCESS_KEY")
  1679  
  1680  	os.Setenv("AWS_SHARED_CREDENTIALS_FILE", tmpfile.Name())
  1681  	defer os.Unsetenv("AWS_SHARED_CREDENTIALS_FILE")
  1682  
  1683  	info := logger.Info{
  1684  		Config: map[string]string{},
  1685  	}
  1686  
  1687  	c, err := newAWSLogsClient(info)
  1688  	assert.Check(t, err)
  1689  
  1690  	client := c.(*cloudwatchlogs.CloudWatchLogs)
  1691  
  1692  	creds, err := client.Config.Credentials.Get()
  1693  	assert.Check(t, err)
  1694  
  1695  	assert.Check(t, is.Equal(expectedAccessKeyID, creds.AccessKeyID))
  1696  	assert.Check(t, is.Equal(expectedSecretAccessKey, creds.SecretAccessKey))
  1697  }