"""DRBD 同步停滞的自动恢复（在每个 LINSTOR 节点上常驻运行，只看本节点）。
只处理本节点是同步目标、且本地数据未完成同步（Inconsistent / Outdated）的连接：
- F8（DRBD 9.3.4，results.md §11.6）：同步源失去无盘主节点后，目标以 unsecured-resync 结束同步，
源端的 resync-again 位图被丢弃，双方停在 WFBitMapS / WFBitMapT 互相等待，不会自行恢复
- §9.3：SyncTarget 的剩余量长时间不变
- 本地 Inconsistent、连接正常、对端 UpToDate，却停在 Established 不开始同步（F8 的另一种结局：
同步以 unsecured-resync 结束后没有新的位图交换，直到主节点降级或重连才会恢复）
处理方法是在本节点断开并重连该连接（drbdadm disconnect <资源>:<对端>; drbdadm adjust <资源>）。
本地数据未完成同步，重连不会用它覆盖任何一方；本地已是 UpToDate 时绝不重连（两端 UpToDate 时重连不能用来修复，§11 F4）。
运行：python3 -m linstor_ops.autoheal [--dry-run] [--once]
指标（node_exporter textfile）：cinder_gen_drbd_autoheal_total / _giveup_total / _stuck_seconds
"""
import argparse
import json
import os
import subprocess
import sys
import time
WFBITMAP_STATES = ("WFBitMapT", "WFSyncUUID", "StartingSyncT")
SYNC_STATES = ("SyncTarget",)
NOT_SYNCED = ("Inconsistent", "Outdated")
TEXTFILE = "/var/lib/prometheus/node-exporter/cinder_gen_drbd_autoheal.prom"
def log(msg):
sys.stdout.write("%s\n" % msg)
sys.stdout.flush()
def run(cmd, timeout=60):
p = subprocess.run(cmd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, timeout=timeout,
stdin=subprocess.DEVNULL)
return p.returncode, p.stdout.decode(errors="replace")
def read_status(runner=run):
rc, out = runner("drbdsetup status --json --statistics")
if rc != 0:
raise RuntimeError("drbdsetup status failed: %s" % out[-200:])
return json.loads(out or "[]")
def candidates(status):
"""返回 {(资源, 对端): (原因, 剩余 KiB)}：本节点是未完成同步的目标、连接正常、对端 UpToDate"""
found = {}
for r in status:
disks = {d.get("volume", 0): d.get("disk-state") for d in r.get("devices", [])}
for c in r.get("connections", []):
if c.get("connection-state") != "Connected":
continue
for pd in c.get("peer_devices", []):
if disks.get(pd.get("volume", 0)) not in NOT_SYNCED or pd.get("peer-disk-state") != "UpToDate":
continue
repl = pd.get("replication-state", "")
key = (r["name"], c["name"])
if repl in WFBITMAP_STATES:
found[key] = ("wfbitmap", pd.get("out-of-sync") or 0)
elif repl in SYNC_STATES and pd.get("resync-suspended", "no") in ("no", False):
found[key] = ("resync-stalled", pd.get("out-of-sync") or 0)
elif repl == "Established" and disks.get(pd.get("volume", 0)) == "Inconsistent":
found[key] = ("idle-inconsistent", pd.get("out-of-sync") or 0)
return found
class Healer(object):
def __init__(self, runner=run, clock=time.time, wfbitmap_after=60, stalled_after=600, idle_after=120,
max_per_hour=3, dry_run=False, textfile=TEXTFILE):
self.runner, self.clock = runner, clock
self.wfbitmap_after, self.stalled_after, self.idle_after = wfbitmap_after, stalled_after, idle_after
self.max_per_hour, self.dry_run, self.textfile = max_per_hour, dry_run, textfile
self.seen = {} # key -> (原因, 首次看到的时间, 上次剩余量, 剩余量上次变化的时间)
self.history = {} # key -> [重连时间]
self.total = {} # (key, 原因) -> 次数
self.giveup = {} # key -> 次数
self.giveup_logged = {}
def tick(self):
now = self.clock()
found = candidates(read_status(self.runner))
for key in list(self.seen):
if key not in found:
reason, since, _, _ = self.seen.pop(key)
log("%s:%s 已恢复（%s，持续 %ds）" % (key[0], key[1], reason, now - since))
actions = []
for key, (reason, oos) in found.items():
prev = self.seen.get(key)
if prev is None or prev[0] != reason:
self.seen[key] = (reason, now, oos, now)
continue
_, since, last_oos, changed = prev
if oos != last_oos:
self.seen[key] = (reason, since, oos, now)
continue
waited = now - (changed if reason == "resync-stalled" else since)
limit = {"wfbitmap": self.wfbitmap_after, "idle-inconsistent": self.idle_after}.get(reason, self.stalled_after)
if waited >= limit:
actions.append((key, reason, waited))
for key, reason, waited in actions:
self.heal(key, reason, waited, now)
self.write_metrics(now)
return actions
def heal(self, key, reason, waited, now):
res, peer = key
recent = [t for t in self.history.get(key, []) if now - t < 3600]
if len(recent) >= self.max_per_hour:
self.giveup[key] = self.giveup.get(key, 0) + 1
if now - self.giveup_logged.get(key, 0) >= 3600:
self.giveup_logged[key] = now
log("%s:%s %s 已持续 %ds，但 1 小时内已重连 %d 次，不再自动处理（需人工，runbook §8「副本一致性」）"
% (res, peer, reason, waited, len(recent)))
self.seen[key] = (reason, now, None, now)
return
# 执行前再确认一次：本地仍未完成同步、状态没变
again = candidates(read_status(self.runner)).get(key)
if again is None or again[0] != reason:
log("%s:%s 状态已变化，不处理" % (res, peer))
return
log("%s:%s %s 已持续 %ds（剩余 %s KiB），在本节点断开重连%s"
% (res, peer, reason, waited, again[1], "（dry-run）" if self.dry_run else ""))
if not self.dry_run:
rc, out = self.runner("drbdadm disconnect %s:%s; sleep 2; drbdadm adjust %s" % (res, peer, res))
if rc != 0:
log(" 重连命令返回 %d：%s" % (rc, out.strip()[-300:]))
recent.append(now)
self.history[key] = recent
self.total[(key, reason)] = self.total.get((key, reason), 0) + 1
self.seen.pop(key, None)
def write_metrics(self, now):
if not self.textfile:
return
lines = ["# HELP cinder_gen_drbd_autoheal_total Reconnects done by cinder-gen DRBD autoheal.",
"# TYPE cinder_gen_drbd_autoheal_total counter"]
for ((res, peer), reason), n in sorted(self.total.items()):
lines.append('cinder_gen_drbd_autoheal_total{name="%s",conn_name="%s",reason="%s"} %d' % (res, peer, reason, n))
lines += ["# HELP cinder_gen_drbd_autoheal_giveup_total Stalls left alone because the hourly limit was reached.",
"# TYPE cinder_gen_drbd_autoheal_giveup_total counter"]
for (res, peer), n in sorted(self.giveup.items()):
lines.append('cinder_gen_drbd_autoheal_giveup_total{name="%s",conn_name="%s"} %d' % (res, peer, n))
lines += ["# HELP cinder_gen_drbd_autoheal_stuck_seconds How long a sync target has been waiting.",
"# TYPE cinder_gen_drbd_autoheal_stuck_seconds gauge"]
for (res, peer), (reason, since, _, _) in sorted(self.seen.items()):
lines.append('cinder_gen_drbd_autoheal_stuck_seconds{name="%s",conn_name="%s",reason="%s"} %d'
% (res, peer, reason, now - since))
lines += ["# HELP cinder_gen_drbd_autoheal_last_run_timestamp_seconds Last successful check.",
"# TYPE cinder_gen_drbd_autoheal_last_run_timestamp_seconds gauge",
"cinder_gen_drbd_autoheal_last_run_timestamp_seconds %d" % now]
tmp = self.textfile + ".tmp"
try:
with open(tmp, "w") as f:
f.write("\n".join(lines) + "\n")
os.rename(tmp, self.textfile)
except OSError as e:
log("写指标失败：%s" % e)
def main(argv=None):
ap = argparse.ArgumentParser(description="DRBD 同步停滞自动恢复（本节点）")
ap.add_argument("--interval", type=int, default=10, help="检查间隔（秒）")
ap.add_argument("--wfbitmap-after", type=int, default=60, help="WFBitMapT 等状态持续多少秒后重连")
ap.add_argument("--stalled-after", type=int, default=600, help="SyncTarget 剩余量多少秒不变后重连")
ap.add_argument("--idle-after", type=int, default=120, help="本地 Inconsistent 却停在 Established 多少秒后重连")
ap.add_argument("--max-per-hour", type=int, default=3, help="每个连接每小时最多重连次数")
ap.add_argument("--textfile", default=TEXTFILE, help="node_exporter textfile 路径（空字符串表示不写）")
ap.add_argument("--dry-run", action="store_true", help="只记录，不重连")
ap.add_argument("--once", action="store_true", help="只检查一次")
a = ap.parse_args(argv)
h = Healer(wfbitmap_after=a.wfbitmap_after, stalled_after=a.stalled_after, idle_after=a.idle_after,
max_per_hour=a.max_per_hour,
dry_run=a.dry_run, textfile=a.textfile or None)
log("启动：间隔 %ds，WFBitMap* %ds / Inconsistent 空闲 %ds / SyncTarget 停滞 %ds 后重连，每连接每小时最多 %d 次%s"
% (a.interval, a.wfbitmap_after, a.idle_after, a.stalled_after, a.max_per_hour, "，dry-run" if a.dry_run else ""))
while True:
try:
h.tick()
except Exception as e: # 单次失败（例如 drbdsetup 暂时不可用）不退出
log("检查失败：%s" % e)
if a.once:
return 0
time.sleep(a.interval)
if __name__ == "__main__":
sys.exit(main())
Summary
With DRBD 9.3.4, when a sync source loses its connection to a diskless primary
while a resync to a third node is running, the sync target correctly refuses to
continue ("Can not secure resync request ... against a source that lost the
writer, ending the resync" — the fix for acknowledged writes being overwritten,
from 9.2.20). But right after that the resync does not restart:
resync-again→WFBitMapS)and sends its bitmap;
unsecured-resync→Established) and drops that bitmap (unexpected repl_state (Established) in receive_bitmap);WFBitMapTthroughafter-unstableandboth sides wait for each other's bitmap forever, or the target stays
Established+Inconsistentnext to anUpToDatepeer.No acknowledged data is lost (the target stays Inconsistent), but redundancy is
gone until the connection is cycled by hand. It does not recover when the
primary demotes.
On 9.3.2 the same scenario silently lost acknowledged writes (the target became
UpToDate with stale data), so 9.3.4 is a clear improvement — this report is
about the remaining liveness problem.
Environment
quorum majority,on-no-quorum suspend-io,timeout 10,ping-int 2,c-max-rate 400M,c-min-rate 20M,c-fill-target 1MReproduction
drbdadm disconnect), thendrbdadm adjust→ B becomes SyncTarget from A.resource port, both directions, on both nodes). P keeps quorum via B + tiebreaker logic.
Script:
vrf-t5.sh a N(below). It writes with a small integrity probe (genio.py, below) that records everyacknowledged write and afterwards checks both backing devices for acknowledged writes that were lost.
Result on 9.3.4: resync hung in 5 of 14 rounds (4 × WFBitMapS/WFBitMapT, 1 × Established/Inconsistent).
Log excerpt (round 2 of a run)
Sync target (B):
Sync source (A):
Analysis
The two sides leave the resync on different paths:
drbd_resync_finished()→resync_again()and entersL_WF_BITMAP_S, which immediately sends its bitmap;drbd_resync_request_unreachable()→change_repl_state(L_ESTABLISHED, "unsecured-resync"), which does not runresync_again(), so the target isL_ESTABLISHEDwhen the source's bitmaparrives.
receive_bitmap()merges the bits into the slot but, being neither inL_WF_BITMAP_SnorL_WF_BITMAP_T, neither answers nor starts a resync.The source then waits in
L_WF_BITMAP_Sfor a bitmap that will never be sent.If the target later enters
L_WF_BITMAP_T(after-unstable), it waits for abitmap that has already been consumed.
Proposed fix
In
receive_bitmap(), when a bitmap arrives while we areL_ESTABLISHED, ourdisk still needs a resync (
D_INCONSISTENT/D_OUTDATED, neverD_UP_TO_DATE) and the peer has usable data, join the peer's exchange as synctarget: enter
L_WF_BITMAP_T, send our bitmap, start the resync, and consumethe pending
resync_againthat this exchange serves. Patch below (≈60 lines,drbd_receiver.conly). It applies to current master (574c9ca9e) with an offset; master still hasthe same
receive_bitmap()/unsecured-resynccode.Test results with the patch
Same reproduction, 20 rounds, watchdog in log-only mode:
Regression (patched): network cut between the diskful primary and a secondary (8 rounds), multi-source resync without IO (6) and with IO (3), verify + reconnect after corrupting blocks: all identical to unpatched 9.3.4, no acknowledged write lost. Builds via dkms on 5.4.0-216; compiled against 6.8 headers it adds no warnings.
The patch does not change the wire protocol; a patched node only answers a
bitmap it would otherwise have dropped.
Question: Established + Inconsistent while the primary keeps writing
Even with the patch, the joined resync can again be ended with
"unsecured-resync" (the source still has not reconnected to the writer). The
target then stays Established + Inconsistent until the cluster becomes
"stable" again (after-unstable handshake), which with a long-running diskless
primary (a VM) may be days. The sync source regains UpToDate as soon as it
reconnects to the primary. Is waiting for stability intended here, or should
the resync restart once the source is UpToDate again? We did not try to change
this, since it needs both sides to agree on a new handshake.
Workaround
Cycling the connection on the sync target (
drbdadm disconnect <res>:<source>; drbdadm adjust <res>) is safe because the target is Inconsistent. We run asmall watchdog that does this after 60 s in WFBitMapT or 120 s
Established/Inconsistent (
autoheal.py, below; comments and log messages are in Chinese).Possibly related: #116 (device blocked in WFBitmapS on a bad network), which has no details.
Files
Patch: drbd: join the peer's bitmap exchange when a bitmap arrives while Established
vrf-t5.sh — reproduction (mode a: diskless writer, cut primary ↔ sync source during resync)
genio.py — write-integrity probe (acknowledged-write ledger + per-block generation check)
autoheal.py — watchdog used as workaround (reconnects only an unsynced sync target)