Bug: a crash after a CHECKPOINT with a reader open can lose commits or block reopening #1304

Activity

1. zahariash commented on Oct 23, 2026

   

   zahariash

   on Oct 23, 2026

   ContributorAuthor

   More actions

   The third case does more than replay the prefix twice: it loses committed transactions. Recovery replays the WAL up to the first CHECKPOINT record and truncates it there, so every transaction committed after the pinned checkpoint is dropped, and the open succeeds without an error. On main 319bb92 this script loses a committed DELETE and a committed 149,999-row SET in 5 of 5 runs; v0.21.2 keeps both:

   import os
   import signal
   import subprocess
   import sys
   import tempfile
   
   import ladybug as lb
   
   CHILD = """
   import sys
   import ladybug as lb
   db = lb.Database(sys.argv[1], checkpoint_threshold=-1)
   w, r = lb.Connection(db), lb.Connection(db)
   w.execute("CREATE NODE TABLE T(id INT64 PRIMARY KEY, v INT64)")
   w.execute("UNWIND range(1, 300000) AS i CREATE (:T {id: i, v: 0})")
   w.execute("CHECKPOINT")
   r.execute("BEGIN TRANSACTION READ ONLY")
   r.execute("MATCH (t:T) RETURN count(*)")
   w.execute("MATCH (t:T {id: 1}) SET t.v = 7")
   w.execute("CHECKPOINT")  # runs with the reader open
   r.execute("COMMIT")
   w.execute("MATCH (t:T {id: 2}) DELETE t")
   w.execute("MATCH (t:T) WHERE t.id % 2 = 0 SET t.v = 1")
   print("committed", flush=True)
   w.execute("CHECKPOINT")
   """
   
   lost = 0
   for _ in range(5):
       path = os.path.join(tempfile.mkdtemp(), "db")
       child = subprocess.Popen([sys.executable, "-c", CHILD, path], stdout=subprocess.PIPE, text=True)
       child.stdout.readline()
       while not os.path.exists(path + ".shadow"):  # the last checkpoint has started
           pass
       os.kill(child.pid, signal.SIGKILL)  # crash
       child.wait()
       conn = lb.Connection(lb.Database(path))
       rows, has_2, updated = conn.execute(
           "MATCH (t:T) RETURN count(*), count(CASE WHEN t.id = 2 THEN 1 END), count(CASE WHEN t.v = 1 THEN 1 END)"
       ).get_all()[0]
       print(f"rows: {rows}, id 2 present: {bool(has_2)}, rows with v = 1: {updated}")
       lost += rows != 299999 or has_2 or updated != 149999
   print(f"{lost} of 5 reopened databases lost committed transactions")

   Expected (v0.21.2), five times: rows: 299999, id 2 present: False, rows with v = 1: 149999. Actual on main, five times: rows: 300000, id 2 present: True, rows with v = 1: 0.

   A kill in that window leaves db.pinned.tmp, a partial db.shadow, and a WAL whose last records are commits after the pinned CHECKPOINT record; a kill after the new checkpoint writes its own CHECKPOINT record recovers correctly. With DDL in the WAL before the pinned record, the same kill makes every later open fail with Catalog exception: T already exists in catalog. instead. Our workload simulator found the loss as committed rel deletes that came back after a crash during an auto-checkpoint.

   Pinned checkpoints came after v0.21.2, so this would ship in 0.22.
2. zahariash

   changed the title [-]Bug: a crash after a CHECKPOINT that ran with a read-only transaction open can leave the database unopenable[/-] [+]Bug: a crash after a CHECKPOINT with a reader open can lose commits or block reopening[/+] on Oct 23, 2026
3. zahariash commented on Oct 24, 2026

   

   zahariash

   on Oct 24, 2026

   ContributorAuthor

   More actions

   A crash isn't needed. When the checkpoints after a pinned one fail, for example on a full disk, and the database is then closed normally, the reopen applies the same rule: it replays the WAL up to the first CHECKPOINT record and truncates it there. Every transaction committed after the pinned checkpoint is gone, and the one the pinned checkpoint already holds is replayed on top of it, so it comes back twice. On main c81ec66 this script keeps 2 of 100 rows in 3 of 3 runs:

   import os
   import resource
   import signal
   import sys
   import tempfile
   
   import ladybug as lb
   
   reader_open = "--no-reader" not in sys.argv
   signal.signal(signal.SIGXFSZ, signal.SIG_IGN)
   path = os.path.join(tempfile.mkdtemp(), "db")
   db = lb.Database(path, checkpoint_threshold=0)  # a checkpoint after every commit
   w, r = lb.Connection(db), lb.Connection(db)
   w.execute("CREATE NODE TABLE P(id INT64 PRIMARY KEY)")
   w.execute("CREATE REL TABLE K(FROM P TO P, n INT64)")
   w.execute("CREATE (:P {id: 1}), (:P {id: 2})")
   if reader_open:
       r.execute("BEGIN TRANSACTION READ ONLY")  # every checkpoint from here on is pinned
       r.execute("MATCH ()-[k:K]->() RETURN count(*)")
   add = "MATCH (a:P {id: 1}), (b:P {id: 2}) CREATE (a)-[:K {n: $n}]->(b)"
   w.execute(add, {"n": 0})
   soft, hard = resource.getrlimit(resource.RLIMIT_FSIZE)
   resource.setrlimit(resource.RLIMIT_FSIZE, (os.path.getsize(path) + 128 * 1024, hard))  # the disk fills up
   for n in range(1, 100):
       try:
           w.execute(add, {"n": n})
       except RuntimeError:
           pass  # before #1361: "Transaction committed successfully, but the post-commit checkpoint failed ..."
   r.close()
   w.close()
   db.close()  # its checkpoint fails too
   resource.setrlimit(resource.RLIMIT_FSIZE, (soft, hard))  # space is freed
   
   conn = lb.Connection(lb.Database(path))
   rows, distinct = conn.execute("MATCH ()-[k:K]->() RETURN count(*), count(DISTINCT k.n)").get_all()[0]
   print(f"rows: {rows}, distinct n: {distinct}")

   Expected (v0.21.2, or with --no-reader): rows: 100, distinct n: 100. Actual on main: rows: 2, distinct n: 1, that is n = 0 twice and n = 1 to 99 lost.

   The file-size limit stands in for the full disk: from the moment it is set, data-file writes fail with File too large, so every checkpoint after it fails, including the one close() runs; the WAL writes still fit. Before #1361 each of those 99 commits raised Transaction committed successfully, but the post-commit checkpoint failed. The committed data is durable and will be recovered on restart, so each lost commit had been reported durable. A stress loop for #1361 found it as committed writes missing after a clean close while checkpoints kept failing; it loses them at the same rate with and without #1361.
4. zahariash commented on Oct 24, 2026

   

   zahariash

   on Oct 24, 2026

   ContributorAuthor

   More actions

   working on it
5. zahariash commented on Oct 24, 2026

   

   zahariash

   on Oct 24, 2026

   ContributorAuthor

   More actions

   Two more crash points block reopening, both inside the cleanup of the pinned checkpoint itself, after it has logged its CHECKPOINT record and applied its shadow pages. Both are deterministic with strace fault injection, on main 7bcc47d:

   Crash at	Left on disk	Reopen
   unlink of db.shadow, which ShadowFile::clear has just truncated	db.wal ending in the CHECKPOINT record, an empty db.shadow	Cannot replay shadow file db.shadow: file is too small.
   opening db.pinned.tmp, after the shadow is gone	db.wal ending in the CHECKPOINT record, no shadow, no marker	Cannot recover checkpoint WAL db.wal: shadow file db.shadow is missing with no pinned-checkpoint marker. ...

   Without the reader, both crash points reopen with every row: the WAL is retired before the shadow is removed, so a leftover empty shadow is ignored. On v0.21.2, a crash at the same unlink fails for every checkpoint, reader or not (Database ID for temporary file 'db.shadow' does not match the current database); main fixed that for unpinned checkpoints only.

   For a pinned checkpoint, postCheckpointCleanup keeps the WAL, clears the shadow and then writes the marker (checkpointer.cpp#L438-L484). ShadowFile::clear truncates the file before it unlinks it (shadow_file.cpp#L422-L424). When the last WAL record is a CHECKPOINT, recovery replays any shadow it finds and needs the marker when there is none (wal_replayer.cpp#L730-L737).

   Writing the marker before removing the shadow closes the second window. The first needs the shadow unlinked before it is truncated, or recovery to treat an empty shadow as absent: a checkpoint logs its CHECKPOINT record only after its shadow, header included, is synced.

   import os, subprocess, sys, tempfile
   import ladybug as lb
   
   CHILD = """
   import sys
   import ladybug as lb
   db = lb.Database(sys.argv[1], checkpoint_threshold=-1)
   w, r = lb.Connection(db), lb.Connection(db)
   w.execute("CREATE NODE TABLE P(id INT64 PRIMARY KEY)")
   w.execute("UNWIND range(1, 1000) AS i CREATE (:P {id: i})")
   r.execute("BEGIN TRANSACTION READ ONLY")
   w.execute("CHECKPOINT")
   """
   target, syscall = (".pinned.tmp", "openat") if sys.argv[1:] == ["marker"] else (".shadow", "unlink")
   path = os.path.join(tempfile.mkdtemp(), "db")
   # SIGKILL the child at its first unlink of db.shadow (already truncated) or open of db.pinned.tmp
   subprocess.run(["strace", "-f", "-qq", "-o", os.devnull, "-P", path + target, "-e", f"trace={syscall}",
                   "-e", f"inject={syscall}:signal=KILL", sys.executable, "-c", CHILD, path])
   try:
       conn = lb.Connection(lb.Database(path))
       print("reopened,", conn.execute("MATCH (p:P) RETURN count(p)").get_all()[0][0], "rows")
   except RuntimeError as e:
       print(e)

   python repro.py crashes at the unlink, python repro.py marker before the marker. Expected: reopened, 1000 rows.