1. Восстановление событий
Вчера днем я получил сигнал тревоги 504, который, очевидно, является сигналом тайм-аута. В то время из-за того, что под рукой были другие вещи, мне было все равно, поэтому я просто взглянул на это, но способ вызова тревоги был очень знакомым, он был написан мной, и первая реакция была немного удивлена. .
Удивившись, продолжайте заниматься своими делами.
Через час я снова получил тот же сигнал тревоги, очевидно, не случайно, должно быть что-то не так, поэтому я начал расследование.
Интерфейс аварийного сигнала — это интерфейс getControllerAMethod уровня контроллера ControllerA, который вызывает несколько микросервисов и, наконец, собирает данные результата для возврата. Проблема заключается в ServiceM.Логика метода getServiceMMethod в сервисе ServiceM также очень проста, в основном это два запроса к базе данных, выборка данных из базы данных MySQL и возврат их вызывающей стороне.
Цепочка вызовов показана на следующем рисунке.
2. Знакомство с окружающей средой
**Язык:**Перейти
**БД:**MySQL
**Взаимодействие с базой данных: **database/sql (Компания сделала некоторые настройки и упаковки на этой основе, и суть в базе данных/sql)
Ниже описан конкретный процесс устранения неполадок для этой проблемы.
3. Инстинктивная реакция: начните с оператора sql
Получите сигнал тревоги из информации о сигнале тревоги и соответствующих сведений журнала, это проблема тайм-аута.
Первая реакция - проверить, является ли оператор sql медленным запросом (хотя я знаю, что вероятность этого крайне мала), оператор sql очень прост, в виде
select a, b, c from tableA where a in (a1,a2,a3)
Известно, что в индекс можно попасть, не глядя на план выполнения.
Но я все же посмотрел план выполнения и реальную ситуацию с выполнением.Результаты анализа и время отклика весьма впечатляют, и проблем нет.
Исследование инстинктивной реакции настолько скучно, что начинается следующий этап исследования.
4. Предварительное расследование: исчерпано ли время контекста
Поскольку это проблема тайм-аута, это может быть тайм-аут восходящего или нисходящего потока.Первый шаг устранения неполадок исключил возможность тайм-аута нисходящего потока, вызванного медленными запросами.
Может ли это быть тайм-аут восходящего потока? Очевидно, это возможно, ведь мы знаем, что контекст Go может передаваться полностью, и все вызовы службы разделяют установленную общую квоту времени.
Более того, из приведенного выше рисунка видно, что ServiceM также является последним шагом восходящего интерфейса, поэтому, если вышеуказанный сервис занимает слишком много времени, квота времени ServiceM будет сжата, и останется немного.
Однако из проверки журнала можно обнаружить, что на уровне ServiceM метод getServiceMethod соответствует sql-запросу, который возвращается почти через десятки миллисекунд.
Из этой ситуации это не похоже на тайм-аут, вызванный недостаточным временем восходящего потока.
5. Предварительное нисходящее расследование: главным подозреваемым становятся скандалы
Поскольку временная квота в восходящем направлении достаточна, существует высокая вероятность того, что проблема заключается в интерфейсе службы в нисходящем направлении.
Поэтому я начал внимательно читать код метода getServiceMMethod.Ниже приведен псевдокод реализации кодовой функции.
rows, err = db.query(sql1)
if err != nil {
...
}
defer rows.Close()
for rows.Next() {
rows.scan(...)
}
rows, err = db.query(sql2)
if err != nil {
...
}
defer rows.Close()
for rows.Next() {
rows.scan(...)
}
Прочитав код, я начал немного волноваться, я думаю, что это правильно, это, вероятно, проблема со строками.
В разделе «Изучение компонентов Go — правильно ли вы использовали пул соединений с базой данных / базой данных sql» я в основном представил ямки, вызванные тем, что строки не закрывались нормально. Поэтому я начал думать, не было ли это из-за того, что соединение с базой данных не было должным образом закрыто в процессе обхода строк, что привело к утечке соединения, чтобы последующие запросы не могли получить соединение и приводили к тайм-ауту.
Я четко проанализировал причину, но каков конкретный шаг в дополнение к проблеме? Единственное, о чем я могу думать, это то, что два запроса здесь используют один и тот же объект строк. Есть ли какая-то ситуация, которая вызвала соединение закрыто в предыдущий раз? Что, если запрос напрямую использует закрытое соединение и время ожидания истекло?
В это время тревоги становились все более и более частыми, поэтому два запроса здесь были изменены с исходной одной строки на получение и закрытие двух строк соответственно, а затем код был отправлен, и тест перешел в режим онлайн после прохождения тестовое задание.
6. Временное затишье
После того, как код был запущен, эффект был незамедлительным.
Тревога сразу прекратилась, в журнале больше не было информации о тайм-ауте, и все вернулось к прежнему спокойствию, что убедило меня в том, что я должен был найти причину и решить проблему.
После возвращения домой мне было еще немного не по себе.С 11:00 я достал свой компьютер и начал моделировать, проверять и восстанавливать причину срабатывания сигнализации.
7. Через три часа осознайте, что спокойствие может быть иллюзией
С 11 до 2 часов, в течение трех полных часов, я не только не нашел причину, но и обнаружил, что мое решение может не решить проблему.
Потому что рассматриваемый код не сложный, как показано выше, то есть всего два запроса Select.
Поэтому я написал тот же фрагмент кода для локального тестирования, и после запуска не было тайм-аута или сбоя соединения. Даже если я установлю для maxConn и IdleConn значение 1, тайм-аута не будет.
Если, как упоминалось в статье «Изучение компонентов Go - пул соединений с базой данных/sql, правильно ли вы его используете», если вы выйдете в начале процесса row.Next() и нет оператора rows.Close(), он будет вызвать следующий запрос не может получить соединение, то есть, как показано в следующем коде
func oneConnWithRowsNextWithError() {
db, _ := db.Open("mysql", "root:rootroot@/dqm?charset=utf8&parseTime=True&loc=Local")
db.SetMaxOpenConns(1)
rows, err := db.Query("select * from test where name = 'jackie' limit 10")
if err != nil {
fmt.Println("query error")
}
i := 1
for rows.Next() {
i++
if i == 3 {
break
}
fmt.Println("close")
}
row, _ := db.Query("select * from test")
fmt.Println(row, rows)
}
Но в исходном коде есть метод defer rows.Close(), соединение в конце концов обязательно закроется, и утечки памяти не будет.
В этот момент я подумал о законе Мерфи (потому что он на самом деле не решил проблему, проблема возникла снова).
Итак, я снова начал парсить исходный код в сочетании с логами и нашел важную подсказку, что многие задачи запросов были активно отменены. Верно, эта отмена — это отмена, возвращаемая context.Timeout (этот код представляет собой богатые функции нашей компании, основанные на базе данных/sql).
Условие, вызванное отменой, заключается в том, что метод QueryContext в базе данных/sql возвращает ошибку
// QueryContext executes a query that returns rows, typically a SELECT.
// The args are for any placeholder parameters in the query.
func (db *DB) QueryContext(ctx context.Context, query string, args ...interface{}) (*Rows, error) {
var rows *Rows
var err error
for i := 0; i < maxBadConnRetries; i++ {
rows, err = db.query(ctx, query, args, cachedOrNewConn)
if err != driver.ErrBadConn {
break
}
}
if err == driver.ErrBadConn {
return db.query(ctx, query, args, alwaysNewConn)
}
return rows, err
}
Первая реакция — недостаточно времени восходящего потока, что напрямую вызвано отменой контекста, но эту причину мы исключили ранее.
Поэтому я перевернул этот код на несколько слоев, и однажды заподозрил, что параметр в нашем собственном коде под названием QueryTimeout был настроен слишком маленьким, но взглянул на конфигурацию (этот взгляд очень важен, я расскажу о нем позже), и обнаружил, что 800мс, видимо, достаточно.
С все новыми и новыми вопросами я неохотно пошел спать.
8. Закон Мерфи все еще в силе
Сегодня днем в 1:00 я снова получил это знакомое оповещение, которое всегда приходит (но получило только одно оповещение).
Как упоминалось ранее, эта отмена может быть важной частью информации, поэтому причина проблемы в том, что она не запустилась, это должно быть из-за тайм-аута, а тайм-аут может быть из-за того, что соединение не может быть установлено.
Поскольку getServiceMMethod был проверен, утечки соединения нет, но будут ли утечки в других местах? Поэтому я проверил весь код службы ServiceM и проверил, нормально ли закрывается код, использующий объект rows.
После расследования надежда рухнула.
До сих пор я исключил проблему утечки связи в моем сердце.
В этот период я также обращался к нашему БД, т. к. пролистал лог, и было несколько запросов в сотни миллисекунд около 8:00 сегодня утром, что, как подозревали, было вызвано нештатным состоянием БД. Администратор баз данных ответил мне, что база данных очень нормальная.
Мониторинг тоже проверял сам, по сравнению с предыдущими днями в статусе БД нет аномального трафика, нет больших взлетов и падений количества пулов подключений.
Мой коллега сказал, что несколько дней назад были введены новые функции, и их количество было больше, чем раньше, поэтому я также посмотрел код, соответствующий новым функциям, и не обнаружил проблем.
9. Подготовьтесь к «кривой, чтобы спасти страну»
Первопричина того, что я хочу, не найдена, поэтому я начал интересоваться, есть ли другие способы обойти эту неизвестную проблему. Ведь лучший способ решить проблему — не решать ее (по-другому).
Подготовьтесь к увеличению времени ожидания метода ServiceM.
Он также готов добавить кеш в метод getServiceMMethod службы ServiceM, чтобы сопротивляться части объема запроса через кеш.
Хорошо, все, давайте завтра попробуем эти два трюка.
Итак, я приготовился встать и передвигаться, и, кстати, я мысленно подвел итоги этой тревоги.
10. С идеей я нашел истину
Предупреждение восходящего потока, тайм-аут нисходящего потока ->
Исключить недостаточно времени вверх по течению ->
Исключить незакрытые нижестоящие строки ->
Исключить нестабильный статус базы данных ->
Определено время ожидания нисходящего потока ->
Подозревается, что невозможно установить соединение ->
Не могу установить соединение, не могу установить соединение, не могу установить соединение
Итак, я пошел читать конфигурацию параметров базы данных, чуть выше, чтобы прочитать параметр QueryTimeout, я смутно помню, что настройка пула соединений здесь невелика. Перейдите к конфигурации и прочитайте ее, idleConn=X, maxConn=Y.
Взглянув еще раз на мониторинг QPS метода getServiceMMethod, я думаю, что нашел истину.
С раннего утра до 8:00 QPS рос, примерно до 8:00, пробив Y, и maxConn=Y.
Таким образом, оно должно быть больше, чем maxConn, чтобы последующие задачи запроса не могли получить соединение и могли только ждать.После ожидания периода ожидания соединение все еще не установлено, поэтому срабатывает упомянутая выше отмена, что также вызывает тайм-аут алармы, видимые в восходящем потоке, как Service M. Метод getServiceMM выполняется с тайм-аутом, потому что он ждал.
Так почему же тревога не продолжалась, когда на рисунке было больше Y. Я так понимаю, что за этот период другие задачи выполнили задачу запроса и поместили соединение обратно в пул соединений, а последующие запросы можно использовать Ведь будет еще одно Окно ожидания периода тайм-аута.
Так почему такого рода будильник не появлялся раньше?Я так понимаю, что раньше сумма была относительно небольшой.Недавно мой коллега запустил новую функцию, что привело к увеличению количества обращений к этому интерфейсу, что высветило эту проблему.
11. Резюме
На самом деле, последняя причина может быть очень простой, то есть количество настроенных подключений невелико, в результате чего последующие задачи запроса не могут получить тайм-аут подключения.
Однако этот тайм-аут распространяется от уровня контроллера до уровня службы и нижнего уровня БД, и каждый уровень может вызвать тайм-аут, поэтому устранить неполадки относительно сложно.
Вот несколько ретроспективных моментов
- Недавно измененный код требует особого внимания. Если будильника давно не было, а новый код сработал недавно, есть большая вероятность, что это как-то связано с запуском (на самом деле этот тайм-аут связан с вновь запущенным кодом. Хотя сам код без проблем, трафик стал больше после нового запуска)
- Хорошо используйте инструменты. Используйте системные инструменты, такие как мониторинг и ведение журнала, чтобы найти полезные подсказки и связи.
- Устранение неполадок и отслеживание сверху вниз. Ошибки, которые нелегко обнаружить, можно проверять, проверять и устранять в определенном порядке, например в последовательности вызовов, до тех пор, пока не будет найдена причина.
Личный публичный аккаунт JackieZheng, добро пожаловать на внимание~