Why is there a data race in this Go program?

I'm trying to store log messages in a buffer to access them only when I get an error. A bit like in Smarter log handling, the case for opportunistic logging. In this example I fetch the logs from the buffer each 5 seconds but I get a data race when I run it with go run -race code.go.

I'm using channels to communicate but I'm doing something wrong, obviously.

<!-- language: lang-golang -->

package main
import (
"bytes"
"fmt"
"io/ioutil"
"log"
"time"
)
type LogRequest struct {
Buffer chan []byte
}
type LogBuffer struct {
LogInputChan chan []byte
LogRequests  chan LogRequest
}
func (f LogBuffer) Write(b []byte) (n int, err error) {
f.LogInputChan <- b
return len(b), nil
}
func main() {
var logBuffer LogBuffer
logBuffer.LogInputChan = make(chan []byte, 100)
logBuffer.LogRequests = make(chan LogRequest, 100)
log.SetOutput(logBuffer)
// store the log messages in a buffer until we ask for it
go func() {
buf := new(bytes.Buffer)
for {
select {
// receive log messages
case logMessage := <-logBuffer.LogInputChan:
buf.Write(logMessage) // <- data race
case logRequest := <-logBuffer.LogRequests:
c, errReadAll := ioutil.ReadAll(buf)
if errReadAll != nil {
panic(errReadAll)
}
logRequest.Buffer <- c
}
}
}()
// log a test message every 1 second
go func() {
for i := 0; i < 30; i++ {
log.Printf("test: %d", i) // <- data race
time.Sleep(1 * time.Second)
}
}()
// print the log every 5 seconds
go func() {
for {
time.Sleep(5 * time.Second)
var logRequest LogRequest
logRequest.Buffer = make(chan []byte, 1)
logBuffer.LogRequests <- logRequest
buffer := <-logRequest.Buffer
fmt.Printf("**** LOG *****\n%s**** END *****\n\n", buffer)
}
}()
time.Sleep(45 * time.Second)
}

The log package uses an internal buffer to build-up log messages for output (the buf field in log/Logger). It composes the header, appends the data provided by the caller, then passes this buffer to your Write method for output.

In order to reduce allocations, the log package recycles this buffer for each log message. It's not stated in the documentation, but the implicit assumption is that your Write method only uses the provided []byte data for the duration of the Write call. This assumption is OK for most outputs, e.g. a file or STDOUT.

To avoid a data race, you need to make an explicit copy of the incoming data before returning from the Write function:

func (f LogBuffer) Write(b []byte) (n int, err error) {
z := make([]byte, len(b))
copy(z, b)
f.LogInputChan <- z
return len(b), nil
}