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