Arash Taher

String operation are not atomic in Go

I was facing intermittent failure in one of our tests, and when looking at the stack trace, I could see that it’s pointing out to this line: {Body: []byte(m.NextSubscriptionMessageToBeReceived)}

How could we fail on this line?

That’s when you know spending too much time in the single threaded world of JS has taken its toll on you :)

Let’s go and check the official documentations:

Strings are actually very simple: they are just read-only slices of bytes…

So what they practically are is a two-word headers (pointer + length).

Now, when you have concurrent reads and writes on the slices, it can cause a header to be old pointer + new length or vice versa.
This now will lead to an invalid memory read during []byte(str)

Example

You can create the scenario for the race condition, but due to the non-deterministic nature of the problem, crashing the program is not that simple.

Here’s an example of such case:

package main

import (
	"fmt"
	"sync"
	"time"
)

func main() {
	var message string
	var wg sync.WaitGroup

	// Start 10 goroutines that write to the same string
	for i := 0; i < 10; i++ {
		wg.Add(1)
		go func(id int) {
			defer wg.Done()
			// Writing to shared string variable
			message = fmt.Sprintf("Hello from goroutine %d", id)
			time.Sleep(time.Millisecond) // Simulate some work
		}(i)
	}

	// Start another goroutine that reads the string
	wg.Add(1)
	go func() {
		defer wg.Done()
		for j := 0; j < 5; j++ {
			// Reading from shared string variable
			fmt.Println("Reading:", message)
			time.Sleep(time.Millisecond)
		}
	}()

	wg.Wait()
	fmt.Println("Final message:", message)
}

If you run the code with -race option, you will get this result:

==================
WARNING: DATA RACE
Write at 0x00c0000101b0 by goroutine 15:
  main.main.func1()
      /Users/cmd/exp/main.go:17 +0xbc
  main.main.gowrap1()
      /Users/cmd/exp/main.go:19 +0x40

Previous read at 0x00c0000101b0 by goroutine 16:
  main.main.func2()
      /Users/cmd/exp/main.go:27 +0xb0

Goroutine 15 (running) created at:
  main.main()
      /Users/cmd/exp/main.go:15 +0x9c

Goroutine 16 (running) created at:
  main.main()
      /Users/cmd/exp/main.go:23 +0x24c
==================
==================
WARNING: DATA RACE
Write at 0x00c0000101b0 by goroutine 10:
  main.main.func1()
      /Users/cmd/exp/main.go:17 +0xbc
  main.main.gowrap1()
      /Users/cmd/exp/main.go:19 +0x40

Previous write at 0x00c0000101b0 by goroutine 6:
  main.main.func1()
      /Users/cmd/exp/main.go:17 +0xbc
  main.main.gowrap1()
      /Users/cmd/exp/main.go:19 +0x40

Goroutine 10 (running) created at:
  main.main()
      /Users/cmd/exp/main.go:15 +0x9c

Goroutine 6 (running) created at:
  main.main()
      /Users/cmd/exp/main.go:15 +0x9c
==================

As you can see we have two race cases: one read/write race and one write/write race (when multiple Go routines want to write to the same string).

Fix

We need to mark the variable access as critical section in the code. That can be done using a mutex.

package main

import (
	"fmt"
	"sync"
	"time"
)

func main() {
	var message string
	var mu sync.Mutex // Add mutex for synchronization
	var wg sync.WaitGroup

	// Start 10 goroutines that write to the same string
	for i := 0; i < 10; i++ {
		wg.Add(1)
		go func(id int) {
			defer wg.Done()
			mu.Lock() // Lock before writing
			message = fmt.Sprintf("Hello from goroutine %d", id)
			mu.Unlock() // Unlock after writing
			time.Sleep(time.Millisecond)
		}(i)
	}

	// Start another goroutine that reads the string
	wg.Add(1)
	go func() {
		defer wg.Done()
		for j := 0; j < 5; j++ {
			mu.Lock() // Lock before reading
			msg := message
			mu.Unlock() // Unlock after reading
			fmt.Println("Reading:", msg)
			time.Sleep(time.Millisecond)
		}
	}()

	wg.Wait()
	mu.Lock()
	fmt.Println("Final message:", message)
	mu.Unlock()
}

Tagged: #Go #Debug #Concurrency

Subscribe to Newsletter