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