racy test: daemon/logger: TestCopier, awslogs.TestCollectBatchMaxTotalBytes

**Steps to reproduce the issue:**
Execute `BUILDFLAGS=-race make test-unit`
(Tested on 29dbcbad878483d9239d6a432c85620aced895c4)

**Describe the results you received:**

```
==================
WARNING: DATA RACE
Write by goroutine 8:
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:130 +0x4b
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Previous write by goroutine 9:
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:130 +0x4b
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Goroutine 8 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc

Goroutine 9 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc
==================
==================
WARNING: DATA RACE
Read by goroutine 8:
  bytes.(*Buffer).grow()
      /usr/local/go/src/bytes/buffer.go:85 +0x45
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:131 +0x6b
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Previous write by goroutine 9:
  bytes.(*Buffer).grow()
      /usr/local/go/src/bytes/buffer.go:109 +0x209
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:131 +0x6b
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Goroutine 8 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc

Goroutine 9 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc
==================
==================
WARNING: DATA RACE
Read by goroutine 8:
  bytes.(*Buffer).grow()
      /usr/local/go/src/bytes/buffer.go:85 +0x61
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:131 +0x6b
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Previous write by goroutine 9:
  bytes.(*Buffer).grow()
      /usr/local/go/src/bytes/buffer.go:107 +0x1be
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:131 +0x6b
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Goroutine 8 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc

Goroutine 9 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc
==================
==================
WARNING: DATA RACE
Write by goroutine 8:
  runtime.slicecopy()
      /usr/local/go/src/runtime/slice.go:110 +0x0
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:132 +0xfd
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Previous write by goroutine 9:
  runtime.slicecopy()
      /usr/local/go/src/runtime/slice.go:110 +0x0
  bytes.(*Buffer).Write()
      /usr/local/go/src/bytes/buffer.go:132 +0xfd
  encoding/json.(*Encoder).Encode()
      /usr/local/go/src/encoding/json/stream.go:201 +0x232
  github.com/docker/docker/daemon/logger.(*TestLoggerJSON).Log()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:20 +0xbb
  github.com/docker/docker/daemon/logger.(*Copier).copySrc()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:67 +0x7bb

Goroutine 8 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc

Goroutine 9 (running) created at:
  github.com/docker/docker/daemon/logger.(*Copier).Run()
      github.com/docker/docker/daemon/logger/_test/_obj_test/copier.go:45 +0x1ab
  github.com/docker/docker/daemon/logger.TestCopier()
      /go/src/github.com/docker/docker/daemon/logger/copier_test.go:65 +0x76c
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc
==================
PASS
coverage: 17.8% of statements
Found 4 data race(s)
FAIL    github.com/docker/docker/daemon/logger  1.222s
time="2016-05-25T01:34:45Z" level=info msg="Trying to get region from EC2 Metadata" 
time="2016-05-25T01:34:45Z" level=info msg="Log stream already exists" errorCode=ResourceAlreadyExistsException logGroupName= logStreamName= message= origError=<nil> 
time="2016-05-25T01:34:45Z" level=error msg="Error!" 
time="2016-05-25T01:34:45Z" level=error msg="Failed to put log events" errorCode=InvalidSequenceTokenException logGroupName=groupName logStreamName=streamName message="use token token" origError=<nil> 
time="2016-05-25T01:34:45Z" level=error msg="Failed to put log events" errorCode=DataAlreadyAcceptedException logGroupName=groupName logStreamName=streamName message="use token token" origError=<nil> 
time="2016-05-25T01:34:45Z" level=info msg="Data already accepted, ignoring error" errorCode=DataAlreadyAcceptedException logGroupName=groupName logStreamName=streamName message="use token token" 
==================
WARNING: DATA RACE
Read by goroutine 26:
  github.com/docker/docker/daemon/logger/awslogs.TestCollectBatchMaxTotalBytes()
      /go/src/github.com/docker/docker/daemon/logger/awslogs/cloudwatchlogs_test.go:612 +0xa27
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc

Previous write by goroutine 27:
  github.com/docker/docker/daemon/logger/awslogs.(*logStream).collectBatch()
      github.com/docker/docker/daemon/logger/awslogs/_test/_obj_test/cloudwatchlogs.go:313 +0x798

Goroutine 26 (running) created at:
  testing.RunTests()
      /usr/local/go/src/testing/testing.go:561 +0xaa3
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:494 +0xe4
  main.main()
      github.com/docker/docker/daemon/logger/awslogs/_test/_testmain.go:128 +0x384

Goroutine 27 (running) created at:
  github.com/docker/docker/daemon/logger/awslogs.TestCollectBatchMaxTotalBytes()
      /go/src/github.com/docker/docker/daemon/logger/awslogs/cloudwatchlogs_test.go:596 +0x6a1
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc
==================
==================
WARNING: DATA RACE
Read by goroutine 26:
  github.com/docker/docker/daemon/logger/awslogs.TestCollectBatchMaxTotalBytes()
      /go/src/github.com/docker/docker/daemon/logger/awslogs/cloudwatchlogs_test.go:613 +0xa4d
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc

Previous write by goroutine 27:
  github.com/docker/docker/daemon/logger/awslogs.(*logStream).collectBatch()
      github.com/docker/docker/daemon/logger/awslogs/_test/_obj_test/cloudwatchlogs.go:312 +0x657

Goroutine 26 (running) created at:
  testing.RunTests()
      /usr/local/go/src/testing/testing.go:561 +0xaa3
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:494 +0xe4
  main.main()
      github.com/docker/docker/daemon/logger/awslogs/_test/_testmain.go:128 +0x384

Goroutine 27 (running) created at:
  github.com/docker/docker/daemon/logger/awslogs.TestCollectBatchMaxTotalBytes()
      /go/src/github.com/docker/docker/daemon/logger/awslogs/cloudwatchlogs_test.go:596 +0x6a1
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc
==================
==================
WARNING: DATA RACE
Read by goroutine 26:
  github.com/docker/docker/daemon/logger/awslogs.TestCollectBatchMaxTotalBytes()
      /go/src/github.com/docker/docker/daemon/logger/awslogs/cloudwatchlogs_test.go:613 +0xa61
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc

Previous write by goroutine 27:
  github.com/docker/docker/daemon/logger/awslogs.(*logStream).collectBatch()
      github.com/docker/docker/daemon/logger/awslogs/_test/_obj_test/cloudwatchlogs.go:311 +0x516

Goroutine 26 (running) created at:
  testing.RunTests()
      /usr/local/go/src/testing/testing.go:561 +0xaa3
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:494 +0xe4
  main.main()
      github.com/docker/docker/daemon/logger/awslogs/_test/_testmain.go:128 +0x384

Goroutine 27 (running) created at:
  github.com/docker/docker/daemon/logger/awslogs.TestCollectBatchMaxTotalBytes()
      /go/src/github.com/docker/docker/daemon/logger/awslogs/cloudwatchlogs_test.go:596 +0x6a1
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:456 +0xdc
==================
PASS
coverage: 77.2% of statements
Found 3 data race(s)
FAIL    github.com/docker/docker/daemon/logger/awslogs  1.122s
?       github.com/docker/docker/daemon/logger/fluentd  [no test files]
?       github.com/docker/docker/daemon/logger/gcplogs  [no test files]
?       github.com/docker/docker/daemon/logger/gelf [no test files]
?       github.com/docker/docker/daemon/logger/journald [no test files]
ok      github.com/docker/docker/daemon/logger/jsonfilelog  1.013s  coverage: 20.1% of statements
ok      github.com/docker/docker/daemon/logger/loggerutils  1.008s  coverage: 14.3% of statements
?       github.com/docker/docker/daemon/logger/splunk   [no test files]
ok      github.com/docker/docker/daemon/logger/syslog   1.011s  coverage: 19.8% of statements
```

**Describe the results you expected:**
There should not be any race.

---

I'll open PR to add `-race` to `go test` after https://github.com/docker/docker/pull/22930 gets merged, which simplifies the flow for `go test`.


Provide feedback

Saved searches

Use saved searches to filter your results more quickly

racy test: daemon/logger: TestCopier, awslogs.TestCollectBatchMaxTotalBytes #22963

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

racy test: daemon/logger: TestCopier, awslogs.TestCollectBatchMaxTotalBytes #22963

Description

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions