dnsmasq: ошибки в AWS — «Temporary failure in name resolution», логи, дебаг и размер кеша

Автор: | 26/10/2019
Нет комментариев

При использовании AWS VPC DNS периодически сталкиваемся с ошибками вида «php_network_getaddresses: getaddrinfo failed: Temporary failure in name resolution«.

Единственный совет от тех. поддержки AWS заключался в установке dnsmasq в роли кеширующего сервиса, но он уже давно установлен — а проблема раз в несколько месяцев проявляется снова.

Хотя пост не о том, но из возможных причин пока представляются реальными две:

  • локальный dnsmasq падает, все запросы начинают обрабатываться AWS VPC DNS, у которого есть хард-лимит на 1024 запросов/сек — он исчерпывается, и получаем ошибку разрешения имён
  • превышение кол-ва пакетов на интерфейсе AWS EC2, см. Packets-per-second limits in EC2 и EC2 Packets per Second: Guaranteed Throughput vs Best Effort

Второй вариант маловероятен, а для того, что бы попробовать отловить проблемы с самим dnsmasq — рассмотрим его полезные опции для логирования и посмотрим, как проверить есть ли проблемы с размером кеша.

Prometheus и метрики dnsmasq

Первое, что мы сделали после того, как согласились с предположением, что dnsmasq падает — это добавили его под мониторинг Prometheus с помощью dnsmasq_exporter.

Експортер собирает такие метрики:

...
Question: []dns.Question{
  question("cachesize.bind."),
  question("insertions.bind."),
  question("evictions.bind."),
  question("misses.bind."),
  question("hits.bind."),
  question("auth.bind."),
  question("servers.bind."),
},
...

Их же можно получить запросов типа Chaos (см. DNS classes) с помощью dig.

Например — список upstream-DNS серверов, на которые пересылает запрос dnsmasq, если не находит запись о домене в своём кеше:

[simterm]

root@bttrm-production-console:/home/admin# dig @localhost +short chaos txt servers.bind
"10.0.3.2#53 9301 0" "1.1.1.1#53 402 0"

[/simterm]

Посмотрим resolv.conf:

[simterm]

root@bttrm-production-console:/home/admin# cat /etc/resolv.conf 
domain us-east-2.compute.internal
search us-east-2.compute.internal
nameserver 127.0.0.1
nameserver 10.0.3.2
nameserver 1.1.1.1

[/simterm]

Собственно их dnsmasq и возвращает: 10.0.3.2 — это VPC DNS, 1.1.1.1 — CloudFlare DNS для fallback, если VPC DNS не отвечает (впрочем — не сильно помогает, как видим).

Что они нам дают?

  • cachesize.bind: размер кеша (кол-во доменов, которые хранятся в кеше)
  • insertions.bind: кол-во добавлений записей в кеш
  • evictions.bind: кол-во удаления записей из кеша (по истечении TTL домена или при достижении лимита кеша)
  • misses.bind: кол-во запросов, которые не были найдены в кеше и были перенаправлены апстрим-серверам
  • hits.bind: кол-во запросов, на которые dnsmasq дал ответ из своего кеша
  • auth.bind: кол-во запросов к authority-зонам (dnsmasq может играть роль authority-сервера для доменов)
  • servers.bind: рассмотрели выше — список апстрим-серверов для форвардинга запросов

Используя их — можем построить графики, например — посмотреть соотношение запросов всего — и запросов, на которые dnsmasq ответил из своего кеша:

sum(increase(dnsmasq_hits[1m])) / (sum(increase(dnsmasq_hits[1m])) + sum(increase(dnsmasq_misses[1m])))

Или с выборкой по конкретному хосту:

sum(increase(dnsmasq_hits{host="bttrm-production-console"}[1m])) / (sum(increase(dnsmasq_hits{host="bttrm-production-console"}[1m])) + sum(increase(dnsmasq_misses{host="bttrm-production-console"}[1m])))

Значит — 98 из 100 запросов отданы из кеша — очень неплохо.

dnsmasq debugging

Сам dnsmasq для дебага можно запустить с опциями -d (—no-daemon) и -q (—log-queries):

[simterm]

$ sudo dnsmasq -q -d
dnsmasq: started, version 2.80 cachesize 150
dnsmasq: compile time options: IPv6 GNU-getopt DBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile
dnsmasq: reading /etc/resolv.conf
dnsmasq: using nameserver 188.190.254.254#53
dnsmasq: using nameserver 31.43.120.254#53
dnsmasq: using nameserver 1.1.1.1#53
dnsmasq: read /etc/hosts - 2 addresses

[/simterm]

Обращаемся к нему:

[simterm]

$ dig @localhost ya.ru +short
87.250.250.242

[/simterm]

Смотрим output:

[simterm]

...
dnsmasq: query[A] ya.ru from ::1
dnsmasq: forwarded ya.ru to 188.190.254.254
dnsmasq: forwarded ya.ru to 31.43.120.254
dnsmasq: forwarded ya.ru to 1.1.1.1
dnsmasq: reply ya.ru is 87.250.250.242
...

[/simterm]

Повторяем запрос — и ещё раз STDOUT:

[simterm]

...
dnsmasq: query[A] ya.ru from ::1
dnsmasq: cached ya.ru is 87.250.250.242
...

[/simterm]

При первом запросе запись в кеше не найдена — и dnsmasq переслал запрос к апстрим-серверам.

При втором запросе — вернул уже cached значение.

Можно добавить extra, что бы добавлять серийный номер к каждой записи, относящейся к конкретному запросу — проще отслеживать запросы, если записей в аутпуте много:

[simterm]

$ sudo dnsmasq --log-queries=extra -d
dnsmasq: started, version 2.80 cachesize 150
dnsmasq: compile time options: IPv6 GNU-getopt DBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile
dnsmasq: reading /etc/resolv.conf
dnsmasq: using nameserver 188.190.254.254#53
dnsmasq: using nameserver 31.43.120.254#53
dnsmasq: using nameserver 1.1.1.1#53
dnsmasq: read /etc/hosts - 2 addresses
dnsmasq: 1 ::1/49217 query[A] ya.ru from ::1
dnsmasq: 1 ::1/49217 forwarded ya.ru to 188.190.254.254
dnsmasq: 1 ::1/49217 forwarded ya.ru to 31.43.120.254
dnsmasq: 1 ::1/49217 forwarded ya.ru to 1.1.1.1
dnsmasq: 1 ::1/49217 reply ya.ru is 87.250.250.242
dnsmasq: 2 ::1/42356 query[A] ya.ru from ::1
dnsmasq: 2 ::1/42356 cached ya.ru is 87.250.250.242

[/simterm]

dnsmasq logging

Кроме мониторинга за самим сервисом — мы добавили сбор его логов в Loki (см. Grafana Labs: Loki — сбор и просмотр логов).

За логгирование отвечает опция log-facility, которой можно задать канал доставки в syslog — по умолчанию это DAEMON, и LOCAL0 при запуске с -d (—no-daemon), см. syslog facility.

Кроме логгирования через syslog — можно просто указать файл лога:

log-facility="/var/log/dnsmasq.log"

И при необходимости там же добавляем log-queries для логгирования ответов на запросы.

Также может пригодится опция log-async, которая включает асинхронную запись — полезно при ключенной log-queries, когда запросов к dnsmasq и записей в лог много.

resolv.conf и resolv.dnsmasq

Имеет смысл вынести апстрим-сервера из resolv.conf и в нём оставить только сам dnsmasq, что бы быть уверенным в том, что все DNS-запросы из системы будут переданы ему, плюс это позволяет иметь динамически обновляемый resolv.conf (например, если он генерируется NetworkManager).

Обновляем resolv.conf:

[simterm]

root@bttrm-production-console:/home/admin# cat /etc/resolv.conf 
domain us-east-2.compute.internal
search us-east-2.compute.internal
nameserver 127.0.0.1

[/simterm]

Далее можно создать новый файл, например resolv.dnsmasq, в котором перечислить апстримы:

[simterm]

root@bttrm-production-console:/home/admin# cat /etc/resolv.dnsmasq
nameserver 10.0.3.2
nameserver 1.1.1.1

[/simterm]

И задать в конфиге /etc/dnsmasq.conf опцию --resolv-file="/etc/resolv.dnsmasq":

...
resolv-file="/etc/resolv.dnsmasq"
...

Перед рестаром проверяем синтаксис конфига:

[simterm]

root@bttrm-production-console:/home/admin# dnsmasq --test
dnsmasq: syntax check OK.

[/simterm]

--servers

Другой вариант — вместо создания /etc/resolv.dnsmasq указать апстримы прямо в конфиге через опцию server:

server=10.0.3.2
server=1.1.1.1

Кроме того,  спомощью server можно задать конкретные апстримы для конкретных доменов.

Например, что бы выполнять разрешение имени backend-db2-slave.example.com исключительно через VPC DNS 10.0.3.2 — задаём в конфиге следующую запись:

...
server=/backend-db2-slave.example.com/10.0.3.2
...

При этом dnsmasq продолжит считывать resolv.conf. Что бы отключить это — добавьте no-resolv.

--strict-order

По умолчанию dnsmasq отпрашивает все известные ему апстрим-сервера, и первый, который ответит на запрос становится primary — dnsmasq будет стараться отправить запросы через него. При этом это может быть любой DNS сервер из resolv.conf, resolv.dnsmasq или из списка server в конфиге.

Для того, что бы dnsmasq использовал сервер строго в порядке очереди — добавляем в конфиг опцию strict-order.

Размер кеша dnsmasq

И один из самых интересных вопросов — какой размер кеша стоит устанавливать для dnsmasq?

Значение по умолчанию — 150 записей, максимальное — 10000.

Задаётся с помощью опции cachesize, например:

cachesize=1000

Но как узнать — надо ли его увеличивать?

SIGUSR1

Для этого — можно сдампить всю статистику работы dnsmasq с момента его запуска с помощью сигнала SIGUSR1:

[simterm]

root@bttrm-production-console:/home/admin# pkill -USR1 dnsmasq && cat /var/log/syslog | grep dns | tail -6
Oct 26 10:53:45 localhost dnsmasq[30433]: time 1572076425
Oct 26 10:53:45 localhost dnsmasq[30433]: cache size 150, 0/45516 cache insertions re-used unexpired cache entries.
Oct 26 10:53:45 localhost dnsmasq[30433]: queries forwarded 22241, queries answered locally 633009
Oct 26 10:53:45 localhost dnsmasq[30433]: queries for authoritative zones 0
Oct 26 10:53:45 localhost dnsmasq[30433]: server 10.0.3.2#53: queries sent 11352, retried or failed 0
Oct 26 10:53:45 localhost dnsmasq[30433]: server 1.1.1.1#53: queries sent 46, retried or failed 0

[/simterm]

В котором мы видимо невероятно много полезной информации:

  • time 1572076425 — время с момента запуска сервера в UNIX epoch
  • cache size 150, 0/45516 cache insertions re-used unexpired cache entries — «добавление в кеш с вытеснением записей с неистёкшим временем жизни» — как раз показатель того, что кеша не хватает: если операции добавления новых записей в кеш начинают вытеснять из него записи, у которых ещё не истёк TTL, заданный для домена его SOA (может быть переопределно в помощью --min-cache-ttl для dnmasq) — значит, места в кеше мало
  • queries forwarded 22241, queries answered locally 633009 — количество запросов, не найденных в кеше, и перенаправленных апстриму (возвращается из misses.bind), и кол-во запросов, обработанных самим dnsmasq из кеша (значение из hits.bind)
  • queries for authoritative zones — при использовании dnsmasq в роли SOA, кол-во запросов к authority-зонам
  • server 10.0.3.2#53: queries sent 11352, retried or failed 0 — та самая строка, которая теоретически поможет нам, когда случится очередной «php_network_getaddresses: getaddrinfo failed: Temporary failure in name resolution» — можно будет увидеть, были ли ошибки от AWS VPC DNS

AWS «Temporary failure in name resolution»

Пока писал этот пост — как раз проскочило несколько ошибок.

Выглядит это так:

При этом в дампе dnsmasq всё по-прежнему отлично:

[simterm]

root@bttrm-production-console:/home/admin# pkill -USR1 dnsmasq && cat /var/log/syslog | grep dns | tail -6
Oct 26 11:12:36 localhost dnsmasq[30433]: time 1572077556
Oct 26 11:12:36 localhost dnsmasq[30433]: cache size 150, 0/49227 cache insertions re-used unexpired cache entries.
Oct 26 11:12:36 localhost dnsmasq[30433]: queries forwarded 24327, queries answered locally 724600
Oct 26 11:12:36 localhost dnsmasq[30433]: queries for authoritative zones 0
Oct 26 11:12:36 localhost dnsmasq[30433]: server 10.0.3.2#53: queries sent 12949, retried or failed 0
Oct 26 11:12:36 localhost dnsmasq[30433]: server 1.1.1.1#53: queries sent 590, retried or failed 0

[/simterm]

Ошибок от VPC DNS нет, кеша хватает — всё нормально.

Зато — явно видно проседание по кол-ву отправленных пакетов (график за день):

И полученных:

И что бы это значило? При этом все сервисы работают нормально — проблемы наблюдаются только с DNS-запросами.

Пока не ясно, но в целом — проблема, судя по всему, не с DNS вообще, и не dnsmasq в частности.

Наблюдаем дальше.

Ссылки по теме