Привет, меня зовут Иван, я занимаюсь бэкенд-разработкой в Ozon — пишу микросервисы для личного кабинета продавца. Сегодня я расскажу небольшую историю проблемы, вызванную неправильной настройкой пула соединений: что случилось, как мы это обнаружили и как исправлять такие проблемы в микросервисах на Go.
Проблема скрывалась внутри нашего API Gateway. Это сервис, который реализует паттерн “Фасад” и предоставляет единственное торчащее наружу окно к микросервисам.
В упрощенном виде его работу можно представить так:
Иллюстрация работы API Gateway
{err_type: context.deadlineExceededError, err: context deadline exceeded}
{err_type: *errors.errorString, err: context canceled}
Трейсы в Jaeger показали ровно такую же картину — мы не дожидались ответа от сервиса аутентификации за 2 секунды. Поэтому между нами и разработчиками сервиса аутентификации произошёл примерно такой диалог:
Скриншот с множеством ошибок Cancelled by client
Итого, мы имеем:
$ ss -natp state time-wait | awk '{print $4}' | sort -nr | uniq -c | sort -nr | head
1053 10.20.49.117:80
1030 10.20.49.92:80
1016 10.20.49.91:80
1014 10.20.54.129:80
1013 10.20.53.213:80
1008 10.20.53.173:80
969 10.20.53.172:80
Эта команда показывает количество TCP-сокетов в состоянии TIME_WAIT до разных удалённых портов. Если коротко, то состояние TIME_WAIT — это де-факто закрытое клиентом соединение. Linux по возможности предотвращает повторное использование этих пар на протяжении 60 секунд, чтобы защититься от того, что старые пакеты помешают вновь установленному TCP-соединению.
Но для нас важно другое. Само существование TCP-соединения означает, что соединение установилось и закрылось. Если такая ситуация происходит массово, то мы имеем дело с накладными расходами на DNS-резолвинг и установку соединения. В результате этого время HTTP-запроса может увеличиваться. Избежать эту проблему помогают пулы соединений. В Go для этой цели используется абстракция http.Transport.
Здесь мы вплотную приближаемся к истокам проблемы. Мы для всех клиентских запросов использовали http.DefaultTransport. Он обладает следующими параметрами:
var DefaultTransport RoundTripper = &Transport{
Proxy: ProxyFromEnvironment,
DialContext: (&net.Dialer{
Timeout: 30 * time.Second,
KeepAlive: 30 * time.Second,
}).DialContext,
ForceAttemptHTTP2: true,
MaxIdleConns: 100,
IdleConnTimeout: 90 * time.Second,
TLSHandshakeTimeout: 10 * time.Second,
ExpectContinueTimeout: 1 * time.Second,
}
Среди перечисленных выше параметров к настройке пула соединений имеют отношения два:
При этом если MaxIdleConnsPerHost не указан, тогда используется значение по умолчанию:
const DefaultMaxIdleConnsPerHost = 2
Поскольку мы использовали именно http.DefaultTransport для всех запросов, мы получили следующую проблему.
Представим, что нам одновременно понадобилось установить 10 соединений до сервиса аутентификации. Тогда хотя бы для 8 из них будут открыты и вскоре тут же закрыты TCP-соединения, из-за ограничения MaxIdleConnsPerHost. Если такая ситуация будет повторяться часто, у нас будет больше накладных расходов на один HTTP-запрос, поскольку для него понадобится новое соединение. Из-за этого вероятность таймаутов возрастает.
result := http.DefaultTransport.(*http.Transport).Clone()
result.MaxIdleConnsPerHost = result.MaxIdleConns
return result
}
График response time обращения к сервису аутентификации
Тут видно значительное уменьшение 0.99-квантиля по времени обращения графиков (голубой цвет) — с 2-3 секунд до менее 300 миллисекунд. Должен признать, даже после этого мы изредка видели таймауты при обращении к сервису аутентификации. Но теперь мы хотя бы видели эти же таймауты на графиках другого сервиса.
Я считаю так: настройки по умолчанию имеют смысл в том случае, когда мы имеем дело с множеством хостов и не очень большим числом запросов. В таком случае значение MaxIdleConnsPerHost предохраняет нас от того, чтобы в ситуации всплеска запросов один из хостов исчерпал оставшийся ресурс свободных соединений и не позволил другому сервису создать хотя бы одно долгоживущее соединение.
Если бы приложения могли говорить...
Чтобы лучше понять предназначение параметра MaxIdleConnsPerHost, представим, что компоненты системы научились говорить друг с другом. Тогда если бы мы выставили значение MaxIdleConnsPerHost равным MaxIdleConns, между нашим приложением и пулом соединений мог бы произойти такой диалог:
Источник статьи: https://habr.com/ru/company/ozontech/blog/561790/
Проблема скрывалась внутри нашего API Gateway. Это сервис, который реализует паттерн “Фасад” и предоставляет единственное торчащее наружу окно к микросервисам.
В упрощенном виде его работу можно представить так:
- Проверить аутентификацию и авторизацию с помощью HTTP-запроса в сервис аутентификации
- Спроксировать запрос в нужный сервис, который определяем по пути и методу запроса пользователя
Конец декабря – время роста нагрузок и числа ошибок
Настал конец декабря. Вместе с ним к нам в поддержку стали приходить вот такие обращения:Ошибки возникали на стороне API Gateway. Мы полезли в логи за подробностями и увидели ошибки, похожие на таймауты обращения к сервису аутентификацию:
{err_type: context.deadlineExceededError, err: context deadline exceeded}
{err_type: *errors.errorString, err: context canceled}
Трейсы в Jaeger показали ровно такую же картину — мы не дожидались ответа от сервиса аутентификации за 2 секунды. Поэтому между нами и разработчиками сервиса аутентификации произошёл примерно такой диалог:
В качестве подтверждения своей правоты, разработчики сервиса аутентификации скинули нам скриншот логов. На нём видно много ошибок об отмене запроса со стороны вызывающей стороны:
Итого, мы имеем:
- Используемый нами сервис аутентификации стабильно отрабатывает за 200 миллисекунд.
- Многие наши обращения к этому сервису таймаутят за 2 секунды.
Причина проблемы: дефолтные настройки в Go
В это время один из авторов нашего API Gateway отметил, что очень давно заметил аномалию: сервис открывает неожиданно много соединений к удаленным портам. При запуске команды из-под контейнера видно:$ ss -natp state time-wait | awk '{print $4}' | sort -nr | uniq -c | sort -nr | head
1053 10.20.49.117:80
1030 10.20.49.92:80
1016 10.20.49.91:80
1014 10.20.54.129:80
1013 10.20.53.213:80
1008 10.20.53.173:80
969 10.20.53.172:80
Эта команда показывает количество TCP-сокетов в состоянии TIME_WAIT до разных удалённых портов. Если коротко, то состояние TIME_WAIT — это де-факто закрытое клиентом соединение. Linux по возможности предотвращает повторное использование этих пар на протяжении 60 секунд, чтобы защититься от того, что старые пакеты помешают вновь установленному TCP-соединению.
Но для нас важно другое. Само существование TCP-соединения означает, что соединение установилось и закрылось. Если такая ситуация происходит массово, то мы имеем дело с накладными расходами на DNS-резолвинг и установку соединения. В результате этого время HTTP-запроса может увеличиваться. Избежать эту проблему помогают пулы соединений. В Go для этой цели используется абстракция http.Transport.
Здесь мы вплотную приближаемся к истокам проблемы. Мы для всех клиентских запросов использовали http.DefaultTransport. Он обладает следующими параметрами:
var DefaultTransport RoundTripper = &Transport{
Proxy: ProxyFromEnvironment,
DialContext: (&net.Dialer{
Timeout: 30 * time.Second,
KeepAlive: 30 * time.Second,
}).DialContext,
ForceAttemptHTTP2: true,
MaxIdleConns: 100,
IdleConnTimeout: 90 * time.Second,
TLSHandshakeTimeout: 10 * time.Second,
ExpectContinueTimeout: 1 * time.Second,
}
Среди перечисленных выше параметров к настройке пула соединений имеют отношения два:
- MaxIdleConns — число соединений, которое разрешается иметь в состоянии Idle (т.е. открытых TCP-соединений, которые в данный момент не используются);
- IdleConnTimeout — время, через которое закрываются такие неактивные соединения.
При этом если MaxIdleConnsPerHost не указан, тогда используется значение по умолчанию:
const DefaultMaxIdleConnsPerHost = 2
Поскольку мы использовали именно http.DefaultTransport для всех запросов, мы получили следующую проблему.
Представим, что нам одновременно понадобилось установить 10 соединений до сервиса аутентификации. Тогда хотя бы для 8 из них будут открыты и вскоре тут же закрыты TCP-соединения, из-за ограничения MaxIdleConnsPerHost. Если такая ситуация будет повторяться часто, у нас будет больше накладных расходов на один HTTP-запрос, поскольку для него понадобится новое соединение. Из-за этого вероятность таймаутов возрастает.
Решение: отдельный транспорт с особенными настройками
Чтобы решить проблему, мы сделали следующее:- Выделили отдельный транспорт под сервисы аутентификации и авторизации, чтобы транспорт под сервис аутентификации не вытеснял остальные сервисы.
- Утилизировали выделенный пул на полную — сделали так, чтобы значение MaxIdleConnsPerHost соответствовало значению MaxIdleConns:
result := http.DefaultTransport.(*http.Transport).Clone()
result.MaxIdleConnsPerHost = result.MaxIdleConns
return result
}
Тут видно значительное уменьшение 0.99-квантиля по времени обращения графиков (голубой цвет) — с 2-3 секунд до менее 300 миллисекунд. Должен признать, даже после этого мы изредка видели таймауты при обращении к сервису аутентификации. Но теперь мы хотя бы видели эти же таймауты на графиках другого сервиса.
Но почему в Go такие настройки по умолчанию?
Возможно, у вас сейчас возник вопрос: зачем делать такие настройки, которые потом приходится исправлять? Неужели разработчики языка Go и библиотек к нему не подумали о том, как это будет использоваться на практике?Я считаю так: настройки по умолчанию имеют смысл в том случае, когда мы имеем дело с множеством хостов и не очень большим числом запросов. В таком случае значение MaxIdleConnsPerHost предохраняет нас от того, чтобы в ситуации всплеска запросов один из хостов исчерпал оставшийся ресурс свободных соединений и не позволил другому сервису создать хотя бы одно долгоживущее соединение.
Если бы приложения могли говорить...
Чтобы лучше понять предназначение параметра MaxIdleConnsPerHost, представим, что компоненты системы научились говорить друг с другом. Тогда если бы мы выставили значение MaxIdleConnsPerHost равным MaxIdleConns, между нашим приложением и пулом соединений мог бы произойти такой диалог:
Разбираемся с непонятными таймаутами в Go: чеклист
Если вдруг вы сталкиваетесь с непонятными таймаутами, попробуйте следующее:- Проверьте метрики по скорости выполнения запросов к сторонним сервисам по HTTP. Если таких метрик нет, заведите – пригодятся.
- Если видите расхождения в таймаутах клиента и сервера, проверьте количество соединений TIME_WAIT.
- Если вы обнаружили много соединений в состоянии TIME_WAIT, это с высокой вероятностью означает, что пул соединений настроен неверно. Обратите внимание на то, что настройки по умолчанию в Go не очень хорошо подходят под большое количество запросов к ограниченному набору сервисов.
- Для хоста с неоправданно большим числом запросов к нему рассмотрите вариант заведения отдельного транспорта.
Что ещё почитать по теме
- Gotchas in the Go Network Packages Defaults: какие ещё подводные камни есть в настройках сети в Golang;
- Coping with the TCP TIME-WAIT state on busy Linux servers: подробнее о TIME_WAIT и зачем оно нужно;
- демо на Github: наглядно об описанной проблеме в миниатюре
Источник статьи: https://habr.com/ru/company/ozontech/blog/561790/