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