github.com/jiasir/docker@v1.3.3-0.20170609024000-252e610103e7/daemon/logger/awslogs/cloudwatchlogs_test.go (about) 1 package awslogs 2 3 import ( 4 "errors" 5 "fmt" 6 "net/http" 7 "reflect" 8 "regexp" 9 "runtime" 10 "strings" 11 "testing" 12 "time" 13 14 "github.com/aws/aws-sdk-go/aws" 15 "github.com/aws/aws-sdk-go/aws/awserr" 16 "github.com/aws/aws-sdk-go/aws/request" 17 "github.com/aws/aws-sdk-go/service/cloudwatchlogs" 18 "github.com/docker/docker/daemon/logger" 19 "github.com/docker/docker/daemon/logger/loggerutils" 20 "github.com/docker/docker/dockerversion" 21 "github.com/stretchr/testify/assert" 22 ) 23 24 const ( 25 groupName = "groupName" 26 streamName = "streamName" 27 sequenceToken = "sequenceToken" 28 nextSequenceToken = "nextSequenceToken" 29 logline = "this is a log line\r" 30 multilineLogline = "2017-01-01 01:01:44 This is a multiline log entry\r" 31 ) 32 33 // Generates i multi-line events each with j lines 34 func (l *logStream) logGenerator(lineCount int, multilineCount int) { 35 for i := 0; i < multilineCount; i++ { 36 l.Log(&logger.Message{ 37 Line: []byte(multilineLogline), 38 Timestamp: time.Time{}, 39 }) 40 for j := 0; j < lineCount; j++ { 41 l.Log(&logger.Message{ 42 Line: []byte(logline), 43 Timestamp: time.Time{}, 44 }) 45 } 46 } 47 } 48 49 func TestNewAWSLogsClientUserAgentHandler(t *testing.T) { 50 info := logger.Info{ 51 Config: map[string]string{ 52 regionKey: "us-east-1", 53 }, 54 } 55 56 client, err := newAWSLogsClient(info) 57 if err != nil { 58 t.Fatal(err) 59 } 60 realClient, ok := client.(*cloudwatchlogs.CloudWatchLogs) 61 if !ok { 62 t.Fatal("Could not cast client to cloudwatchlogs.CloudWatchLogs") 63 } 64 buildHandlerList := realClient.Handlers.Build 65 request := &request.Request{ 66 HTTPRequest: &http.Request{ 67 Header: http.Header{}, 68 }, 69 } 70 buildHandlerList.Run(request) 71 expectedUserAgentString := fmt.Sprintf("Docker %s (%s) %s/%s (%s; %s; %s)", 72 dockerversion.Version, runtime.GOOS, aws.SDKName, aws.SDKVersion, runtime.Version(), runtime.GOOS, runtime.GOARCH) 73 userAgent := request.HTTPRequest.Header.Get("User-Agent") 74 if userAgent != expectedUserAgentString { 75 t.Errorf("Wrong User-Agent string, expected \"%s\" but was \"%s\"", 76 expectedUserAgentString, userAgent) 77 } 78 } 79 80 func TestNewAWSLogsClientRegionDetect(t *testing.T) { 81 info := logger.Info{ 82 Config: map[string]string{}, 83 } 84 85 mockMetadata := newMockMetadataClient() 86 newRegionFinder = func() regionFinder { 87 return mockMetadata 88 } 89 mockMetadata.regionResult <- ®ionResult{ 90 successResult: "us-east-1", 91 } 92 93 _, err := newAWSLogsClient(info) 94 if err != nil { 95 t.Fatal(err) 96 } 97 } 98 99 func TestCreateSuccess(t *testing.T) { 100 mockClient := newMockClient() 101 stream := &logStream{ 102 client: mockClient, 103 logGroupName: groupName, 104 logStreamName: streamName, 105 } 106 mockClient.createLogStreamResult <- &createLogStreamResult{} 107 108 err := stream.create() 109 110 if err != nil { 111 t.Errorf("Received unexpected err: %v\n", err) 112 } 113 argument := <-mockClient.createLogStreamArgument 114 if argument.LogGroupName == nil { 115 t.Fatal("Expected non-nil LogGroupName") 116 } 117 if *argument.LogGroupName != groupName { 118 t.Errorf("Expected LogGroupName to be %s", groupName) 119 } 120 if argument.LogStreamName == nil { 121 t.Fatal("Expected non-nil LogStreamName") 122 } 123 if *argument.LogStreamName != streamName { 124 t.Errorf("Expected LogStreamName to be %s", streamName) 125 } 126 } 127 128 func TestCreateLogGroupSuccess(t *testing.T) { 129 mockClient := newMockClient() 130 stream := &logStream{ 131 client: mockClient, 132 logGroupName: groupName, 133 logStreamName: streamName, 134 logCreateGroup: true, 135 } 136 mockClient.createLogGroupResult <- &createLogGroupResult{} 137 mockClient.createLogStreamResult <- &createLogStreamResult{} 138 139 err := stream.create() 140 141 if err != nil { 142 t.Errorf("Received unexpected err: %v\n", err) 143 } 144 argument := <-mockClient.createLogStreamArgument 145 if argument.LogGroupName == nil { 146 t.Fatal("Expected non-nil LogGroupName") 147 } 148 if *argument.LogGroupName != groupName { 149 t.Errorf("Expected LogGroupName to be %s", groupName) 150 } 151 if argument.LogStreamName == nil { 152 t.Fatal("Expected non-nil LogStreamName") 153 } 154 if *argument.LogStreamName != streamName { 155 t.Errorf("Expected LogStreamName to be %s", streamName) 156 } 157 } 158 159 func TestCreateError(t *testing.T) { 160 mockClient := newMockClient() 161 stream := &logStream{ 162 client: mockClient, 163 } 164 mockClient.createLogStreamResult <- &createLogStreamResult{ 165 errorResult: errors.New("Error!"), 166 } 167 168 err := stream.create() 169 170 if err == nil { 171 t.Fatal("Expected non-nil err") 172 } 173 } 174 175 func TestCreateAlreadyExists(t *testing.T) { 176 mockClient := newMockClient() 177 stream := &logStream{ 178 client: mockClient, 179 } 180 mockClient.createLogStreamResult <- &createLogStreamResult{ 181 errorResult: awserr.New(resourceAlreadyExistsCode, "", nil), 182 } 183 184 err := stream.create() 185 186 if err != nil { 187 t.Fatal("Expected nil err") 188 } 189 } 190 191 func TestPublishBatchSuccess(t *testing.T) { 192 mockClient := newMockClient() 193 stream := &logStream{ 194 client: mockClient, 195 logGroupName: groupName, 196 logStreamName: streamName, 197 sequenceToken: aws.String(sequenceToken), 198 } 199 mockClient.putLogEventsResult <- &putLogEventsResult{ 200 successResult: &cloudwatchlogs.PutLogEventsOutput{ 201 NextSequenceToken: aws.String(nextSequenceToken), 202 }, 203 } 204 events := []wrappedEvent{ 205 { 206 inputLogEvent: &cloudwatchlogs.InputLogEvent{ 207 Message: aws.String(logline), 208 }, 209 }, 210 } 211 212 stream.publishBatch(events) 213 if stream.sequenceToken == nil { 214 t.Fatal("Expected non-nil sequenceToken") 215 } 216 if *stream.sequenceToken != nextSequenceToken { 217 t.Errorf("Expected sequenceToken to be %s, but was %s", nextSequenceToken, *stream.sequenceToken) 218 } 219 argument := <-mockClient.putLogEventsArgument 220 if argument == nil { 221 t.Fatal("Expected non-nil PutLogEventsInput") 222 } 223 if argument.SequenceToken == nil { 224 t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken") 225 } 226 if *argument.SequenceToken != sequenceToken { 227 t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", sequenceToken, *argument.SequenceToken) 228 } 229 if len(argument.LogEvents) != 1 { 230 t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents)) 231 } 232 if argument.LogEvents[0] != events[0].inputLogEvent { 233 t.Error("Expected event to equal input") 234 } 235 } 236 237 func TestPublishBatchError(t *testing.T) { 238 mockClient := newMockClient() 239 stream := &logStream{ 240 client: mockClient, 241 logGroupName: groupName, 242 logStreamName: streamName, 243 sequenceToken: aws.String(sequenceToken), 244 } 245 mockClient.putLogEventsResult <- &putLogEventsResult{ 246 errorResult: errors.New("Error!"), 247 } 248 249 events := []wrappedEvent{ 250 { 251 inputLogEvent: &cloudwatchlogs.InputLogEvent{ 252 Message: aws.String(logline), 253 }, 254 }, 255 } 256 257 stream.publishBatch(events) 258 if stream.sequenceToken == nil { 259 t.Fatal("Expected non-nil sequenceToken") 260 } 261 if *stream.sequenceToken != sequenceToken { 262 t.Errorf("Expected sequenceToken to be %s, but was %s", sequenceToken, *stream.sequenceToken) 263 } 264 } 265 266 func TestPublishBatchInvalidSeqSuccess(t *testing.T) { 267 mockClient := newMockClientBuffered(2) 268 stream := &logStream{ 269 client: mockClient, 270 logGroupName: groupName, 271 logStreamName: streamName, 272 sequenceToken: aws.String(sequenceToken), 273 } 274 mockClient.putLogEventsResult <- &putLogEventsResult{ 275 errorResult: awserr.New(invalidSequenceTokenCode, "use token token", nil), 276 } 277 mockClient.putLogEventsResult <- &putLogEventsResult{ 278 successResult: &cloudwatchlogs.PutLogEventsOutput{ 279 NextSequenceToken: aws.String(nextSequenceToken), 280 }, 281 } 282 283 events := []wrappedEvent{ 284 { 285 inputLogEvent: &cloudwatchlogs.InputLogEvent{ 286 Message: aws.String(logline), 287 }, 288 }, 289 } 290 291 stream.publishBatch(events) 292 if stream.sequenceToken == nil { 293 t.Fatal("Expected non-nil sequenceToken") 294 } 295 if *stream.sequenceToken != nextSequenceToken { 296 t.Errorf("Expected sequenceToken to be %s, but was %s", nextSequenceToken, *stream.sequenceToken) 297 } 298 299 argument := <-mockClient.putLogEventsArgument 300 if argument == nil { 301 t.Fatal("Expected non-nil PutLogEventsInput") 302 } 303 if argument.SequenceToken == nil { 304 t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken") 305 } 306 if *argument.SequenceToken != sequenceToken { 307 t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", sequenceToken, *argument.SequenceToken) 308 } 309 if len(argument.LogEvents) != 1 { 310 t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents)) 311 } 312 if argument.LogEvents[0] != events[0].inputLogEvent { 313 t.Error("Expected event to equal input") 314 } 315 316 argument = <-mockClient.putLogEventsArgument 317 if argument == nil { 318 t.Fatal("Expected non-nil PutLogEventsInput") 319 } 320 if argument.SequenceToken == nil { 321 t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken") 322 } 323 if *argument.SequenceToken != "token" { 324 t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", "token", *argument.SequenceToken) 325 } 326 if len(argument.LogEvents) != 1 { 327 t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents)) 328 } 329 if argument.LogEvents[0] != events[0].inputLogEvent { 330 t.Error("Expected event to equal input") 331 } 332 } 333 334 func TestPublishBatchAlreadyAccepted(t *testing.T) { 335 mockClient := newMockClient() 336 stream := &logStream{ 337 client: mockClient, 338 logGroupName: groupName, 339 logStreamName: streamName, 340 sequenceToken: aws.String(sequenceToken), 341 } 342 mockClient.putLogEventsResult <- &putLogEventsResult{ 343 errorResult: awserr.New(dataAlreadyAcceptedCode, "use token token", nil), 344 } 345 346 events := []wrappedEvent{ 347 { 348 inputLogEvent: &cloudwatchlogs.InputLogEvent{ 349 Message: aws.String(logline), 350 }, 351 }, 352 } 353 354 stream.publishBatch(events) 355 if stream.sequenceToken == nil { 356 t.Fatal("Expected non-nil sequenceToken") 357 } 358 if *stream.sequenceToken != "token" { 359 t.Errorf("Expected sequenceToken to be %s, but was %s", "token", *stream.sequenceToken) 360 } 361 362 argument := <-mockClient.putLogEventsArgument 363 if argument == nil { 364 t.Fatal("Expected non-nil PutLogEventsInput") 365 } 366 if argument.SequenceToken == nil { 367 t.Fatal("Expected non-nil PutLogEventsInput.SequenceToken") 368 } 369 if *argument.SequenceToken != sequenceToken { 370 t.Errorf("Expected PutLogEventsInput.SequenceToken to be %s, but was %s", sequenceToken, *argument.SequenceToken) 371 } 372 if len(argument.LogEvents) != 1 { 373 t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents)) 374 } 375 if argument.LogEvents[0] != events[0].inputLogEvent { 376 t.Error("Expected event to equal input") 377 } 378 } 379 380 func TestCollectBatchSimple(t *testing.T) { 381 mockClient := newMockClient() 382 stream := &logStream{ 383 client: mockClient, 384 logGroupName: groupName, 385 logStreamName: streamName, 386 sequenceToken: aws.String(sequenceToken), 387 messages: make(chan *logger.Message), 388 } 389 mockClient.putLogEventsResult <- &putLogEventsResult{ 390 successResult: &cloudwatchlogs.PutLogEventsOutput{ 391 NextSequenceToken: aws.String(nextSequenceToken), 392 }, 393 } 394 ticks := make(chan time.Time) 395 newTicker = func(_ time.Duration) *time.Ticker { 396 return &time.Ticker{ 397 C: ticks, 398 } 399 } 400 401 go stream.collectBatch() 402 403 stream.Log(&logger.Message{ 404 Line: []byte(logline), 405 Timestamp: time.Time{}, 406 }) 407 408 ticks <- time.Time{} 409 stream.Close() 410 411 argument := <-mockClient.putLogEventsArgument 412 if argument == nil { 413 t.Fatal("Expected non-nil PutLogEventsInput") 414 } 415 if len(argument.LogEvents) != 1 { 416 t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents)) 417 } 418 if *argument.LogEvents[0].Message != logline { 419 t.Errorf("Expected message to be %s but was %s", logline, *argument.LogEvents[0].Message) 420 } 421 } 422 423 func TestCollectBatchTicker(t *testing.T) { 424 mockClient := newMockClient() 425 stream := &logStream{ 426 client: mockClient, 427 logGroupName: groupName, 428 logStreamName: streamName, 429 sequenceToken: aws.String(sequenceToken), 430 messages: make(chan *logger.Message), 431 } 432 mockClient.putLogEventsResult <- &putLogEventsResult{ 433 successResult: &cloudwatchlogs.PutLogEventsOutput{ 434 NextSequenceToken: aws.String(nextSequenceToken), 435 }, 436 } 437 ticks := make(chan time.Time) 438 newTicker = func(_ time.Duration) *time.Ticker { 439 return &time.Ticker{ 440 C: ticks, 441 } 442 } 443 444 go stream.collectBatch() 445 446 stream.Log(&logger.Message{ 447 Line: []byte(logline + " 1"), 448 Timestamp: time.Time{}, 449 }) 450 stream.Log(&logger.Message{ 451 Line: []byte(logline + " 2"), 452 Timestamp: time.Time{}, 453 }) 454 455 ticks <- time.Time{} 456 457 // Verify first batch 458 argument := <-mockClient.putLogEventsArgument 459 if argument == nil { 460 t.Fatal("Expected non-nil PutLogEventsInput") 461 } 462 if len(argument.LogEvents) != 2 { 463 t.Errorf("Expected LogEvents to contain 2 elements, but contains %d", len(argument.LogEvents)) 464 } 465 if *argument.LogEvents[0].Message != logline+" 1" { 466 t.Errorf("Expected message to be %s but was %s", logline+" 1", *argument.LogEvents[0].Message) 467 } 468 if *argument.LogEvents[1].Message != logline+" 2" { 469 t.Errorf("Expected message to be %s but was %s", logline+" 2", *argument.LogEvents[0].Message) 470 } 471 472 stream.Log(&logger.Message{ 473 Line: []byte(logline + " 3"), 474 Timestamp: time.Time{}, 475 }) 476 477 ticks <- time.Time{} 478 argument = <-mockClient.putLogEventsArgument 479 if argument == nil { 480 t.Fatal("Expected non-nil PutLogEventsInput") 481 } 482 if len(argument.LogEvents) != 1 { 483 t.Errorf("Expected LogEvents to contain 1 elements, but contains %d", len(argument.LogEvents)) 484 } 485 if *argument.LogEvents[0].Message != logline+" 3" { 486 t.Errorf("Expected message to be %s but was %s", logline+" 3", *argument.LogEvents[0].Message) 487 } 488 489 stream.Close() 490 491 } 492 493 func TestCollectBatchMultilinePattern(t *testing.T) { 494 mockClient := newMockClient() 495 multilinePattern := regexp.MustCompile("xxxx") 496 stream := &logStream{ 497 client: mockClient, 498 logGroupName: groupName, 499 logStreamName: streamName, 500 multilinePattern: multilinePattern, 501 sequenceToken: aws.String(sequenceToken), 502 messages: make(chan *logger.Message), 503 } 504 mockClient.putLogEventsResult <- &putLogEventsResult{ 505 successResult: &cloudwatchlogs.PutLogEventsOutput{ 506 NextSequenceToken: aws.String(nextSequenceToken), 507 }, 508 } 509 ticks := make(chan time.Time) 510 newTicker = func(_ time.Duration) *time.Ticker { 511 return &time.Ticker{ 512 C: ticks, 513 } 514 } 515 516 go stream.collectBatch() 517 518 stream.Log(&logger.Message{ 519 Line: []byte(logline), 520 Timestamp: time.Now(), 521 }) 522 stream.Log(&logger.Message{ 523 Line: []byte(logline), 524 Timestamp: time.Now(), 525 }) 526 stream.Log(&logger.Message{ 527 Line: []byte("xxxx " + logline), 528 Timestamp: time.Now(), 529 }) 530 531 ticks <- time.Now() 532 533 // Verify single multiline event 534 argument := <-mockClient.putLogEventsArgument 535 assert.NotNil(t, argument, "Expected non-nil PutLogEventsInput") 536 assert.Equal(t, 1, len(argument.LogEvents), "Expected single multiline event") 537 assert.Equal(t, logline+"\n"+logline+"\n", *argument.LogEvents[0].Message, "Received incorrect multiline message") 538 539 stream.Close() 540 541 // Verify single event 542 argument = <-mockClient.putLogEventsArgument 543 assert.NotNil(t, argument, "Expected non-nil PutLogEventsInput") 544 assert.Equal(t, 1, len(argument.LogEvents), "Expected single multiline event") 545 assert.Equal(t, "xxxx "+logline+"\n", *argument.LogEvents[0].Message, "Received incorrect multiline message") 546 } 547 548 func BenchmarkCollectBatch(b *testing.B) { 549 for i := 0; i < b.N; i++ { 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 570 go stream.collectBatch() 571 stream.logGenerator(10, 100) 572 ticks <- time.Time{} 573 stream.Close() 574 } 575 } 576 577 func BenchmarkCollectBatchMultilinePattern(b *testing.B) { 578 for i := 0; i < b.N; i++ { 579 mockClient := newMockClient() 580 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]`) 581 stream := &logStream{ 582 client: mockClient, 583 logGroupName: groupName, 584 logStreamName: streamName, 585 multilinePattern: multilinePattern, 586 sequenceToken: aws.String(sequenceToken), 587 messages: make(chan *logger.Message), 588 } 589 mockClient.putLogEventsResult <- &putLogEventsResult{ 590 successResult: &cloudwatchlogs.PutLogEventsOutput{ 591 NextSequenceToken: aws.String(nextSequenceToken), 592 }, 593 } 594 ticks := make(chan time.Time) 595 newTicker = func(_ time.Duration) *time.Ticker { 596 return &time.Ticker{ 597 C: ticks, 598 } 599 } 600 go stream.collectBatch() 601 stream.logGenerator(10, 100) 602 ticks <- time.Time{} 603 stream.Close() 604 } 605 } 606 607 func TestCollectBatchMultilinePatternMaxEventAge(t *testing.T) { 608 mockClient := newMockClient() 609 multilinePattern := regexp.MustCompile("xxxx") 610 stream := &logStream{ 611 client: mockClient, 612 logGroupName: groupName, 613 logStreamName: streamName, 614 multilinePattern: multilinePattern, 615 sequenceToken: aws.String(sequenceToken), 616 messages: make(chan *logger.Message), 617 } 618 mockClient.putLogEventsResult <- &putLogEventsResult{ 619 successResult: &cloudwatchlogs.PutLogEventsOutput{ 620 NextSequenceToken: aws.String(nextSequenceToken), 621 }, 622 } 623 ticks := make(chan time.Time) 624 newTicker = func(_ time.Duration) *time.Ticker { 625 return &time.Ticker{ 626 C: ticks, 627 } 628 } 629 630 go stream.collectBatch() 631 632 stream.Log(&logger.Message{ 633 Line: []byte(logline), 634 Timestamp: time.Now(), 635 }) 636 637 // Log an event 1 second later 638 stream.Log(&logger.Message{ 639 Line: []byte(logline), 640 Timestamp: time.Now().Add(time.Second), 641 }) 642 643 // Fire ticker batchPublishFrequency seconds later 644 ticks <- time.Now().Add(batchPublishFrequency * time.Second) 645 646 // Verify single multiline event is flushed after maximum event buffer age (batchPublishFrequency) 647 argument := <-mockClient.putLogEventsArgument 648 assert.NotNil(t, argument, "Expected non-nil PutLogEventsInput") 649 assert.Equal(t, 1, len(argument.LogEvents), "Expected single multiline event") 650 assert.Equal(t, logline+"\n"+logline+"\n", *argument.LogEvents[0].Message, "Received incorrect multiline message") 651 652 stream.Close() 653 } 654 655 func TestCollectBatchMultilinePatternNegativeEventAge(t *testing.T) { 656 mockClient := newMockClient() 657 multilinePattern := regexp.MustCompile("xxxx") 658 stream := &logStream{ 659 client: mockClient, 660 logGroupName: groupName, 661 logStreamName: streamName, 662 multilinePattern: multilinePattern, 663 sequenceToken: aws.String(sequenceToken), 664 messages: make(chan *logger.Message), 665 } 666 mockClient.putLogEventsResult <- &putLogEventsResult{ 667 successResult: &cloudwatchlogs.PutLogEventsOutput{ 668 NextSequenceToken: aws.String(nextSequenceToken), 669 }, 670 } 671 ticks := make(chan time.Time) 672 newTicker = func(_ time.Duration) *time.Ticker { 673 return &time.Ticker{ 674 C: ticks, 675 } 676 } 677 678 go stream.collectBatch() 679 680 stream.Log(&logger.Message{ 681 Line: []byte(logline), 682 Timestamp: time.Now(), 683 }) 684 685 // Log an event 1 second later 686 stream.Log(&logger.Message{ 687 Line: []byte(logline), 688 Timestamp: time.Now().Add(time.Second), 689 }) 690 691 // Fire ticker in past to simulate negative event buffer age 692 ticks <- time.Now().Add(-time.Second) 693 694 // Verify single multiline event is flushed with a negative event buffer age 695 argument := <-mockClient.putLogEventsArgument 696 assert.NotNil(t, argument, "Expected non-nil PutLogEventsInput") 697 assert.Equal(t, 1, len(argument.LogEvents), "Expected single multiline event") 698 assert.Equal(t, logline+"\n"+logline+"\n", *argument.LogEvents[0].Message, "Received incorrect multiline message") 699 700 stream.Close() 701 } 702 703 func TestCollectBatchClose(t *testing.T) { 704 mockClient := newMockClient() 705 stream := &logStream{ 706 client: mockClient, 707 logGroupName: groupName, 708 logStreamName: streamName, 709 sequenceToken: aws.String(sequenceToken), 710 messages: make(chan *logger.Message), 711 } 712 mockClient.putLogEventsResult <- &putLogEventsResult{ 713 successResult: &cloudwatchlogs.PutLogEventsOutput{ 714 NextSequenceToken: aws.String(nextSequenceToken), 715 }, 716 } 717 var ticks = make(chan time.Time) 718 newTicker = func(_ time.Duration) *time.Ticker { 719 return &time.Ticker{ 720 C: ticks, 721 } 722 } 723 724 go stream.collectBatch() 725 726 stream.Log(&logger.Message{ 727 Line: []byte(logline), 728 Timestamp: time.Time{}, 729 }) 730 731 // no ticks 732 stream.Close() 733 734 argument := <-mockClient.putLogEventsArgument 735 if argument == nil { 736 t.Fatal("Expected non-nil PutLogEventsInput") 737 } 738 if len(argument.LogEvents) != 1 { 739 t.Errorf("Expected LogEvents to contain 1 element, but contains %d", len(argument.LogEvents)) 740 } 741 if *argument.LogEvents[0].Message != logline { 742 t.Errorf("Expected message to be %s but was %s", logline, *argument.LogEvents[0].Message) 743 } 744 } 745 746 func TestCollectBatchLineSplit(t *testing.T) { 747 mockClient := newMockClient() 748 stream := &logStream{ 749 client: mockClient, 750 logGroupName: groupName, 751 logStreamName: streamName, 752 sequenceToken: aws.String(sequenceToken), 753 messages: make(chan *logger.Message), 754 } 755 mockClient.putLogEventsResult <- &putLogEventsResult{ 756 successResult: &cloudwatchlogs.PutLogEventsOutput{ 757 NextSequenceToken: aws.String(nextSequenceToken), 758 }, 759 } 760 var ticks = make(chan time.Time) 761 newTicker = func(_ time.Duration) *time.Ticker { 762 return &time.Ticker{ 763 C: ticks, 764 } 765 } 766 767 go stream.collectBatch() 768 769 longline := strings.Repeat("A", maximumBytesPerEvent) 770 stream.Log(&logger.Message{ 771 Line: []byte(longline + "B"), 772 Timestamp: time.Time{}, 773 }) 774 775 // no ticks 776 stream.Close() 777 778 argument := <-mockClient.putLogEventsArgument 779 if argument == nil { 780 t.Fatal("Expected non-nil PutLogEventsInput") 781 } 782 if len(argument.LogEvents) != 2 { 783 t.Errorf("Expected LogEvents to contain 2 elements, but contains %d", len(argument.LogEvents)) 784 } 785 if *argument.LogEvents[0].Message != longline { 786 t.Errorf("Expected message to be %s but was %s", longline, *argument.LogEvents[0].Message) 787 } 788 if *argument.LogEvents[1].Message != "B" { 789 t.Errorf("Expected message to be %s but was %s", "B", *argument.LogEvents[1].Message) 790 } 791 } 792 793 func TestCollectBatchMaxEvents(t *testing.T) { 794 mockClient := newMockClientBuffered(1) 795 stream := &logStream{ 796 client: mockClient, 797 logGroupName: groupName, 798 logStreamName: streamName, 799 sequenceToken: aws.String(sequenceToken), 800 messages: make(chan *logger.Message), 801 } 802 mockClient.putLogEventsResult <- &putLogEventsResult{ 803 successResult: &cloudwatchlogs.PutLogEventsOutput{ 804 NextSequenceToken: aws.String(nextSequenceToken), 805 }, 806 } 807 var ticks = make(chan time.Time) 808 newTicker = func(_ time.Duration) *time.Ticker { 809 return &time.Ticker{ 810 C: ticks, 811 } 812 } 813 814 go stream.collectBatch() 815 816 line := "A" 817 for i := 0; i <= maximumLogEventsPerPut; i++ { 818 stream.Log(&logger.Message{ 819 Line: []byte(line), 820 Timestamp: time.Time{}, 821 }) 822 } 823 824 // no ticks 825 stream.Close() 826 827 argument := <-mockClient.putLogEventsArgument 828 if argument == nil { 829 t.Fatal("Expected non-nil PutLogEventsInput") 830 } 831 if len(argument.LogEvents) != maximumLogEventsPerPut { 832 t.Errorf("Expected LogEvents to contain %d elements, but contains %d", maximumLogEventsPerPut, len(argument.LogEvents)) 833 } 834 835 argument = <-mockClient.putLogEventsArgument 836 if argument == nil { 837 t.Fatal("Expected non-nil PutLogEventsInput") 838 } 839 if len(argument.LogEvents) != 1 { 840 t.Errorf("Expected LogEvents to contain %d elements, but contains %d", 1, len(argument.LogEvents)) 841 } 842 } 843 844 func TestCollectBatchMaxTotalBytes(t *testing.T) { 845 mockClient := newMockClientBuffered(1) 846 stream := &logStream{ 847 client: mockClient, 848 logGroupName: groupName, 849 logStreamName: streamName, 850 sequenceToken: aws.String(sequenceToken), 851 messages: make(chan *logger.Message), 852 } 853 mockClient.putLogEventsResult <- &putLogEventsResult{ 854 successResult: &cloudwatchlogs.PutLogEventsOutput{ 855 NextSequenceToken: aws.String(nextSequenceToken), 856 }, 857 } 858 var ticks = make(chan time.Time) 859 newTicker = func(_ time.Duration) *time.Ticker { 860 return &time.Ticker{ 861 C: ticks, 862 } 863 } 864 865 go stream.collectBatch() 866 867 longline := strings.Repeat("A", maximumBytesPerPut) 868 stream.Log(&logger.Message{ 869 Line: []byte(longline + "B"), 870 Timestamp: time.Time{}, 871 }) 872 873 // no ticks 874 stream.Close() 875 876 argument := <-mockClient.putLogEventsArgument 877 if argument == nil { 878 t.Fatal("Expected non-nil PutLogEventsInput") 879 } 880 bytes := 0 881 for _, event := range argument.LogEvents { 882 bytes += len(*event.Message) 883 } 884 if bytes > maximumBytesPerPut { 885 t.Errorf("Expected <= %d bytes but was %d", maximumBytesPerPut, bytes) 886 } 887 888 argument = <-mockClient.putLogEventsArgument 889 if len(argument.LogEvents) != 1 { 890 t.Errorf("Expected LogEvents to contain 1 elements, but contains %d", len(argument.LogEvents)) 891 } 892 message := *argument.LogEvents[0].Message 893 if message[len(message)-1:] != "B" { 894 t.Errorf("Expected message to be %s but was %s", "B", message[len(message)-1:]) 895 } 896 } 897 898 func TestCollectBatchWithDuplicateTimestamps(t *testing.T) { 899 mockClient := newMockClient() 900 stream := &logStream{ 901 client: mockClient, 902 logGroupName: groupName, 903 logStreamName: streamName, 904 sequenceToken: aws.String(sequenceToken), 905 messages: make(chan *logger.Message), 906 } 907 mockClient.putLogEventsResult <- &putLogEventsResult{ 908 successResult: &cloudwatchlogs.PutLogEventsOutput{ 909 NextSequenceToken: aws.String(nextSequenceToken), 910 }, 911 } 912 ticks := make(chan time.Time) 913 newTicker = func(_ time.Duration) *time.Ticker { 914 return &time.Ticker{ 915 C: ticks, 916 } 917 } 918 919 go stream.collectBatch() 920 921 times := maximumLogEventsPerPut 922 expectedEvents := []*cloudwatchlogs.InputLogEvent{} 923 timestamp := time.Now() 924 for i := 0; i < times; i++ { 925 line := fmt.Sprintf("%d", i) 926 if i%2 == 0 { 927 timestamp.Add(1 * time.Nanosecond) 928 } 929 stream.Log(&logger.Message{ 930 Line: []byte(line), 931 Timestamp: timestamp, 932 }) 933 expectedEvents = append(expectedEvents, &cloudwatchlogs.InputLogEvent{ 934 Message: aws.String(line), 935 Timestamp: aws.Int64(timestamp.UnixNano() / int64(time.Millisecond)), 936 }) 937 } 938 939 ticks <- time.Time{} 940 stream.Close() 941 942 argument := <-mockClient.putLogEventsArgument 943 if argument == nil { 944 t.Fatal("Expected non-nil PutLogEventsInput") 945 } 946 if len(argument.LogEvents) != times { 947 t.Errorf("Expected LogEvents to contain %d elements, but contains %d", times, len(argument.LogEvents)) 948 } 949 for i := 0; i < times; i++ { 950 if !reflect.DeepEqual(*argument.LogEvents[i], *expectedEvents[i]) { 951 t.Errorf("Expected event to be %v but was %v", *expectedEvents[i], *argument.LogEvents[i]) 952 } 953 } 954 } 955 956 func TestParseLogOptionsMultilinePattern(t *testing.T) { 957 info := logger.Info{ 958 Config: map[string]string{ 959 multilinePatternKey: "^xxxx", 960 }, 961 } 962 963 multilinePattern, err := parseMultilineOptions(info) 964 assert.Nil(t, err, "Received unexpected error") 965 assert.True(t, multilinePattern.MatchString("xxxx"), "No multiline pattern match found") 966 } 967 968 func TestParseLogOptionsDatetimeFormat(t *testing.T) { 969 datetimeFormatTests := []struct { 970 format string 971 match string 972 }{ 973 {"%d/%m/%y %a %H:%M:%S%L %Z", "31/12/10 Mon 08:42:44.345 NZDT"}, 974 {"%Y-%m-%d %A %I:%M:%S.%f%p%z", "2007-12-04 Monday 08:42:44.123456AM+1200"}, 975 {"%b|%b|%b|%b|%b|%b|%b|%b|%b|%b|%b|%b", "Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec"}, 976 {"%B|%B|%B|%B|%B|%B|%B|%B|%B|%B|%B|%B", "January|February|March|April|May|June|July|August|September|October|November|December"}, 977 {"%A|%A|%A|%A|%A|%A|%A", "Monday|Tuesday|Wednesday|Thursday|Friday|Saturday|Sunday"}, 978 {"%a|%a|%a|%a|%a|%a|%a", "Mon|Tue|Wed|Thu|Fri|Sat|Sun"}, 979 {"Day of the week: %w, Day of the year: %j", "Day of the week: 4, Day of the year: 091"}, 980 } 981 for _, dt := range datetimeFormatTests { 982 t.Run(dt.match, func(t *testing.T) { 983 info := logger.Info{ 984 Config: map[string]string{ 985 datetimeFormatKey: dt.format, 986 }, 987 } 988 multilinePattern, err := parseMultilineOptions(info) 989 assert.Nil(t, err, "Received unexpected error") 990 assert.True(t, multilinePattern.MatchString(dt.match), "No multiline pattern match found") 991 }) 992 } 993 } 994 995 func TestValidateLogOptionsDatetimeFormatAndMultilinePattern(t *testing.T) { 996 cfg := map[string]string{ 997 multilinePatternKey: "^xxxx", 998 datetimeFormatKey: "%Y-%m-%d", 999 logGroupKey: groupName, 1000 } 1001 conflictingLogOptionsError := "you cannot configure log opt 'awslogs-datetime-format' and 'awslogs-multiline-pattern' at the same time" 1002 1003 err := ValidateLogOpt(cfg) 1004 assert.NotNil(t, err, "Expected an error") 1005 assert.Equal(t, err.Error(), conflictingLogOptionsError, "Received invalid error") 1006 } 1007 1008 func TestCreateTagSuccess(t *testing.T) { 1009 mockClient := newMockClient() 1010 info := logger.Info{ 1011 ContainerName: "/test-container", 1012 ContainerID: "container-abcdefghijklmnopqrstuvwxyz01234567890", 1013 Config: map[string]string{"tag": "{{.Name}}/{{.FullID}}"}, 1014 } 1015 logStreamName, e := loggerutils.ParseLogTag(info, loggerutils.DefaultTemplate) 1016 if e != nil { 1017 t.Errorf("Error generating tag: %q", e) 1018 } 1019 stream := &logStream{ 1020 client: mockClient, 1021 logGroupName: groupName, 1022 logStreamName: logStreamName, 1023 } 1024 mockClient.createLogStreamResult <- &createLogStreamResult{} 1025 1026 err := stream.create() 1027 1028 if err != nil { 1029 t.Errorf("Received unexpected err: %v\n", err) 1030 } 1031 argument := <-mockClient.createLogStreamArgument 1032 1033 if *argument.LogStreamName != "test-container/container-abcdefghijklmnopqrstuvwxyz01234567890" { 1034 t.Errorf("Expected LogStreamName to be %s", "test-container/container-abcdefghijklmnopqrstuvwxyz01234567890") 1035 } 1036 } 1037 1038 func BenchmarkUnwrapEvents(b *testing.B) { 1039 events := make([]wrappedEvent, maximumLogEventsPerPut) 1040 for i := 0; i < maximumLogEventsPerPut; i++ { 1041 mes := strings.Repeat("0", maximumBytesPerEvent) 1042 events[i].inputLogEvent = &cloudwatchlogs.InputLogEvent{ 1043 Message: &mes, 1044 } 1045 } 1046 1047 as := assert.New(b) 1048 b.ResetTimer() 1049 for i := 0; i < b.N; i++ { 1050 res := unwrapEvents(events) 1051 as.Len(res, maximumLogEventsPerPut) 1052 } 1053 }