Skip to content

add cmd/binlog-visibility-repro: stand-alone MySQL contract repro#820

Merged
morgo merged 12 commits into
block:mainfrom
morgo:stress-test-binlog-visibility
May 3, 2026
Merged

add cmd/binlog-visibility-repro: stand-alone MySQL contract repro#820
morgo merged 12 commits into
block:mainfrom
morgo:stress-test-binlog-visibility

Conversation

@morgo
Copy link
Copy Markdown
Collaborator

@morgo morgo commented May 3, 2026

Summary

Adds cmd/binlog-visibility-repro, a stand-alone reproducer for what looks like an upstream MySQL contract violation:

with binlog_order_commits=ON, every row event the binlog streamer observes for a committed transaction must already be visible to a fresh autocommit SELECT on a separate connection.

The tool is a single main.go that uses only database/sql + go-mysql-org/go-mysql/replication. No spirit components. That's the point — when this fails, it can't be attributed to anything in pkg/repl, the delta map, the chunker, the applier, or any other spirit wrapper. The failure attributes to MySQL itself.

This is the smoking gun behind the second bug in #746: spirit's deltaMap.Flush periodically sees affected_rows < num_keys from REPLACE INTO _new ... SELECT FROM original WHERE id IN (...), meaning a key was in the delta map (so the binlog streamer had already delivered an event for it) but the row wasn't visible to a separate-connection SELECT moments later.

How it works

  1. Connects to MySQL and creates a small InnoDB table.
  2. Spawns N producer goroutines, each looping BEGIN; INSERT; UPDATE; COMMIT; on the table.
  3. Opens a binlog replication connection. For every WriteRowsEvent on the test table, immediately runs SELECT id FROM <table> WHERE id = ? on a separate connection.
  4. On the first miss, sleeps -recheck-delay (default 100 ms), re-runs the SELECT, and classifies the miss as either permanent (still not visible) or delayed (now visible). Both are violations of the contract; "delayed" is the soft form, "permanent" the hard form.
  5. Prints a summary and exits — 1 if a miss was seen, 0 if -max-duration elapses cleanly, 2 for an infrastructure problem.

Bisect — what triggers the race

Local Docker MySQL 8.0.45 (no -race), short runs (~16 k commits / 5 s):

Producer shape Result
autocommit INSERT … VALUES (…) does NOT reproduce
BEGIN; INSERT; COMMIT; (explicit txn, single stmt) does NOT reproduce
BEGIN; INSERT; UPDATE; COMMIT; reproduces (probabilistic)

The minimum producer shape that surfaces the race is a multi-statement transaction that INSERTs and then UPDATEs the same row before COMMIT. Single-statement transactions, with or without explicit BEGIN/COMMIT, do not reproduce in the same time budget.

How to run it

A repro service has been added to compose/compose.yml and compose/replication-tls/replication-ci.yml. It builds the binary and runs it against the local mysql service. The exact same docker compose commands the existing matrix uses, just targeting mysql repro instead of mysql test:

# MySQL 8.0.28 (Aurora)
cd compose && docker compose -f compose.yml -f 8.0.28.yml up --build mysql repro --abort-on-container-exit --exit-code-from repro

# MySQL 8.0.43 (Oracle Linux 9 base — same userspace as the default tag)
cd compose && docker compose -f compose.yml -f 8.0.43.yml up --build mysql repro --abort-on-container-exit --exit-code-from repro

# MySQL 8.0.43 (Debian base — same MySQL version, different container userspace,
# linux/amd64 only so on Apple Silicon Docker emulates via Rosetta)
cd compose && docker compose -f compose.yml -f 8.0.43-debian.yml up --build mysql repro --abort-on-container-exit --exit-code-from repro

# MySQL 8.0.45 (default)
cd compose && docker compose up --build mysql repro --abort-on-container-exit --exit-code-from repro

# MySQL 8.0.45 RBR-minimal
cd compose && docker compose -f compose.yml -f 8.0.45-rbr-minimal.yml up --build mysql repro --abort-on-container-exit --exit-code-from repro

# MySQL 8.0.42 (Aurora LTS)
cd compose/replication-tls && docker compose -f replication-ci.yml -f 8.0.42.yml up --build mysql repro --abort-on-container-exit --exit-code-from repro

# MySQL 8.4 GA
cd compose/replication-tls && docker compose -f replication-ci.yml -f 8.4.yml up --build mysql repro --abort-on-container-exit --exit-code-from repro

# MySQL 9.7
cd compose/replication-tls && docker compose -f replication-ci.yml -f 9.7.yml up --build mysql repro --abort-on-container-exit --exit-code-from repro

--exit-code-from repro propagates the binary's exit code to the shell, so a failure shows up as exit 1.

For a faster iteration loop (shorter max-duration, more producers, etc.), run the binary directly:

cd compose && docker compose run --rm --build --entrypoint "" repro \
  bash -c "go build -o /tmp/repro ./cmd/binlog-visibility-repro && \
           /tmp/repro -dsn 'tsandbox:msandbox@tcp(mysql:3306)/' \
                      -max-duration 1m -producers 16"

Flags:

flag default meaning
-dsn tsandbox:msandbox@tcp(127.0.0.1:8033)/ MySQL DSN; the program creates and drops its own database
-max-duration 5m give up if no miss is seen within this long
-recheck-delay 100ms how long to wait before re-checking a missed row's visibility
-producers 8 concurrent producer goroutines

Findings so far

  • Every MySQL version we test reproduces at least once across short runs: 8.0.28, 8.0.42, 8.0.43, 8.0.45, 8.0.45-rbr-min, 9.7. 8.4 GA hasn't reproduced in our limited samples but we don't have enough data to call it clean.
  • Container userspace doesn't matter: mysql:8.0.43 (Oracle Linux 9 base) and mysql:8.0.43-debian (Debian base) both reproduce on the same host, with the same MySQL version. Same kernel, different userspace — same bug.
  • Architecture doesn't matter: arm64 native, amd64 native (CI), and amd64 emulated via Rosetta (Apple Silicon running the Debian variant) all reproduce.
  • The bug only surfaces on Linux: native macOS MySQL 8.0.43 directly on Apple Silicon (no Docker) does NOT reproduce in short runs, while the same MySQL 8.0.43 inside Docker (which is just a Linux VM on the same host) reproduces in seconds. The most parsimonious explanation is that the race window is much narrower on Darwin's scheduler / pthread / fsync stack than on Linux's — but the bug almost certainly exists on Darwin too, just at a much lower rate.
  • Almost every miss is "delayed": the row becomes visible to a fresh SELECT within 100 ms of the binlog event being observed. Only one permanent miss has been seen so far (MySQL 8.0.28).
  • The race is sensitive to load: it surfaces in ~1 in 2 k–150 k commits depending on the host. Docker on small CI runners reproduces faster than a beefy local machine.

Why this isn't in CI

The matrix workflow that ran this on every push is intentionally not included. The test is designed to fail under the bug we're hunting; gating PRs on that would be silly. The repro lives as a stand-alone artefact: anyone can run it on demand against any MySQL with the commands above.

Related

🤖 Generated with Claude Code

morgo and others added 8 commits May 3, 2026 10:29
Probe whether MySQL honours the binlog_order_commits=ON contract under
concurrent commit load: every row event the binlog streamer observes
should already be visible to a fresh autocommit SELECT on a separate
connection.

Producers loop BEGIN/INSERT/UPDATE/COMMIT on a fresh table; a streamer
goroutine reads WriteRowsEvents directly via go-mysql-org/go-mysql and,
for each new PK, runs a SELECT on a distinct connection pool. Failures
are logged with binlog_pos, retry-after-50ms outcome, and a producer
cross-check.

The package deliberately uses no spirit/pkg/repl machinery, so any
failure attributes to MySQL (or to the test producer) rather than to
spirit's wrappers. Picked up automatically by every existing CI matrix
lane via go test ./...; tunable via SPIRIT_VISIBILITY_STRESS_DURATION,
_PRODUCERS, and _VERBOSE env vars.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Replace the 3-case event-type switch with an if so the exhaustive linter
doesn't demand cases for every replication.EventType constant.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Increase stress duration so the lower-load lanes (8.4 GA via the
replication-tls compose, 8.0.45-with-replicas) get enough commits to
surface the binlog_order_commits=ON visibility race that the 5s run
already reproduced on 8.0.28 / 8.0.42 / 8.0.45-rbr-min / 9.7.

This branch is not merging — it exists purely to gather repro data.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Strips the visibility-stress test down to a single main.go that uses
only database/sql + go-mysql-org/go-mysql/replication. No spirit
dependencies, no testing framework — suitable for attaching to an
upstream MySQL bug report.

Bisect on Docker MySQL 8.0.45 (no -race, ~16k commits/5s):
  - autocommit INSERT only:        5/5 PASS
  - BEGIN; INSERT; COMMIT:         5/5 PASS
  - BEGIN; INSERT; UPDATE; COMMIT: ~2/3 FAIL  (kept as the minimum)

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Two changes that turn the artifact into something committable:

1. Drop pkg/replstress/visibility_stress_test.go. The test-form would
   fail in CI (which is the entire point of the probe), so it can't
   live in the test matrix. The standalone CLI is the durable form.

2. Switch the CLI from "run for a fixed duration, count misses" to
   "run until the first miss, re-check after 100ms, exit". This is
   how a reproducer wants to behave: it terminates as soon as it has
   evidence, with a clear exit code (1 = miss seen, 0 = clean within
   the budget, 2 = infrastructure issue).

   New flags: -max-duration (cap, default 5m) and -recheck-delay
   (default 100ms). The 100ms recheck classifies the miss as delayed
   (visible after the wait) or permanent (still not visible), which
   together capture the soft and hard forms of the same contract
   violation.

Also clears the lint suite (errcheck / noctx / exitAfterDefer).

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Adds a new GitHub Actions workflow that runs cmd/binlog-visibility-repro
against every MySQL version in the existing test matrix:

  - 8.0.28 (Aurora), 8.0.42 (Aurora LTS), 8.0.45 (default),
    8.0.45 RBR-minimal, 8.4 GA, 9.7

Each lane brings up that lane's MySQL container and runs the repro
binary until either the first miss is detected (lane fails, exit 1) or
-max-duration elapses (lane passes, exit 0). The lane outcomes are
independent (fail-fast: false) so a single failure doesn't mask the
behaviour on the other versions.

Triggered via workflow_dispatch and on push to this branch only — never
on pull_request, since the workflow is intentionally flaky-by-design
(reproducing a contract violation is the whole point) and would
otherwise gate unrelated PRs.

Implementation: a `repro` service is added to compose/compose.yml and
compose/replication-tls/replication-ci.yml that builds the binary and
runs it against the local mysql service. The workflow just brings up
`mysql repro` per lane with `--exit-code-from repro` so the repro's
exit code propagates to the workflow step.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
- Workflow name now "Binlog visibility stress /w docker-compose" so it
  reads alongside the existing "MySQL X.Y /w docker-compose" workflows.
- Matrix lane names prefixed with "Binlog visibility stress /" so the
  six lanes sort together in the GH check list and identify themselves
  immediately.
- Triggers match every other matrix workflow: push to main and
  pull_request to main.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
We've already proven the contract violation reproduces on every MySQL
version we test; pinning a CI workflow on it adds noise without new
information. The reproducer lives as a stand-alone artefact in
cmd/binlog-visibility-repro, runnable on demand against any MySQL via
the docker-compose `repro` service. Anyone can run it locally with the
commands documented in the PR description.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
@morgo morgo changed the title test: add binlog visibility stress test add cmd/binlog-visibility-repro: stand-alone MySQL contract repro May 3, 2026
@morgo morgo marked this pull request as ready for review May 3, 2026 17:48
@morgo morgo enabled auto-merge May 3, 2026 18:24
Two new docker-compose overlays for binlog-visibility-repro testing:

- 8.0.43.yml         — mysql:8.0.43 (the OS contributor's local
                       version), Oracle Linux 9 base. Same userspace
                       layer as the default tag.
- 8.0.43-debian.yml  — mysql:8.0.43-debian (linux/amd64 only). Same
                       MySQL binary version, different container
                       userspace. On Apple Silicon Docker emulates
                       via Rosetta — useful as both an "OS variation"
                       and "amd64 emulation" data point.

Both reproduce the binlog_order_commits=ON visibility race in seconds
on Apple Silicon. Combined with the existing matrix data, this rules
out version-specificity AND container-userspace-specificity as the
cause: the only constant across reproducing cases is "running on a
Linux kernel."

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
@morgo morgo merged commit 234ea4d into block:main May 3, 2026
12 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants