MEASUREMENT

bench/stretched-cache/latency.py

The script that produced the numbers in the article, and the record of the run. The file is read from the repository at build time — this is the code that was run, not a copy of it.

Cited in

/en/system-design/caching/stretched-cache

Run on

Redis 7.0.15, PostgreSQL 16.13, Python 3.11.15, redis-py 8.1.0

How to run it

python3 bench/stretched-cache/replication.py   # блоки 1-3
python3 bench/stretched-cache/cluster.py       # блоки 4-6
python3 bench/stretched-cache/latency.py       # блок 7
python3 bench/stretched-cache/readsdown.py     # блок 8
python3 bench/stretched-cache/offsets.py       # блок 9
python3 bench/stretched-cache/waitcost.py      # блок 10
python3 bench/stretched-cache/relaycheck.py    # блоки 11-14
python3 bench/stretched-cache/versions.py      # блок 15

The run below is recorded in Russian. It is a lab record, kept in the language it was written in; the numbers, the tables and the code read the same either way.

Record of the run

Замеры для статьи «Растянутый кэш на два датацентра»

Скрипт	Что делает
`link.py`	канал между датацентрами: ретранслятор в пользовательском коде, который задерживает байты и умеет обрываться. Два варианта: конвейерный `DelayedLink` и сериализующий `SerializingLink` — разница между ними измерена в блоке 13. Общий модуль, сам ничего не печатает
`replication.py`	мастер в одном ДЦ, реплика в другом: отставание, потеря подтверждённых записей при переключении, цена `WAIT` — блоки 1–3
`cluster.py`	кластер из шести узлов, три раскладки по датацентрам, разрыв канала — блоки 4–6
`latency.py`	кэш в чужом ДЦ против базы в своём — блок 7
`readsdown.py`	что решает `cluster-allow-reads-when-down` — блок 8
`offsets.py`	чем измеряется окно потерь: отставание против круга — блок 9
`waitcost.py`	из чего складывается цена `WAIT`, на трёх расстояниях — блок 10
`relaycheck.py`	проверка самого стенда: во что он обходится при нулевой задержке, сколько раз задержка применяется к операции, сериализующий канал против конвейерного, калибровка — блоки 11–14
`versions.py`	те же утверждения на Redis 7.0.15, Redis 8.10.1 и Valkey 9.1.2 — блок 15

python3 bench/stretched-cache/replication.py   # блоки 1-3
python3 bench/stretched-cache/cluster.py       # блоки 4-6
python3 bench/stretched-cache/latency.py       # блок 7
python3 bench/stretched-cache/readsdown.py     # блок 8
python3 bench/stretched-cache/offsets.py       # блок 9
python3 bench/stretched-cache/waitcost.py      # блок 10
python3 bench/stretched-cache/relaycheck.py    # блоки 11-14
python3 bench/stretched-cache/versions.py      # блок 15

Нужен redis-server в PATH, для кластера ещё и redis-cli, для latency.py — работающий PostgreSQL (DSN в DE_TEST_DATABASE_URL). Другую сборку можно подсунуть через REDIS_SERVER_BIN и REDIS_CLI_BIN; versions.py берёт список из DE_REDIS_BUILDS вида «имя=каталог/bin» через запятую. Узлы поднимаются во временных каталогах на случайных портах и убиваются в finally; после себя скрипты не оставляют ни процессов, ни файлов.

Чем изображается разрыв, и почему двумя разными способами

В replication.py, latency.py, offsets.py, waitcost.py и relaycheck.py — ретранслятором link.py. Он слушает порт, соединяется с настоящим Redis и переносит байты, задерживая каждую порцию на заданное время. tc netem был бы честнее, но в ядре этой среды его попросту нет: CONFIG_NET_SCH_NETEM не собран, и tc qdisc add ... netem отвечает Error: Specified qdisc kind is unknown. Права тут ни при чём.

И у этого ретранслятора нашлось два дефекта — оба измерены и устранены. Первый: на его двух соединениях не был выставлен TCP_NODELAY, и пара «алгоритм Нейгла — отложенное подтверждение» добавляла сорок миллисекунд к каждой операции, где по каналу шло несколько мелких сообщений подряд. Ровно эти сорок миллисекунд первая версия статьи опубликовала как «слагаемое неизвестной природы» в цене WAIT. Второй: задержка ставилась между recv и sendall в одном потоке, поэтому порции шли по очереди, а не параллельно, и операция стоила на один лишний перелёт дороже. Пока первый дефект был на месте, второй был невидим — он вчетверо меньше. Подробности печатает relaycheck.py.

У ретранслятора есть cut(): он закрывает все соединения и перестаёт принимать новые. Это важнее задержки. Разрыв между датацентрами — это не «стало медленно», а «перестало ходить вовсе», и изображать его увеличенной задержкой нельзя: репликация с задержкой в десять секунд всё равно догонит, а оборванная — нет.

В cluster.py — сигналом STOP дальней половине. Здесь ретранслятор не годится: узлы кластера общаются друг с другом по шине напрямую, а не через клиентский порт, и ставить ретранслятор пришлось бы на каждую пару. Процесс, остановленный SIGSTOP, жив и держит порт открытым, но не отвечает и не шлёт heartbeat — для оставшейся половины он неотличим от узла за оборванным каналом. Убить узлы было нельзя: вторую половину надо было опросить тоже, и а каждая половина наблюдается на СВОЁМ свежем кластере с той же, заданной руками топологией. Это исправление: раньше обе половины проверялись по очереди на одном кластере, и повышение реплики в первой проверке могло изменить топологию для второй. Две последовательные проверки — не две стороны одного разрыва.

Что здесь важно прочитать правильно

Абсолютные миллисекунды не переносятся никуда — ни на другую машину, ни на другую версию Redis. Содержательны отношение внутри блока, знак разницы и то, какая половина кластера ответила, а какая нет. Двадцать миллисекунд в одну сторону выбраны не «чтобы было хуже», а как обычное расстояние между датацентрами в пределах одной страны.

Номера портов в блоках 4–6 случайны и в каждом прогоне свои. Читаются не они, а роли узлов и столбец состояния. Именно поэтому в блоке 5 стоит проследить пальцем, чья реплика где: в этом весь результат.

Блоки 5 и 6 различаются одной перестановкой реплики. Деление узлов по датацентрам в них одинаковое; меняется только то, чью реплику оставили дома. Разница в исходе — между «отказали обе половины» и «одна работает».

Замер задержки сравнивает самую дешёвую операцию базы. Пять тысяч строк, всё в памяти, чтение по первичному ключу. Из того, что первые две строки блока 7 почти совпали, не следует, что кэш не нужен, — следует только правило: поход в кэш обязан быть дешевле той операции источника, которую он заменяет, на этом расстоянии. Для дорогого агрегата ответ может быть и другим, и здесь он не мерился.

Опубликованная основа — Redis 7.0.15, но она не единственная проверка. Блок 15 (versions.py) прогоняет те же утверждения на Redis 8.10.1 и Valkey 9.1.2: ни одно не разошлось. Числа блоков 1–10 при этом на новые версии не переносятся и не заменяются ими — вопрос блока 15 другой: не разъехалось ли поведение.

Что получилось (Redis 7.0.15, PostgreSQL 16.13, Python 3.11.15, redis-py 8.1.0)

Мастер и реплика, канал 20 мс в одну сторону:

что	значение
реплика в том же ДЦ: запись видна через	1,1 мс
реплика в другом ДЦ: запись видна через	20,1 мс

В этом опыте при низкой нагрузке дополнительная задержка видимости почти совпала с добавленным перелётом в одну сторону. Совпадение не есть закон: обработка, буферизация и нагрузка добавляют своё.

Переключение на реплику, 200 подтверждённых клиенту записей:

когда оборвали	оказалось на реплике	потеряно
сразу после записи	107	93 (46,5 %)
через секунду после записи	200	0

Обе строки — один и тот же опыт с единственной разницей: успела ли репликация догнать до обрыва. Проценты — не свойство Redis; переносится граница: под угрозой то, что не доехало до реплики. Чем эта граница измеряется, см. ниже — здесь первая версия ошибалась.

Цена WAIT 1:

что	значение
обычная запись	0,24 мс
запись с `WAIT 1`	41,73 мс
во сколько раз дороже	×171,6

Это ровно один круг до реплики — разбор на трёх расстояниях ниже. Купленное свойство в любом случае слабее ожидаемого: WAIT сообщает число подтвердивших реплик, но не отменяет запись, если их меньше.

Кластер из шести узлов, разрыв канала между датацентрами:

раскладка	ДЦ-1	ДЦ-2
A: все мастера в ДЦ-1, все реплики в ДЦ-2	работает	`CLUSTERDOWN`
B: узлы поровну, мастера 2 и 1	`CLUSTERDOWN`	`CLUSTERDOWN`
C: то же деление, реплика чужого мастера дома	работает	`CLUSTERDOWN`

Главный результат — строка B. У ДЦ-1 большинство мастеров, и голосов на повышение реплики ему хватает, а кэша всё равно нет: реплика мастера, оставшегося в ДЦ-2, тоже осталась в ДЦ-2, и слоты этого мастера не покрыты никем.

Задержка, медиана из 200 замеров:

откуда читаем	медиана	p95
кэш в своём ДЦ	0,10 мс	0,14 мс
база в своём ДЦ	0,09 мс	0,13 мс
кэш в чужом ДЦ	41,09 мс	41,36 мс

Выводы, которые пришлось исправить

Разборов снаружи было два. Первый указал на три вывода, сделанных из одной точки каждый; второй — на сам измерительный стенд. Все указанные места пришлось не переписать словами, а перемерить, и четыре вывода из пяти оказались неверны.

«Наблюдаемое поведение шире документации» — неверно. Было сказано: раз cluster-require-full-coverage описан через записи, а GET тоже получил CLUSTERDOWN, значит поведение шире написанного. На самом деле за чтения отвечает отдельная описанная настройка cluster-allow-reads-when-down, по умолчанию no. readsdown.py меряет обе: с no двадцать ключей из двадцати получают CLUSTERDOWN; с yes узел отдаёт только ключи своих слотов — четырнадцать из двадцати, — остальные перенаправляет за оборванный канал, а записи отказаны при обоих значениях.

«Под угрозой всё, что записано за последний круг» — неверно. Круг совпал с потерей случайно. offsets.py меняет один только темп записи на том же канале и получает 104, 3 и 0 потерянных записей при отставании 3548, 99 и 0 байт. Мерой служит разница смещений потока репликации, а не круг.

«82 мс — это два круга» — неверно, и заменившее его объяснение тоже. waitcost.py показал, что фиксированным числом кругов цена не описывается, и статья честно написала, что сверх круга остаётся слагаемое в 42–44 мс неизвестной природы. Природа оказалась в приборе: relaycheck.py включает и выключает TCP_NODELAY на ретрансляторе при НУЛЕВОЙ задержке и получает 44,00 и 0,70 мс. После исправления цена WAIT — ровно один круг: 10,90, 41,52 и 81,40 мс при отношении 1,09, 1,04 и 1,02.

«Две половины одного разрыва» — так называть две последовательные проверки было нельзя. После первой проверки топология не обязана вернуться к исходной: реплика могла повыситься, слоты переехать. cluster.py теперь поднимает свежий кластер на каждую сторону и печатает топологию до и после, а также смену ролей.

«Большинство плюс реплика каждого потерянного мастера» — условие неполное. Третья часть — свежесть реплики: отставшая сверх cluster-replica-validity-factor выборы не начнёт. В этих опытах она не мешала, и это теперь напечатано, а не предполагается.

Источники

Redis. Redis replication — https://redis.io/docs/latest/operate/oss_and_stack/management/replication/
Redis. Redis cluster specification — https://redis.io/docs/latest/operate/oss_and_stack/reference/cluster-spec/
Redis. Scale with Redis Cluster (cluster-require-full-coverage) — https://redis.io/docs/latest/operate/oss_and_stack/management/scaling/
Valkey. Replication — https://valkey.io/topics/replication/
Valkey. Cluster specification — https://valkey.io/topics/cluster-spec/
PostgreSQL. High Availability, Load Balancing, and Replication — https://www.postgresql.org/docs/current/high-availability.html
PostgreSQL. Replication configuration parameters — https://www.postgresql.org/docs/current/runtime-config-replication.html
Redis. Active-Active geo-distributed databases — https://redis.io/docs/latest/operate/rs/databases/active-active/
Amazon. Caching challenges and strategies — https://aws.amazon.com/builders-library/caching-challenges-and-strategies/

Script

205 lines

"""Кэш в чужом датацентре против базы в своём.

ГЛАВНЫЙ ВОПРОС ЗАМЕРА. Кэш существует ради одного свойства: он быстрее
источника. Свойство это не абсолютное, а сравнительное, и потому его можно
потерять — если источник рядом, а кэш за сотней километров. Здесь оно
измеряется прямо: попадание в кэш через канал между ДЦ против чтения той же
строки из локальной базы.

ПОЧЕМУ БАЗА НАСТОЯЩАЯ. Сравнивать замер с «обычно база отвечает за 5 мс»
нельзя: это число ниоткуда. Postgres поднят рядом, таблица заполнена, чтение
идёт по первичному ключу — то есть сравниваются две измеренные величины, а
не измеренная с воображаемой.

ЗАПУСК: python3 bench/stretched-cache/latency.py
Нужны redis-server и работающий Postgres (адрес в DE_TEST_DATABASE_URL или
postgres://deep:deep@localhost:5433/deep_engineering).
"""

from __future__ import annotations

import os
import shutil
import socket
import statistics
import subprocess
import sys
import tempfile
import time

sys.path.insert(0, os.path.dirname(os.path.abspath(__file__)))
from link import DelayedLink  # noqa: E402

import psycopg  # noqa: E402
import redis  # noqa: E402

# Какой сервер запускать. По умолчанию тот, что в PATH; REDIS_SERVER_BIN и
# REDIS_CLI_BIN позволяют прогнать тот же замер на другой сборке — так снята
# таблица регрессии на Redis 8.10.1 и smoke-прогон на Valkey.
SERVER = os.environ.get("REDIS_SERVER_BIN", "redis-server")
CLI = os.environ.get("REDIS_CLI_BIN", "redis-cli")

ONE_WAY_MS = 20.0
ROWS = 5000
SAMPLES = 200
DSN = os.environ.get(
    "DE_TEST_DATABASE_URL",
    "postgres://deep:deep@localhost:5433/deep_engineering",
)


def free_port() -> int:
    s = socket.socket()
    s.bind(("127.0.0.1", 0))
    port = s.getsockname()[1]
    s.close()
    return port


def start_redis(port: int, dirname: str) -> subprocess.Popen:
    proc = subprocess.Popen(
        [SERVER, "--port", str(port), "--dir", dirname,
         "--save", "", "--appendonly", "no",
         "--logfile", os.path.join(dirname, "redis.log")]
    )
    deadline = time.time() + 10
    while time.time() < deadline:
        try:
            c = redis.Redis(port=port, socket_timeout=0.5)
            if c.ping():
                c.close()
                return proc
        except Exception:
            time.sleep(0.05)
    raise RuntimeError("redis не поднялся")


def percentile(values: list[float], q: float) -> float:
    ordered = sorted(values)
    idx = min(len(ordered) - 1, int(q * len(ordered)))
    return ordered[idx]


def main() -> None:
    tmp = tempfile.mkdtemp(prefix="cache-lat-")
    port = free_port()
    proc = None
    try:
        proc = start_redis(port, tmp)
        local = redis.Redis(port=port, decode_responses=True)
        version = local.info("server")["redis_version"]

        with psycopg.connect(DSN, autocommit=True) as db:
            pg_version = db.execute("SHOW server_version").fetchone()[0]
            db.execute("DROP TABLE IF EXISTS cache_probe")
            db.execute("CREATE TABLE cache_probe (id int PRIMARY KEY, payload text)")
            with db.cursor().copy(
                "COPY cache_probe (id, payload) FROM STDIN"
            ) as copy:
                for i in range(ROWS):
                    copy.write_row((i, f"payload-{i}-" + "x" * 180))
            db.execute("ANALYZE cache_probe")

            for i in range(ROWS):
                local.set(f"row:{i}", f"payload-{i}-" + "x" * 180)

            far = DelayedLink(port, delay_ms=ONE_WAY_MS)
            remote = redis.Redis(port=far.port, decode_responses=True,
                                 socket_timeout=5)

            print(f"Redis {version} · PostgreSQL {pg_version} · один хост")
            print(f"канал между ДЦ: {ONE_WAY_MS:.0f} мс в одну сторону, "
                  f"круг {2 * ONE_WAY_MS:.0f} мс")
            print(f"таблица {ROWS} строк, чтение по первичному ключу; "
                  f"{SAMPLES} замеров на строку вывода")
            print()

            def measure(fn) -> list[float]:
                """Прогрев, потом замер. И медиана вместо среднего.

                ПОЧЕМУ ПРОГРЕВ. Первое обращение оплачивает то, что к
                предмету замера отношения не имеет: разбор запроса, план,
                первое чтение страницы с диска, установление соединения.
                Без прогрева эти разовые расходы попадают в выборку и
                искажают её тем сильнее, чем быстрее сама операция.

                ПОЧЕМУ НЕ СРЕДНЕЕ. Первая редакция печатала среднее, и по
                базе вышло 1,94 мс при p95 = 0,16 мс. Среднее было в
                двенадцать раз больше девяносто пятого перцентиля — это не
                описание величины, а сообщение о том, что в выборке есть
                несколько выбросов, и они её и составляют. Медиана
                описывает середину, а p95 — хвост; вдвоём они говорят правду,
                которую среднее скрывало.
                """
                for i in range(50):
                    fn(i * 7 % ROWS)
                out = []
                for i in range(SAMPLES):
                    key = i * 7 % ROWS
                    t0 = time.perf_counter()
                    fn(key)
                    out.append((time.perf_counter() - t0) * 1000)
                return out

            cache_local = measure(lambda k: local.get(f"row:{k}"))
            cache_remote = measure(lambda k: remote.get(f"row:{k}"))
            cur = db.cursor()
            db_local = measure(
                lambda k: cur.execute(
                    "SELECT payload FROM cache_probe WHERE id = %s", (k,)
                ).fetchone()
            )

            print("7. КЭШ В ЧУЖОМ ДЦ МЕДЛЕННЕЕ БАЗЫ В СВОЁМ")
            print("-" * 66)
            print("                                    медиана, мс   p95, мс")
            for label, data in (
                ("кэш в своём ДЦ", cache_local),
                ("база в своём ДЦ", db_local),
                ("кэш в чужом ДЦ", cache_remote),
            ):
                print(f"  {label:<32} {statistics.median(data):>8.2f}"
                      f"   {percentile(data, 0.95):>7.2f}")
            print()
            ratio = statistics.median(cache_remote) / statistics.median(db_local)
            print(f"  кэш в чужом ДЦ медленнее базы в своём примерно "
                  f"в {ratio:.0f} раз")
            print()
            print("  Кэш существует ради одного свойства: он быстрее источника.")
            print("  Свойство сравнительное, а не абсолютное, и здесь оно")
            print("  потеряно — обращение в чужой ДЦ стоит сорок миллисекунд")
            print("  против доли миллисекунды до базы под рукой. Такой кэш не")
            print("  ускоряет ответ, а замедляет его, и вдобавок добавляет ещё")
            print("  одну систему, которая может отказать.")
            print()
            print("  ЧЕГО ЭТОТ ЗАМЕР НЕ ГОВОРИТ, и это важнее самих чисел.")
            print()
            print("  Первые две строки почти совпали: чтение по первичному")
            print("  ключу из прогретой таблицы стоит столько же, сколько GET")
            print("  из Redis. Отсюда НЕ следует, что кэш не нужен. Здесь")
            print("  сравнивается самая дешёвая операция базы: пять тысяч")
            print("  строк, всё в памяти, обращение по ключу, никакой")
            print("  конкуренции за соединения. Кэш ставят не против такого")
            print("  запроса, а против соединений, агрегатов по миллионам")
            print("  строк и тех же запросов, повторённых тысячу раз в")
            print("  секунду, — там разница появляется, и большая.")
            print()
            print("  Из замера следует ровно одно: кратность у кэша берётся")
            print("  из сравнения с источником, и если источник ближе, чем")
            print("  кэш, никакая кратность её не спасёт. Проверять надо не")
            print("  «быстрый ли Redis», а «быстрее ли он ТОГО, что заменяет,")
            print("  на ЭТОМ расстоянии».")
            db.execute("DROP TABLE cache_probe")
    finally:
        if proc is not None:
            proc.terminate()
            try:
                proc.wait(timeout=5)
            except subprocess.TimeoutExpired:
                proc.kill()
        shutil.rmtree(tmp, ignore_errors=True)


if __name__ == "__main__":
    main()