Debugging challenges

Первый вопрос: завершился с ошибкой или сделал свою работу и вышел? Их различает код возврата.

docker ps -a --filter name=worker --format '{{.Status}}'
docker inspect worker --format '{{.State.ExitCode}}'

Причина. Скрипт печатает строку и заканчивается. Container живёт ровно столько, сколько живёт процесс с PID 1 — это не «машина», которую можно «оставить работать».

Exited (0) 2 seconds ago
0

Код 0 — ключ. Ошибки не было; работа сделана.

Исправление — дать процессу работу:

import signal
import sys
import time

running = True


def on_term(signum, frame):
    global running
    running = False


signal.signal(signal.SIGTERM, on_term)
print("обработчик запущен", flush=True)
while running:
    time.sleep(1)
print("обработчик остановлен", flush=True)

Чего делать не следует. Добавить sleep infinity или tail -f /dev/null, чтобы «не падало». Container будет жив, работа не сделана, и никто об этом не узнает (урок 19.4).

Разбор: урок 4.1.

Строки появляются при завершении. Значит, они где-то накапливались. Где именно и почему именно при перенаправлении?

Причина. Python буферизует stdout блоками, когда он не терминал. В container'е вывод идёт в канал, а не в терминал, поэтому строки копятся в буфере до его заполнения или до завершения процесса.

Проверка гипотезы:

docker run --rm -e PYTHONUNBUFFERED=1 образ

Если строки появились сразу — причина найдена.

Исправление в Dockerfile:

ENV PYTHONUNBUFFERED=1

Почему не flush=True в каждом print. Работает, но не покрывает вывод библиотек и logging. Переменная окружения действует на всё.

Чего это стоит. Буферизация ускоряет вывод; её отключение — сознательный размен производительности на наблюдаемость. Для сервиса размен верный: лог, появляющийся через час, бесполезен.

Разбор: урок 6.6.

Публикация порта и наличие слушателя — разные вещи. Проверьте изнутри container'а, что именно слушает и на каком порту.

docker exec app python -c "
import socket
for p in (8000, 8080):
    s = socket.socket(); s.settimeout(1)
    print(p, 'открыт' if s.connect_ex(('127.0.0.1', p)) == 0 else 'закрыт')"

Причина, случай А. Приложение слушает не тот порт, который опубликован. -p 8080:8000 означает «порт 8080 хоста ведёт на порт 8000 container'а». Если приложение слушает 5000, публикация ведёт в пустоту.

Причина, случай Б. Приложение слушает 127.0.0.1 — см. challenge 4.

Как различить. Внутри container'а:

docker exec app python -c "
import socket
s = socket.socket(); s.settimeout(1)
print('8000 изнутри:', s.connect_ex(('127.0.0.1', 8000)))"

• соединение проходит, снаружи нет → случай Б;
• не проходит и изнутри → случай А или приложение не запустилось.

Существенно. EXPOSE в Dockerfile ничего не публикует. Это документация: она сообщает, какой порт предполагается, и не создаёт ни одного правила.

Разбор: урок 8.3.

Изнутри работает, снаружи нет. Что означает 127.0.0.1 внутри container'а?

Причина. Каждый container имеет собственный network namespace (урок 17.3). 127.0.0.1 внутри — это петлевой интерфейс самого container'а, а не хоста.

Опубликованный порт направляет трафик на адрес container'а в сети Docker. Приложение, слушающее только петлю, этот трафик не видит.

Исправление:

uvicorn.run(app, host="0.0.0.0", port=8000)

Возражение «это небезопасно» и ответ на него. 0.0.0.0 внутри container'а означает «все интерфейсы container'а», а их немного. Наружу сервис попадает только через публикацию порта — и вот её как раз стоит ограничивать:

docker run -p 127.0.0.1:8080:8000 образ

Так порт доступен с хоста и недоступен из сети.

Разбор: урок 8.3.

Проверьте, в какой сети находятся оба:

docker inspect first --format '{{json .NetworkSettings.Networks}}'

Причина. Оба container'а попали в сеть по умолчанию bridge. В ней нет разрешения имён — только адреса.

Встроенный DNS работает в пользовательских сетях, а сеть по умолчанию сохранена ради совместимости и такого разрешения не даёт.

Исправление:

docker network create app-net
docker run -d --name first --network app-net образ
docker run -d --name second --network app-net образ
docker exec first getent hosts second

172.18.0.3      second

В Compose это происходит само. Compose создаёт пользовательскую сеть для проекта, поэтому симптом встречается только при ручном docker run.

Разбор: урок 8.4.

Разрешение имён работает, а подключение нет. Значит, имя правильное, а адрес — нет. К чему относится localhost в этом контексте?

Причина. localhost внутри container'а api указывает на сам api. База работает в другом container'е, у которого свой network namespace и свой localhost.

Исправление — обращаться по имени сервиса:

DATABASE_URL: postgresql://app@db:5432/appdb

Три места, где эта ошибка повторяется:

Вторая строка не ошибка: healthcheck выполняется внутри того же container'а, и localhost там указывает куда надо. Различать эти случаи и есть суть.

Разбор: урок 8.4.

Кто владелец каталога внутри container'а?

docker compose exec app ls -ldn /data

Причина. Пустой именованный том при первом подключении получает владельца и права из образа — точнее, из того каталога, поверх которого он подключён. Если в образе /data не существовал или принадлежал root, том достаётся root, а процесс работает от 10001.

drwxr-xr-x 2 0 0 4096 Aug  4 12:00 /data

Владелец 0 — это root.

Исправление в образе — создать каталог заранее с нужным владельцем:

RUN mkdir -p /data && chown 10001:10001 /data
USER 10001:10001
VOLUME ["/data"]

Чего делать не следует. chmod 777 на томе. Работает, и любой процесс получает полный доступ к данным.

Тонкость. Права копируются из образа только при первом подключении пустого тома. Уже созданный том сохраняет свои права, и пересборка образа их не изменит — нужно docker volume rm.

Разбор: урок 7.5.

Сравните содержимое каталога с монтированием и без:

docker run --rm образ ls /app
docker run --rm -v "$PWD:/app" образ ls /app

Причина. Монтирование накрывает каталог целиком. Файлы образа по этому пути становятся недоступны — они никуда не делись, но их не видно, как книгу под скатертью.

# без монтирования
app  requirements.txt  venv

# с монтированием
app.py  README.md

Каталог хоста не содержит того, что было в образе.

Три исправления, и выбор между ними — по задаче:

Второй способ обычно лучший: он устраняет саму причину, а не последствие.

Разбор: урок 7.3.

Смотрите вывод сборки: где заканчиваются строки CACHED и начинается выполнение. Первая невыполненная инструкция — та, которая сбросила кэш.

Причина. COPY . . копирует всё, включая исходники. Любое изменение любого файла меняет контрольную сумму слоя, и весь дальнейший кэш недействителен — в том числе pip install.

Исправление — разделить копирование:

FROM python:3.13-slim
WORKDIR /app
COPY requirements.txt .
RUN --mount=type=cache,target=/root/.cache/pip \
    pip install -r requirements.txt
COPY app/ ./app/
CMD ["python", "-m", "app"]

Теперь изменение кода сбрасывает только последние два слоя.

Проверка исправления по времени, а не по числу CACHED:

docker build -t проба . && touch app/main.py && time docker build -t проба .

Секунды — работает. Минуты — нет.

Вторая, менее заметная причина того же симптома — отсутствие .dockerignore. Тогда в контекст попадают .git, __pycache__, каталоги окружений, и COPY видит изменения даже там, где вы ничего не трогали.

Разбор: урок 5.5.

Найдите, какие слои занимают место:

docker history образ --human --format 'table {{.Size}}\t{{.CreatedBy}}' | head -15

Четыре причины, и все четыре здесь присутствуют.

Исправление:

# syntax=docker/dockerfile:1
FROM python:3.13-slim AS deps
RUN python -m venv /opt/venv
ENV PATH=/opt/venv/bin:$PATH
RUN apt-get update && apt-get install -y --no-install-recommends build-essential \
    && rm -rf /var/lib/apt/lists/*
COPY requirements.txt .
RUN pip install -r requirements.txt

FROM python:3.13-slim AS runtime
ENV PATH=/opt/venv/bin:$PATH
WORKDIR /app
COPY --from=deps /opt/venv /opt/venv
COPY app/ ./app/
USER 10001:10001
CMD ["python", "-m", "app"]

Существенно про третью строку. Удаление кэша следующей инструкцией не помогает: файлы остаются в предыдущем слое. Слои только добавляются; удаление в новом слое лишь скрывает файл (урок 3.2).

Разбор: урок 3.4, урок 5.7.

Что происходит с аргументами docker run, когда задан только CMD? А когда задан ENTRYPOINT?

Причина. Аргументы docker run заменяют CMD целиком. Команда превращается в --help, а поскольку образ основан на python, выполняется python --help... либо, в зависимости от базового образа, вообще ничего.

Исправление:

ENTRYPOINT ["python", "-m", "app"]
CMD ["--help"]

Теперь docker run образ печатает справку, а docker run образ --top 3 передаёт аргументы приложению.

Второй симптом того же семейства — shell-форма:

ENTRYPOINT python -m app     # неверно

Она разворачивается в /bin/sh -c "python -m app", аргументы docker run вообще теряются, а PID 1 становится оболочкой (challenge 12).

Разбор: урок 5.4.

Ровно 10 секунд — это grace period по умолчанию. Значит, сигнал не был обработан и пришёл SIGKILL. Кто получил SIGTERM?

docker exec app ps -eo pid,ppid,cmd

Причина. Shell-форма CMD разворачивается в /bin/sh -c "python app.py". PID 1 — оболочка, Python — её потомок.

  PID  PPID CMD
    1     0 /bin/sh -c python app.py
    7     1 python app.py

docker stop посылает SIGTERM процессу с PID 1, то есть sh. Она не пересылает сигнал потомкам. Через 10 секунд приходит SIGKILL, убивающий всё разом.

Исправление — exec-форма:

CMD ["python", "app.py"]

  PID  PPID CMD
    1     0 python app.py

Как отличить эту причину от «обработчика нет вовсе». Только проверкой PID 1: при отсутствии обработчика PID 1 был бы самим Python. Симптом одинаков — 10 секунд.

Второй источник того же. Если точка входа — скрипт-обёртка, вызывающий приложение, нужен exec:

#!/bin/sh
exec python app.py     # без exec оболочка останется PID 1

Разбор: урок 4.4, урок 4.5.

Код 137 = 128 + 9. Кто послал сигнал 9, и почему приложение не смогло об этом сообщить?

docker inspect app --format '{{.State.ExitCode}} {{.State.OOMKilled}}'

Причина. Превышено ограничение памяти cgroup; ядро завершило процесс через OOM killer. SIGKILL не перехватывается — обработчика для него не существует в принципе, поэтому приложение физически не могло ничего записать.

137 true

Почему в логах приложения пусто. Запись делает ядро:

dmesg | grep -i 'killed process'
docker events --filter 'event=oom' --since 24h

Как предсказать заранее — счётчики давления памяти растут задолго до отказа:

docker exec app cat /sys/fs/cgroup/memory.events

low 0
high 0
max 4213
oom 12
oom_kill 3

Ненулевой max означает, что процесс уже упирался в предел.

Три гипотезы, и различить их можно только измерением:

Поднять лимит, не различив их, — обычная ошибка: при утечке это лишь отодвигает отказ.

Разбор: урок 11.4, урок 17.4.

Healthcheck выполняется внутри container'а. Проверьте, что там происходит:

docker inspect app --format '{{json .State.Health}}' | python3 -m json.tool

Причина, случай А — curl нет в образе.

{
    "Status": "unhealthy",
    "Log": [{"ExitCode": 127, "Output": "OCI runtime exec failed: exec: \"curl\": executable file not found"}]
}

Код 127 — «команда не найдена». В python:*-slim и в alpine curl отсутствует.

Исправление без установки лишнего пакета:

HEALTHCHECK --interval=10s --timeout=3s --start-period=10s --retries=3 \
    CMD ["python", "-c", "import urllib.request,sys; sys.exit(0 if urllib.request.urlopen('http://127.0.0.1:8000/health').status==200 else 1)"]

Причина, случай Б — нет start-period. Приложение стартует 20 секунд, проверки идут с первой, три подряд неудачи помечают container нездоровым ещё до того, как он успел запуститься.

Причина, случай В — проверка зависит от базы. Тогда отказ базы делает нездоровым приложение, и оркестратор перезапускает его — хотя перезапуск ничего не чинит (урок 11.3).

Как различить. Поле Log[].ExitCode: 127 — нет команды, 1 — проверка вернула ошибку, 124 — истёк timeout.

Разбор: урок 5.8.

Что именно гарантирует depends_on в форме списка? Прочитайте формулировку буквально.

Причина. depends_on в форме списка ждёт запуска container'а, а не готовности процесса внутри. PostgreSQL после старта container'а несколько секунд инициализирует кластер и соединения не принимает.

Плавающий характер — следствие: на прогретой машине база успевает, на холодной нет.

Исправление:

services:
  api:
    depends_on:
      db:
        condition: service_healthy

  db:
    image: postgres:17-alpine
    healthcheck:
      test: ["CMD-SHELL", "pg_isready -U app -d appdb"]
      interval: 5s
      timeout: 3s
      retries: 10
      start_period: 10s

Чего это не решает. Отказ базы в работе, а не при старте. depends_on действует один раз; повторы подключения в коде действуют всегда. Правильный ответ — и то и другое, а в Kubernetes останется только второе (урок 18.3).

Проверка исправления. Один успешный запуск ничего не доказывает:

for i in $(seq 10); do
  docker compose down -v >/dev/null 2>&1
  docker compose up -d >/dev/null 2>&1
  sleep 15
  docker compose ps api --format '{{.Status}}'
done

Разбор: урок 9.4.

Адреса доступны, имена нет — значит, сеть работает, а разрешение имён нет. Проверьте, что видит container:

docker exec app cat /etc/resolv.conf

Причина, случай А — сеть объявлена internal.

networks:
  backend:
    internal: true

internal: true отрезает выход наружу. Внутренние имена разрешаются, внешние — нет. Это не ошибка, если так и задумано: контейнеры с данными не должны ходить в интернет.

Причина, случай Б — DNS хоста недоступен из сети Docker. Типично, когда /etc/resolv.conf хоста указывает на 127.0.0.53 (systemd-resolved): внутри container'а этот адрес указывает на сам container.

Docker обычно подменяет такой адрес, но при нестандартной настройке подмена не срабатывает.

Проверка:

docker exec app cat /etc/resolv.conf
docker run --rm --dns 1.1.1.1 образ getent hosts pypi.org

Если со вторым явно заданным DNS работает — причина в разрешении, а не в сети.

Исправление для случая Б:

services:
  app:
    dns: [1.1.1.1, 8.8.8.8]

Как различить А и Б. Проверить internal у сети:

docker network inspect имя --format '{{.Internal}}'

Разбор: урок 8.4, урок 8.6.

Место занимают четыре разных вещи, и очищаются они по-разному:

docker system df -v | head -20

Четыре источника:

Четвёртый пункт находят реже прочих, потому что docker system df его не показывает:

du -sh /var/lib/docker/containers/*/*-json.log | sort -h | tail -5

Исправление логов — ротация:

logging:
  driver: json-file
  options:
    max-size: "10m"
    max-file: "3"

Или в /etc/docker/daemon.json для всех container'ов сразу.

Очистка — по возрастанию опасности:

docker builder prune                    # кэш сборки: безопасно
docker image prune                      # образы без тегов: почти безопасно
docker volume prune                     # тома без container'ов: ОПАСНО, это данные
docker system prune -a                  # всё, включая нужные образы

Чего не делать в эксплуатации. docker system prune -a удаляет образы, на которых можно было бы откатиться. Место освободится, а откат станет невозможен.

Разбор: урок 13.4.

Что такое <none>:<none> и откуда они берутся? Сравните с выводом docker images -a.

Причина. Это образы, потерявшие тег. Сборка с тем же тегом переносит его на новый образ; старый остаётся без имени и не удаляется.

docker build -t app:latest .   # первый образ получает тег
docker build -t app:latest .   # тег переходит на новый; первый становится <none>

Один docker build в день — тридцать безымянных образов в месяц.

Исправление, часть 1 — очистка:

docker image prune                    # только безымянные
docker image prune -a --filter 'until=168h'   # старше недели

Исправление, часть 2 — не создавать проблему. Неизменяемые теги вместо перезаписываемых:

docker build -t "app:g$(git rev-parse --short HEAD)" .

Тогда каждый образ сохраняет имя, и удалять их можно осознанно — по возрасту или по номеру сборки.

Побочная польза. Тот же приём делает возможным откат: перезаписываемый тег latest не позволяет вернуться к предыдущему образу, потому что под этим именем его уже нет (урок 14.4).

Разбор: урок 3.4.

Слои неизменяемы и только добавляются. Что делает rm в новом слое с файлом из предыдущего?

docker history --no-trunc образ | grep -i ssh

Причина. Файловая система образа — стек слоёв. Удаление в новом слое создаёт запись «этого файла здесь нет», но содержимое остаётся в нижнем слое и извлекается:

docker save образ -o образ.tar
tar -xf образ.tar -C распакованное
grep -rl 'BEGIN OPENSSH PRIVATE KEY' распакованное/

Исправление — секрет, не попадающий в слои:

# syntax=docker/dockerfile:1
RUN --mount=type=secret,id=ssh_key,target=/root/.ssh/id_rsa \
    git clone git@github.com:org/private.git

docker build --secret id=ssh_key,src=$HOME/.ssh/id_rsa .

Секрет доступен во время выполнения инструкции и в слой не записывается.

Второй способ — multi-stage: клонировать в стадии сборки и копировать в итоговый образ только результат. Слой с ключом останется в промежуточной стадии, которая в образ не входит.

Что делать с уже опубликованным образом. Считать ключ скомпрометированным и отозвать его. Удаление образа из registry не помогает: он мог быть загружен кем угодно.

Разбор: урок 12.6.

Выясните, какая конкретная возможность нужна, вместо того чтобы выдавать все. Проверить можно перебором.

Что даёт privileged: true:

Вместе с - /:/host это эквивалентно правам root на хосте (урок 19.2).

Исправление, шаг 1 — выдать точную возможность:

services:
  backup:
    cap_drop: [ALL]
    cap_add: [DAC_READ_SEARCH]    # чтение любых файлов, без записи
    volumes:
      - /:/host:ro                # только для чтения
    read_only: true

Как найти нужную возможность. Перебором от пустого набора: запускать с cap_drop: [ALL] и добавлять по одной, пока не заработает. Обратный порядок — снимать по одной от полного набора — обычно оставляет лишнее.

Исправление, шаг 2 — усомниться в задаче. Резервное копирование всей файловой системы хоста из container'а — сомнительный приём сам по себе. Обычно правильнее запускать копирование на хосте, а container использовать только для выгрузки в хранилище.

Три конфигурации, эквивалентные root на хосте:

Вторая опаснее прочих тем, что выглядит безобидно: «просто файл».

Разбор: урок 12.4.