Deep Engineering

MEASUREMENT

bench/nameres/resolve.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/interview/sre/name-resolution
How to run it
sudo python3 bench/nameres/resolve.py  > bench/nameres/runs/resolve.txt
sudo python3 bench/nameres/practice.py > bench/nameres/runs/practice.txt

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

Замеры для урока «Разрешение имени»

Файл Что делает
resolve.py пять наблюдений: откуда приходит ответ (файл или сеть); есть ли кеш в процессе; цена имени, которое не разрешается; сколько запросов уходит при AF_UNSPEC и при AF_INET; что делают поисковые области и точка на конце имени
practice.py ответы к задачам урока: сколько имён спрошено с поисковой областью и без неё, сколько запросов уходит на неуказанное семейство и во что обходится ненайденное имя при настройках по умолчанию

Запуск из корня репозитория:

sudo python3 bench/nameres/resolve.py  > bench/nameres/runs/resolve.txt
sudo python3 bench/nameres/practice.py > bench/nameres/runs/practice.txt

Как устроен замер

Настоящий сервер имён для блоков 3–5 не нужен и вреден: его времена — это чужая сеть, а не поведение библиотеки. Вместо него скрипт поднимает свой сервер на 127.0.0.1:53, который принимает запросы и не отвечает ни на один, и на время замера подменяет /etc/resolv.conf. Всё, что при этом видно, — расписание повторов самой libc.

Исходный /etc/resolv.conf копируется в /tmp до первой подмены и возвращается в finally. Если процесс всё же убить между блоками, файл останется подменённым — копия лежит в /tmp/resolv.conf.bench-backup.

Что воспроизводимо

Цена ненайденного имени: timeout × attempts × число серверов, секунда в секунду. Число запросов: два при AF_UNSPEC, один при AF_INET; два имени при поисковой области и одно при точке на конце. Порядок источников — из nsswitch.conf.

Не воспроизводимы миллисекунды настоящих запросов: в этой среде они гуляют от 2,2 до 29,3 мс, поэтому ни одно утверждение урока на них не опирается. Не воспроизводится и то, какой именно адрес вернётся для example.com, — важно лишь, что за шесть вызовов подряд он менялся.

Требования к среде

Блокам 3–5 нужны права root: bind на порт 53 и запись в /etc/resolv.conf. Без них скрипт печатает not permitted и выполняет первые два блока. Нужен также рабочий выход в сеть для блоков 1 и 2 — без него example.com не разрешится и строки покажут gaierror.

Числа сняты на CPython 3.11.15, Linux 6.18.44, glibc с hosts: files dns.

Script

295 lines
"""Разрешение имени: приложение зовёт getaddrinfo, а не DNS.

ЗАЧЕМ ЭТОТ ФАЙЛ. «Медленный DNS» — диагноз, который ставят, ни разу не
посмотрев, что именно делает программа, когда ей дали имя. А делает она один
вызов libc, и дальше всё решают три файла: nsswitch.conf, hosts и resolv.conf.
Отсюда и вещи, которые на собеседовании звучат неожиданно: ответ может прийти
вообще без сети; кеша в процессе нет; а имя, которое не разрешается, стоит
времени, посчитанного из настроек, ещё до того, как начнёт тикать собственный
таймаут приложения.

ЧТО ЗДЕСЬ ИЗМЕРЯЕТСЯ. Пять наблюдений:
  1. Откуда приходит ответ: из файла или из сети, и какова разница в цене.
  2. Есть ли кеш в процессе: повторы одного имени по времени и по адресу.
  3. Цена имени, которое не разрешается: timeout x attempts x серверов.
  4. Сколько запросов уходит на одно имя при AF_UNSPEC и при AF_INET.
  5. Что делают поисковые области и точка на конце имени.

ПОЧЕМУ В БЛОКЕ 4 СЧИТАЮТСЯ ЗАПРОСЫ, А НЕ МИЛЛИСЕКУНДЫ. Времена настоящих
запросов в этой среде гуляют от 2 до 30 мс, и на таком разбросе сравнение двух
вызовов по времени не значит ничего. А число отправленных запросов — величина
точная, и именно она объясняет, откуда берётся разница.

КАК ИЗМЕРЯЮТСЯ БЛОКИ 3-5. Настоящий сервер имён для этого не нужен и вреден:
его времена — это чужая сеть. Вместо него скрипт поднимает СВОЙ сервер на
127.0.0.1:53, который принимает запросы и не отвечает ни на один, и на время
замера подменяет /etc/resolv.conf. Тогда всё, что видно, — это расписание
повторов самой libc, и оно воспроизводится точно. Исходный resolv.conf
возвращается в блоке finally.

ПОЧЕМУ ПОДПИСИ ПО-АНГЛИЙСКИ. Урок существует в двух языках и цитирует запись
прогона дословно обеими версиями.

ЗАПУСК: sudo python3 bench/nameres/resolve.py
Вывод: runs/resolve.txt

Блокам 3-5 нужны права: bind на порт 53 и запись в /etc/resolv.conf. Без них
скрипт честно печатает `not permitted` и пропускает их, а первые два блока
работают от любого пользователя.
"""

import os
import shutil
import socket
import sys
import threading
import time

RESOLV = "/etc/resolv.conf"
BACKUP = "/tmp/resolv.conf.bench-backup"
# Имя, которого нет ни в одной зоне: длинная случайная метка плюс .invalid,
# который зарезервирован именно под «этого имени не будет никогда».
PROBE = "zz-probe-9931"


def show(title: str) -> None:
    print()
    print(title)
    print("-" * len(title))


def row(label: str, value: object) -> None:
    print(f"  {label:<44} {value}")


def lookup(name: str, family: int = socket.AF_INET) -> tuple[float, str]:
    """Один вызов getaddrinfo: сколько занял и что вернул."""
    started = time.perf_counter()
    try:
        answer = socket.getaddrinfo(name, 80, family, socket.SOCK_STREAM)
        result = answer[0][4][0]
    except OSError as exc:
        result = type(exc).__name__
    return (time.perf_counter() - started) * 1000, result


# ------------------------------------------------------------------ 1
def block1() -> None:
    show("1. THE ANSWER CAN COME WITHOUT ANY NETWORK AT ALL")

    # Первый вызов в процессе грузит модули NSS, и эта цена — разовая. Мерить
    # её вместе с поиском по файлу значит мерить не то, о чём блок.
    lookup("localhost")

    order = "not readable"
    try:
        for line in open("/etc/nsswitch.conf"):
            if line.startswith("hosts:"):
                order = line.split(":", 1)[1].strip()
    except OSError:
        pass
    row("nsswitch.conf says hosts:", order)

    for name in ("localhost", "example.com"):
        ms, addr = lookup(name)
        row(f"getaddrinfo({name!r}), ms", f"{ms:.2f}  -> {addr}")

    print()
    print("  The first name is in /etc/hosts, the second is not. Same call,")
    print("  same library, and the gap is not a matter of a fast server: one")
    print("  of the two never leaves the machine at all.")


# ------------------------------------------------------------------ 2
def block2() -> None:
    show("2. THERE IS NO CACHE INSIDE THE PROCESS")

    times = []
    addrs = []
    for _ in range(6):
        ms, addr = lookup("example.com")
        times.append(ms)
        addrs.append(addr)
    for i, (ms, addr) in enumerate(zip(times, addrs), start=1):
        row(f"call {i} of getaddrinfo('example.com'), ms", f"{ms:.2f}  -> {addr}")
    row("distinct addresses returned", len(set(addrs)))
    row("last call against the first, ms", f"{times[-1]:.2f} against {times[0]:.2f}")

    print()
    print("  The spread does not depend on the call number, and the address")
    print("  is not stable either. Nothing is kept inside the process, so a")
    print("  program that resolves a name per request pays on every request.")


# ------------------------------------------------------------------ silent server
class SilentNameServer:
    """Сервер имён на 127.0.0.1:53, который принимает запросы и молчит.

    Нужен, чтобы измерять расписание повторов libc, а не чужую сеть. Имена
    из принятых пакетов разбираются, чтобы было видно, ЧТО именно спрошено:
    в блоке 5 это и есть предмет наблюдения.
    """

    def __init__(self) -> None:
        self.sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
        self.sock.bind(("127.0.0.1", 53))
        self.seen: list[str] = []
        threading.Thread(target=self._loop, daemon=True).start()

    def _loop(self) -> None:
        while True:
            try:
                packet, _ = self.sock.recvfrom(512)
            except OSError:
                return
            try:
                self.seen.append(self._name(packet))
            except Exception:  # noqa: BLE001 — чужой пакет нас не касается
                pass

    @staticmethod
    def _name(packet: bytes) -> str:
        """Имя из секции вопроса. Заголовок DNS — ровно 12 байт."""
        i = 12
        parts = []
        while packet[i]:
            length = packet[i]
            parts.append(packet[i + 1 : i + 1 + length].decode())
            i += length + 1
        return ".".join(parts)

    def close(self) -> None:
        self.sock.close()


def write_resolv(text: str) -> None:
    with open(RESOLV, "w") as handle:
        handle.write(text)


def timed_lookup(server: SilentNameServer, name: str) -> tuple[float, list[str]]:
    """Замер с отбором своих запросов: в контейнере есть и чужой трафик."""
    server.seen.clear()
    started = time.perf_counter()
    try:
        socket.getaddrinfo(name, 80, socket.AF_INET, socket.SOCK_STREAM)
    except OSError:
        pass
    elapsed = (time.perf_counter() - started) * 1000
    return elapsed, [n for n in server.seen if PROBE in n]


# ------------------------------------------------------------------ 3
def block3(server: SilentNameServer) -> None:
    show("3. A NAME THAT DOES NOT RESOLVE COSTS timeout x attempts x servers")

    cases = [
        ("127.0.0.1", 1, 1),
        ("127.0.0.1", 1, 2),
        ("127.0.0.1", 1, 3),
        ("127.0.0.1", 2, 2),
    ]
    print(f"  {'nameservers':>12} {'timeout':>8} {'attempts':>9} {'expected, s':>12} {'measured, ms':>13} {'queries':>8}")
    for servers, timeout, attempts in cases:
        write_resolv(
            f"nameserver {servers}\noptions timeout:{timeout} attempts:{attempts}\n"
        )
        ms, seen = timed_lookup(server, f"{PROBE}.invalid")
        print(
            f"  {1:>12} {timeout:>8} {attempts:>9} {timeout * attempts:>12}"
            f" {ms:>13.1f} {len(seen):>8}"
        )

    write_resolv(
        "nameserver 127.0.0.1\nnameserver 127.0.0.1\noptions timeout:1 attempts:2\n"
    )
    ms, seen = timed_lookup(server, f"{PROBE}.invalid")
    print(f"  {2:>12} {1:>8} {2:>9} {4:>12} {ms:>13.1f} {len(seen):>8}")

    print()
    print("  The rule is arithmetic, not luck: every server gets every attempt,")
    print("  and each attempt waits the full timeout. A second name server in")
    print("  the file is not a spare - it is a doubling of the worst case.")


# ------------------------------------------------------------------ 4
def block4(server: SilentNameServer) -> None:
    show("4. AF_UNSPEC ASKS TWICE: ONE QUESTION PER ADDRESS FAMILY")

    write_resolv("nameserver 127.0.0.1\noptions timeout:1 attempts:1 ndots:15\n")
    for family, label in (
        (socket.AF_UNSPEC, "AF_UNSPEC (the default of most clients)"),
        (socket.AF_INET, "AF_INET (IPv4 only)"),
    ):
        server.seen.clear()
        started = time.perf_counter()
        try:
            socket.getaddrinfo(f"{PROBE}.invalid", 80, family, socket.SOCK_STREAM)
        except OSError:
            pass
        elapsed = (time.perf_counter() - started) * 1000
        mine = [n for n in server.seen if PROBE in n]
        word = "query" if len(mine) == 1 else "queries"
        row(label, f"{len(mine)} {word}, {elapsed:.1f} ms")

    print()
    print("  AF_UNSPEC is what a high-level client uses unless told otherwise,")
    print("  and it asks for A and AAAA. Both questions go to the same server,")
    print("  so a server that is slow or silent on one family holds up the")
    print("  whole call even when the other family answered at once.")


# ------------------------------------------------------------------ 5
def block5(server: SilentNameServer) -> None:
    show("5. SEARCH DOMAINS TURN ONE LOOKUP INTO SEVERAL")

    base = "nameserver 127.0.0.1\nsearch svc.cluster.local cluster.local\noptions timeout:1 attempts:1 "
    for ndots, name, label in (
        (5, f"{PROBE}.internal", "ndots:5, name has one dot"),
        (1, f"{PROBE}.internal", "ndots:1, same name"),
        (5, f"{PROBE}.internal.", "ndots:5, same name with a trailing dot"),
    ):
        write_resolv(base + f"ndots:{ndots}\n")
        ms, seen = timed_lookup(server, name)
        word = "lookup" if len(seen) == 1 else "lookups"
        row(label, f"{ms:.1f} ms, {len(seen)} {word}")
        for asked in seen:
            row("  asked for", asked)

    print()
    print("  ndots decides the ORDER, the search list decides HOW MANY. Each")
    print("  extra name costs the whole timeout arithmetic from block 3 again.")
    print("  A trailing dot means 'this name is already complete' and skips")
    print("  the search list entirely.")


def main() -> None:
    print(f"Python {sys.version.split()[0]} · Linux {os.uname().release}")
    print("blocks 3 to 5 use a silent name server on 127.0.0.1:53")
    block1()
    block2()

    try:
        shutil.copyfile(RESOLV, BACKUP)
        server = SilentNameServer()
    except OSError as exc:
        show("3-5. NOT PERMITTED")
        row("cannot bind :53 or write resolv.conf", type(exc).__name__)
        print()
        print("  Run as root to measure the retry schedule and the query counts.")
        return

    try:
        block3(server)
        block4(server)
        block5(server)
    finally:
        shutil.copyfile(BACKUP, RESOLV)
        server.close()
        print()
        print("  resolv.conf restored from the backup taken before block 3.")


if __name__ == "__main__":
    main()