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 в частности.

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

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