TestSaramaConsumerWrapper_start_Errors racy test

[black-adder]

=== RUN   TestSaramaConsumerWrapper_start_Errors
2018-10-08T11:39:47.148Z	INFO	consumer/consumer.go:67	Starting main loop
2018-10-08T11:39:47.148Z	INFO	consumer/consumer.go:94	Starting message handler	{"partition": 316}
2018-10-08T11:39:47.148Z	INFO	consumer/consumer.go:125	Starting error handler	{"partition": 316}
2018-10-08T11:39:47.148Z	ERROR	consumer/consumer.go:132	Error consuming from Kafka	{"error": "kafka: error while consuming morekuzambu/316: Daisy, Daisy"}
github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*Consumer).handleErrors
	/home/travis/gopath/src/github.com/jaegertracing/jaeger/cmd/ingester/app/consumer/consumer.go:132
2018-10-08T11:39:47.150Z	INFO	consumer/consumer.go:119	Closing partition consumer	{"partition": 316}
2018-10-08T11:39:47.150Z	INFO	consumer/consumer.go:115	Finished handling messages	{"partition": 316}
2018-10-08T11:39:47.150Z	INFO	consumer/consumer.go:119	Closing partition consumer	{"partition": 316}
==================
WARNING: DATA RACE
Read at 0x00c000044a80 by goroutine 25:
  github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks.(*PartitionConsumer).Close()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks/consumer.go:215 +0x553
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*partitionConsumerWrapper).Close()
      <autogenerated>:1 +0x67
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*Consumer).closePartition()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/cmd/ingester/app/consumer/consumer.go:120 +0x1cd
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*Consumer).handleMessages()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/cmd/ingester/app/consumer/consumer.go:116 +0xa05
Previous write at 0x00c000044a80 by goroutine 23:
  runtime.closechan()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/runtime/chan.go:327 +0x0
  github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks.(*PartitionConsumer).AsyncClose.func1()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks/consumer.go:203 +0x86
  sync.(*Once).Do()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/sync/once.go:44 +0xde
  github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks.(*PartitionConsumer).AsyncClose()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks/consumer.go:201 +0x61
  github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks.(*PartitionConsumer).Close()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/vendor/github.com/Shopify/sarama/mocks/consumer.go:223 +0xdc
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*partitionConsumerWrapper).Close()
      <autogenerated>:1 +0x67
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*Consumer).closePartition()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/cmd/ingester/app/consumer/consumer.go:120 +0x1cd
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*Consumer).Close()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/cmd/ingester/app/consumer/consumer.go:86 +0x143
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.TestSaramaConsumerWrapper_start_Errors()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/cmd/ingester/app/consumer/consumer_test.go:207 +0x63a
  testing.tRunner()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/testing/testing.go:827 +0x162
Goroutine 25 (running) created at:
  github.com/jaegertracing/jaeger/cmd/ingester/app/consumer.(*Consumer).Start.func1()
      /home/travis/gopath/src/github.com/jaegertracing/jaeger/cmd/ingester/app/consumer/consumer.go:77 +0x128
Goroutine 23 (running) created at:
  testing.(*T).Run()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/testing/testing.go:878 +0x650
  testing.runTests.func1()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/testing/testing.go:1119 +0xa8
  testing.tRunner()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/testing/testing.go:827 +0x162
  testing.runTests()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/testing/testing.go:1117 +0x4ee
  testing.(*M).Run()
      /home/travis/.gimme/versions/go1.11.linux.amd64/src/testing/testing.go:1034 +0x2ee
  main.main()
      _testmain.go:118 +0x332
==================
2018-10-08T11:39:47.151Z	INFO	consumer/consumer.go:134	Finished handling errors	{"partition": 316}
2018-10-08T11:39:47.151Z	INFO	consumer/consumer.go:121	Closed partition consumer	{"partition": 316}
2018-10-08T11:39:47.151Z	INFO	consumer/consumer.go:121	Closed partition consumer	{"partition": 316}
2018-10-08T11:39:47.151Z	INFO	consumer/consumer.go:89	Closing parent consumer
--- FAIL: TestSaramaConsumerWrapper_start_Errors (0.00s)
    testing.go:771: race detected during execution of test

From https://travis-ci.org/jaegertracing/jaeger/jobs/438577665

[vprithvi]

Looks like the spec on len and close ver a bit ambiguous and the behavior on Go 1.11 changed (golang/go#27070). Might be worthwhile to update the Sarama driver itself and reproducing before investigating more.

[yurishkuro]

According to golang tickets, it's been fixed in the onesiest patch 1.11.1

[vprithvi]

@black-adder Does the test fail with the patched version - Go 1.11.1?

The attached Travis logs have the following:

$ go version
go version go1.11 linux/amd64

[black-adder]

Fixed by #1104