Урок наблюдаемости
Траление через мусор
Мы привыкли вызывать print () для отладки кода, предназначенного для разовых школьных проектов и MVP. Со временем мы сможем оценить полезность специализированных регистраторов и отладчиков, но привычки к неструктурированному ведению журнала переходят в производственную среду. И когда-нибудь он тебя сильно укусит ...
Меня это укусило, когда я исследовал свою первую ошибку в производстве в Klinify. Что-то пошло не так с большим запросом, сработали таймауты по всем направлениям, и интерфейс начал рассылать спам по тому же запросу. Это перегрузило Backend и вызвало проблемы с производительностью. Наша производственная инфраструктура распределена по виртуальным машинам, управляемым Azure службам и кластеру Kubernetes. Azure Log Analytics (ALA) был предпочтительным инструментом при просмотре журналов, заполняющих около нескольких сотен строк в секунду.
Я боролся с ALA, пытаясь сузить свой запрос, чтобы найти проблемные строки. Было несколько проблем, которые делали процесс сложным, утомительным, медленным и неточным:
- Журналы из разных сервисов имели разную структуру, и никто этого не задокументировал.
- Было трудно различить службу источника записи в журнале. Единственный способ сделать это - посмотреть на идентификатор, присвоенный модулю AKS, у которого не было имени изображения!
- Как только запрос попадает в серверную часть и перемещается от сервиса к сервису, понимание причинно-следственной связи становится затруднительным. Это была дикая игра - проверять временные метки и надеяться, что смещение часов будет минимальным.
- Было много шума. Вам приходилось настраивать каждый запрос, чтобы свести к минимуму ложные срабатывания и ложные отрицания.
TL; DR; это был не самый веселый день для траления бревен.
Почему это случилось
Вы можете подумать: «Что за куча скрабов. Я бы исправил проблему с логированием, пока она не стала такой серьезной! " Я сомневаюсь. Если это то, что вы видите в своей организации, то потому, что в какой-то момент это тоже их укусило. Поздравляю. Тем не менее, стоит изучить, почему это происходит в первую очередь.
Сценарий является проявлением технического долга. Это подкрадывается к вам, потому что они никогда не были главным приоритетом в команде инженеров. Такие проблемы не случаются через день, поэтому я мог бы исправить ошибку и двинуться дальше. И я бы боялся того дня, когда мне снова придется заниматься тралом. Это не очень привлекательные проекты, которые имеют наибольшую рентабельность инвестиций на вашем DevX. Теперь, когда наша команда Backend имела дополнительную огневую мощь (также известную как я), мы могли позволить себе сосредоточиться на этом. В остальной части статьи описаны шаги, которые мы предприняли для достижения этой цели.
Стандартизируйте структуру журнала
Я вставил структуру журнала Klinify из нашей внутренней вики. Мы собираемся распаковать его части ниже и следовать рассуждениям. Я хочу, чтобы вы вынесли отсюда вывод, что очень важно, чтобы все ваши журналы по всем направлениям выглядели одинаково. Таким образом, вы будете точно знать, какие поля извлекать, а какие фильтровать в вашем запросе.
{
"level": "INFO",
"timestamp": "2021-06-30 02:51:31,310",
"process": 20,
"thread": 139739621476096,
"message": "Request received",
"name": "ResponseAction",
"funcName": "_log_incoming_request",
"pathname": "/app/./ResponseAction.py",
"content": {
... // dict values passed into logger will be inserted here
},
"request_trace": {
"request_id": "MzA5MjAzLTE2MjUwMjU2ODA2NTI=",
},
"pod_metadata": {
"service": "klinify-proxy",
"pod": "klinify-proxy-76689c6458-584j8",
"version": "v2.13.1",
"hash": "d949e2a"
},
"exc_info": "..."
}Определите соглашения о ведении журнала
Разработчикам необходимо точно знать, что регистрировать. Оставив это решение полностью разработчикам, мы делаем 2 вещи:
- Это создает умственные издержки, потому что им нужно решить, что включить / исключить.
- Это увеличивает шанс пропустить важные строки и включить ненужные.
Включите в свою внутреннюю документацию некоторые приблизительные практические правила. Ниже приводится выдержка из наших документов. Ваши точные соглашения будут зависеть от вашего контекста:
When to Log -----------A Service can log data to record one or more of the following: An intention to do something (eg. going to send a response) Successful completion of some activity (eg. received a request / updated the db) Failure to complete an activity (eg. error while saving to db) The state of the app at a certain point. (eg. result of an intermediate computation)Do not log PII, except as DEBUG logs. Watch for them in URL params, responses, queries. Do not log passwords or secrets. Be sure to scrub them from URLs and headers. Don't even log them as debug logs. Log exceptions where it happens (e.g. do LOGGER(“exception”, {“message”:”…”}) within the try/except block)You must always log: All requests to Services All responses by Services When a service has initialized successfully when a service is shut down When a service fails to do the main thing it’s supposed to do, and there was no backup plan.For all logs other than the above, ask yourself: When will I search for this log? This will typically be for troubleshooting something. If you don't have a clear answer, don't log. What information will I need when I search for this log? Make sure you provide those in the log. Do I want an alert every time the code reaches this state? Log, and set up the alert on Azure. What problems can I not fix if I don't log this? If the information from this log can be inferred from other logs/data easily, then don't log. Am I building a new feature and I need to watch the logs to make sure it’s working fine? Add debug logs, and remove them once the feature stabilizes.
Другой пример решений, которые вам необходимо принять, - это то, для чего следует использовать каждый из ваших уровней (ИНФОРМАЦИЯ / ПРЕДУПРЕЖДЕНИЕ / ОШИБКА / КРИТИЧЕСКИЙ).
После того, как вы укажете и реализуете свои соглашения, траулер сможет сделать определенные предположения и сократить время обнаружения ошибки.
Свяжите вместе свои журналы
Вам необходимо включить механизм для этого, особенно если ваша архитектура ориентирована на службы. Все наши запросы - как от клиентов, так и от внутренних служб - помечаются x-klinify-request-id и регистрируются под request_trace.request_id. Теперь, когда нам нужно исследовать определенный запрос, мы фильтруем его request_id, и цепочка причинно-следственных связей появляется прямо перед нами.
Включить метаданные для быстрых фильтров
Pod_metadata сообщает вам, из какой службы и модуля ведется журнал, в какой версии находится модуль и хеш фиксации. Если у вас есть ошибка, вы знаете версию кода, на которую нужно обратить внимание, что полезно во время скользящих выпусков. Вы также узнаете, проявляется ли ошибка в конкретном модуле (это может быть OOM и неравномерное распределение нагрузки).
Чтобы добавить их, мы потребовали использовать теги git. Затем вы можете написать сценарии оболочки или интегрировать метаданные в конвейеры CI / CD, чтобы внедрить их в модуль. Например, это отображается в наших файлах Dockerfiles:
ARG COMMIT_REF
ENV COMMIT_REF=${COMMIT_REF}
ARG COMMIT_HASH
ENV COMMIT_HASH=${COMMIT_HASH}И это отображается в наших файлах развертывания K8s:
...
- name: MY_SERVICE_NAME
valueFrom:
fieldRef:
fieldPath: metadata.labels['app']
- name: MY_POD_NAME
valueFrom:
fieldRef:
fieldPath: metadata.name
...Определите библиотеку журналов
Вместо того, чтобы изобретать колесо для каждой службы, вы должны определить библиотеку ведения журналов. Библиотека должна обеспечивать соблюдение требований к ведению журнала и позволять очень легко делать правильные вещи. Вот как мы используем нашу библиотеку журналов в базе кода:
from klinify_core.klinify_logger import get_klinify_logger LOGGER = get_klinify_logger("custom_name")LOGGER("info", {"message": "human readable string, mandated by internal standards", "otherKeys": "otherValues that go into .content field"})
Вот и все! Библиотека обрабатывает все метаданные, структурирование, проверку и т. Д.
Уменьшить шум
Большая часть вашего шума к этому моменту должна исчезнуть, если ваши условные обозначения хорошо определены, но на это стоит взглянуть еще раз. Просмотрите свои журналы и посмотрите, какие строки вам вообще не нужны. Брось их. Например, мы сделали простое исправление - не регистрировать uwsgi 2xx / 3xx. Это сократило объем нашего журнала и сэкономило нам немало денег! Все, что потребовалось, это следующие 3 строчки в нашем uwsgi.ini:
disable-logging = true
log-4xx = true
log-5xx = trueОпределить многоразовые запросы
Вы можете хранить функции прямо там, где вы запрашиваете свои журналы, или в своей вики для легкого копирования и вставки. Определите наиболее распространенные запросы для повторного использования. Не изобретайте велосипед каждый раз, когда вам нужно перебирать бревна.
Полученные результаты
- Я больше не боюсь траловых журналов. Так как мне не нужно бороться с моими инструментами, это на самом деле стало довольно забавным.
- Вы чувствуете себя бэтменом, потому что можете быстро собрать улики.
- Время устранения проблемы резко сократилось. У нас была возможность протестировать новую структуру ведения журнала во время простоев.
Теперь, когда вы вооружены этой мудростью, я надеюсь, что ваше путешествие по тралению бревна будет намного более гладким, чем у меня. Взгляните на свою кодовую базу под новым углом. Что можно улучшить?
Особая благодарность Яо Вэй за большую часть работы над этой проблемой и облегчение моей работы!
