← Labsconcurrency-01Concurrency●○○○

A data race that "works", one that doesn't, and what TSan sees

concurrency/01_race_tsan.cppneeds: clang++ -fsanitize=thread, tools/bench.h4 steps

0/4 steps

what this lab teaches

Two threads increment the same counter 2M times each. Four versions: collapsed plain `counter++` in a loop, as written -> passes! (why?) racy the same, with a barrier so each ++ really executes atomic std::atomic fetch_add(relaxed) mutex std::mutex around the increment plus the same binary under ThreadSanitizer. The lesson is not "races give wrong answers"; it is that a race is undefined behaviour that may give the RIGHT answer for reasons that will change with the next compiler flag, and that a tool sees what tests cannot.

evidence to leave with

collapsed: one add per thread, 'passes'; racy: 2.0M of 4.0M; TSan flags both; atomic 39 ns, mutex 107 ns

first, get the code

run this

$ git clone https://github.com/adit4443ya/debug_labs.git && cd debug_labs

then build it

run this

$ cd concurrency && ./build.sh

produces bin/01_race_tsan (-O2), bin/01_race_tsan.tsan (-O1 -fsanitize=thread)

walk it, one step at a time

run this

$ for i in 1 2 3; do ./bin/01_race_tsan collapsed; done

what it printed on the machine that wrote this lab

collapsed expected 4000000 got 4000000 OK  (0.3 ms, 0.1 ns/increment)
collapsed expected 4000000 got 4000000 OK  (0.3 ms, 0.1 ns/increment)
collapsed expected 4000000 got 4000000 OK  (0.3 ms, 0.1 ns/increment)

run this

$ for i in 1 2 3; do ./bin/01_race_tsan racy; done

what it printed on the machine that wrote this lab

racy      expected 4000000 got 2043416 WRONG  (8.9 ms, 2.2 ns/increment)
racy      expected 4000000 got 2031633 WRONG  (4.1 ms, 1.0 ns/increment)
racy      expected 4000000 got 2097535 WRONG  (13.1 ms, 3.3 ns/increment)

run this

$ ./bin/01_race_tsan atomic ; ./bin/01_race_tsan mutex

what it printed on the machine that wrote this lab

atomic    expected 4000000 got 4000000 OK  (154.8 ms, 38.7 ns/increment)
mutex     expected 4000000 got 4000000 OK  (427.9 ms, 107.0 ns/increment)

run this

$ objdump -d --no-show-raw-insn bin/01_race_tsan | sed -n '/<_ZL14racy_collapsedv>:/,/ret/p'

what it printed on the machine that wrote this lab

0000000000400840 <_ZL14racy_collapsedv>:
  400840:  addq   $0x1e8480,0x283d(%rip)        # 403088 <_ZL13plain_counter>
  40084b:  ret

The optimizer turned two million increments into ONE add of 2,000,000 (0x1e8480). Each thread performs a single read-modify-write; the window for the two to interleave is a few nanoseconds, so they almost never collide and the answer comes out right. It is still a data race, still undefined behaviour, and -O0 or a slightly different loop body brings the wrong answers back. Passing tests prove nothing about races.

survive). Each thread does load-add-store; when both load the same value, one store overwrites the other. Note it is not "slightly off": about half is lost, because the two threads run in lockstep on the same line. And it took 1-3 ns per increment, faster than the correct versions: wrong answers are cheap.

run this

$ ./bin/01_race_tsan.tsan racy

what it printed on the machine that wrote this lab

  WARNING: ThreadSanitizer: data race (pid=56417)
    Write of size 8 at 0x000001899760 by thread T2:
      #0 racy() .../concurrency/01_race_tsan.cpp:12:72
    Previous write of size 8 at 0x000001899760 by thread T1:
      #0 racy() .../concurrency/01_race_tsan.cpp:12:72
  SUMMARY: ThreadSanitizer: data race .../01_race_tsan.cpp:12:72 in racy()
  racy      expected 4000000 got 2089718 WRONG  (183.8 ms, 45.9 ns/increment)

run this

$ ./bin/01_race_tsan.tsan collapsed

what it printed on the machine that wrote this lab

  WARNING: ThreadSanitizer: data race (pid=56425)
      #0 racy_collapsed() .../01_race_tsan.cpp:11:78

run this

$ ./bin/01_race_tsan.tsan atomic   -> 0 warnings
$ ./bin/01_race_tsan.tsan mutex    -> 0 warnings

what it printed on the machine that wrote this lab

  Read it: TSan reports the two conflicting accesses with their stacks,
  INCLUDING for the collapsed version whose output was correct. It does
  not need the race to misbehave: it tracks happens-before relations
  (via locks and atomics) and flags any pair of unordered conflicting
  accesses. Cost: ~5-15x slower, 5-10x memory; run your test suite under
  it regularly, not in production.

THE COSTS (this machine, two threads on two P-cores):
  atomic relaxed fetch_add   38.7 ns/increment   the line ping-pongs between cores (cache lab 04)
  std::mutex lock/unlock    107.0 ns/increment   two atomics plus, under contention, futex sleeps (lab 04 here)

Both are "correct"; both are slow because they SHARE. The fast fix is per-thread counters combined at the end: no sharing on the hot path.

the rules

R1. Any two unsynchronized accesses to the same location, at least one a write, from two threads = data race = UB. Not "a stale read". R2. Tests cannot find races; TSan can. Build with -fsanitize=thread in CI for every multi-threaded target. R3. The correct fix is usually to not share (partition, message-pass), then atomics, then locks. Measure the contention (lab 04).

take it further

1. Build `collapsed` at -O0 and run it three times: wrong answers appear. 2. Make the counter `volatile`: still a race (TSan still fires), still wrong. volatile is not a synchronization primitive. 3. Give each thread its own counter (padded, cache lab 04) and sum at the end: correct, and ~1 ns per increment. ============================================================

read the source · concurrency/01_race_tsan.cpp

#include "../tools/bench.h"
#include <atomic>
#include <mutex>
#include <thread>
#include <cstring>
static const long ITERS = 2000000;
static long plain_counter = 0;                       // the racy one
static std::atomic<long> atomic_counter{0};
static long mutex_counter = 0; static std::mutex mu;
static void racy_collapsed() { for (long i = 0; i < ITERS; i++) plain_counter++; }   /* clang folds this into ONE add */
static void racy()   { for (long i = 0; i < ITERS; i++) { plain_counter++; __asm__ volatile("" ::: "memory"); } }   /* a real load-add-store per iteration */
static void atomic_() { for (long i = 0; i < ITERS; i++) atomic_counter.fetch_add(1, std::memory_order_relaxed); }
static void locked() { for (long i = 0; i < ITERS; i++) { std::lock_guard<std::mutex> g(mu); mutex_counter++; } }
int main(int argc, char **argv) {
    const char *mode = argc > 1 ? argv[1] : "racy";
    void (*fn)() = !strcmp(mode, "atomic") ? atomic_ : !strcmp(mode, "mutex") ? locked : !strcmp(mode, "collapsed") ? racy_collapsed : racy;
    uint64_t t0 = bench_ns();
    std::thread a(fn), b(fn); a.join(); b.join();
    double ms = (bench_ns() - t0) / 1e6;
    long got = !strcmp(mode, "atomic") ? atomic_counter.load() : !strcmp(mode, "mutex") ? mutex_counter : plain_counter;
    printf("%-9s expected %ld got %ld %s  (%.1f ms, %.1f ns/increment)\n", mode, 2 * ITERS, got, got == 2 * ITERS ? "OK" : "WRONG", ms, ms * 1e6 / (2.0 * ITERS));
    return 0;
}

◇

Finish the lab: write the evidence note

A lab is done when you can say what it showed on your machine — not when you have read it.