В журналы с головой

Одно из моих первых заданий в компании Amazon, куда я пришел работать после колледжа, заключалось в настройке и запуске веб-сервера amazon.com на настольном компьютере разработчика. Первая попытка оказалась неудачной, и я не мог понять, в чем именно ошибся. На помощь пришел коллега, предложивший проверить журналы. Для этого, как он выразился, нужно было «катнуть файл журнала». Я был уверен, что это розыгрыш или шутка, и не понимал, о каком катании идет речь. В колледже я использовал Linux только для компилирования, управления версиями исходного кода и работы в текстовом редакторе. Поэтому я не знал, что слово «катнуть» происходит от команды cat. С ее помощью можно вывести файл на терминал и загрузить его в другую программу для поиска закономерностей.

Коллеги обратили мое внимание на такие инструменты, как cat, grep, sed и awk. Вооружившись новым набором инструментов, я с головой окунулся в журналы веб-сервера amazon.com на настольном компьютере разработчика. В приложении веб-сервера уже были необходимые инструменты для внесения всевозможной полезной информации в журналы. Благодаря этому я увидел, отсутствие какой настройки мешало запуску веб-сервера, где была вероятность аварийного отключения и где не было обмена данными с последующим сервисом. Сайт состоит из множества перемещающихся элементов и поначалу напоминал мне черный ящик. Но, погрузившись в систему с головой, я научился выяснять, как работает сервер и как взаимодействовать с его зависимостями, просто изучив выходные данные средств контроля.

Предназначение средств контроля

Я работал во многих коллективах Amazon долгие годы и пришел к выводу, что средства контроля – это ценный «микроскоп», под которым мне и коллегам видна работа систем. Но средства контроля полезны не только для изучения систем. Это ключевой элемент операционной культуры в компании Amazon. С помощью прекрасных средств контроля можно понять, какие впечатления получают наши клиенты.
 
Масштабы компании измеряются тем, какое внимание уделяют в ней операционной производительности. Повышение задержки в сервисах, связанных с сайтом amazon.com, ухудшает впечатления клиентов от покупок, а из-за этого падают коэффициенты конверсии. Клиенты, работающие с AWS, зависят от высокой доступности и низкой задержки сервисов AWS.
 
В компании Amazon рассматривают не просто среднюю задержку. Мы уделяем еще более пристальное внимание аномальным показателям задержки, например процентилям 99,9 и 99,99. Дело в том, что если один запрос из 1000 или 10 000 будет выполнен медленно, у клиентов останутся плохие впечатления. Мы обнаружили, что при уменьшении задержки высокого процентиля в системе попутно сократилась и медианная задержка. Но выяснилось также, что уменьшение медианной задержки не так часто приводит к снижению задержки высокого процентиля.
 
Другая причина, по которой мы уделяем большое внимание задержке высокого процентиля, заключается в том, что высокая задержка в одном сервисе может привести к тому, что задержка в других сервисах окажется в несколько раз большей. Amazon построен на принципах сервисно-ориентированной архитектуры. Многие сервисы взаимодействуют друг с другом при выполнении определенных задач, например прорисовке веб-страницы на amazon.com. В результате увеличение задержки сервиса глубоко в цепочке вызова – даже если увеличение наблюдается в высоком процентиле, – оказывает значительное влияние на задержку для конечного пользователя.
 
Большие системы Amazon состоят из множества сервисов, взаимодействующих друг с другом. Каждый сервис разрабатывается и управляется одной командой (большие «сервисы» состоят из многих сервисов или компонентов, работающих «за кулисами»). Команда, владеющая сервисом, называется владельцем сервиса. Каждый специалист такой команды мыслит как владелец и оператор сервиса, будь то разработчик программного обеспечения, сетевой инженер, менеджер или кто-либо другой. В роли владельцев команды устанавливают целевые показатели операционной производительности для всех затрагиваемых сервисов. Мы обеспечиваем также видимость операций сервиса, чтобы можно было добиваться целевых показателей, устранять возникающие проблемы и ставить перед собой еще более высокие цели на следующий год. Чтобы ставить цели и обеспечивать видимость, команды должны оснащать системы средствами контроля.
Кроме того, с помощью средств контроля мы можем оперативно выявлять события, связанные с эксплуатацией, и реагировать на них.
 
Средства контроля передают данные на операционные информационные панели, чтобы операторы могли видеть показатели в режиме реального времени. Они также передают данные в оповещения для операторов, чтобы те обратили внимание на неожиданное поведение системы. Используя подробные выходные данные средств контроля, операторы быстро проводят диагностику и выявляют причину неполадок. После этого можно устранить проблему и предотвратить ее возникновение в будущем. Без хороших средств контроля, охватывающих весь код, мы нерационально тратим драгоценное время на диагностику проблем.

Объекты измерения

Чтобы сервисы работали в соответствии с нашими высокими стандартами доступности и задержки, владельцам сервисов нужно измерять поведение систем.

Чтобы получить необходимые телеметрические данные, владельцы сервисов измеряют операционную производительность во многих точках и затем всесторонне изучают поведение. Эту задачу сложно выполнить даже в простой архитектуре. Рассмотрим сервис, к которому обращаются клиенты через балансировщик нагрузки. Сервис обменивается данными с удаленным кэшем и удаленной базой данных. Нужно, чтобы каждый компонент передавал показатели своего поведения. Нужно также измерить, как каждый компонент воспринимает поведение других компонентов. Объединив всевозможные показатели, владелец сервиса может быстро выявить источник проблем и докопаться до причины.

Многие сервисы AWS автоматически предоставляют важные операционные данные о ресурсах. Например, Amazon DynamoDB передает для Amazon CloudWatch такие результаты измерений, выполненных с помощью сервиса: задержки, коэффициент успешного выполнения и коэффициент ошибок. Но нам нужно гораздо лучше видеть поведение создаваемых систем, в которых используются такие сервисы. Для средств контроля требуется явный код, который будет регистрировать время выполнения задач, частоту выполнения определенных ветвей кода, метаданные о целях задачи и сведения о выполненных и невыполненных частях задач. Если команда не добавит подробно разработанные средства контроля, ей придется управлять своим сервисом «вслепую».

Например, если мы внедрили операцию API сервиса, которая получила информацию о продукте по его идентификатору, код может выглядеть, как в примере ниже. Этот код ищет сведения о продукте в локальном кэше, затем в удаленном кэше, а затем в базе данных:

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // check our local cache
  ProductInfo info = localCache.get(request.getProductId());
  
  // check the remote cache if we didn't find it in the local cache
  if (info == null) {
    info = remoteCache.get(request.getProductId());
	
	localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    info = db.query(request.getProductId());
	
	localCache.put(info);
	remoteCache.put(info);
  }
  
  return info;
}

При управлении этим сервисом нужны многочисленные средства контроля в коде, чтобы понять поведение кода в производственной среде. Нужна возможность решать проблемы с невыполненными или медленно выполняемыми запросами, нужно контролировать тенденции и признаки недостаточного масштаба или неправильного поведения разных зависимостей. Вот тот же код, в примечаниях к которому есть несколько вопросов, на которые нужно ответить. Вопросы касаются либо производственной системы в целом, либо конкретного запроса:

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // Which product are we looking up?
  // Who called the API? What product category is this in?

  // Did we find the item in the local cache?
  ProductInfo info = localCache.get(request.getProductId());
  
  if (info == null) {
    // Was the item in the remote cache?
    // How long did it take to read from the remote cache?
    // How long did it take to deserialize the object from the cache?
    info = remoteCache.get(request.getProductId());
	
    // How full is the local cache?
    localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    // How long did the database query take?
    // Did the query succeed? 
    // If it failed, is it because it timed out? Or was it an invalid query? Did we lose our database connection?
    // If it timed out, was our connection pool full? Did we fail to connect to the database? Or was it just slow to respond?
    info = db.query(request.getProductId());
	
    // How long did populating the caches take? 
    // Were they full and did they evict other items? 
    localCache.put(info);
    remoteCache.put(info);
  }
  
  // How big was this product info object? 
  return info;
}

Код для ответа на все эти (и другие) вопросы немного длиннее, чем фактическая бизнес-логика. Некоторые библиотеки помогают уменьшить объем инструментального кода, но разработчик все равно должен задавать вопросы о видимости, которая понадобится библиотекам, а также предусмотреть подключение средств контроля.

При устранении проблемы с запросом, проходящим через распределенную систему, иногда сложно разобраться в ситуации, если рассматривать запрос только на основе одного взаимодействия. Чтобы собрать пазл, полезно объединить все показатели всех систем. Для этого в каждой системе должны быть средства для записи идентификатора трассировки каждой задачи и его передачи каждому сервису, который участвует в выполнении задачи. Собирать данные в системах по определенному идентификатору трассировки можно либо после произошедшего события, либо почти в реальном времени с помощью такого сервиса, как AWS X-Ray.

Глубокое изучение

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

На самом высоком уровне средства контроля дают возможность получить объединенные показатели, по которым отображаются оповещения на информационных панелях. С помощью таких объединенных показателей операторы могут контролировать общую скорость выполнения запросов, задержку при вызовах сервисов и коэффициенты ошибок. Благодаря оповещениям и показателям выявляются аномалии и изменения, требующие расследования.

После обнаружения аномалии нужно выяснить ее причину. Для ответа на этот вопрос используются показатели, генерируемые дополнительными средствами контроля. Измеряя время, необходимое для различных этапов выполнения запроса, можно увидеть, какой этап выполняется дольше обычного или чаще приводит к ошибкам.

Хотя объединение таймеров и показателей может помочь выявить причины или области для дальнейшего расследования, этого иногда недостаточно, чтобы полностью разобраться в ситуации. Например, показатели могут обозначать определенную операцию API как источник ошибок, но понять причину сбоя операции невозможно без конкретных данных, которые отсутствуют. Сейчас мы рассматриваем необработанные подробные данные журнала, сгенерированные сервисом за соответствующий период. Необработанные журналы указывают на источник проблемы – либо конкретную возникающую ошибку, либо конкретные аспекты запроса, из-за которых возникает нарушение.

Методы измерений

Для средств контроля нужно написать код. Это означает, что при внедрении новых функциональных возможностей нужно внимательно добавить дополнительный код. С его помощью можно будет понимать, что происходит, что выполняется и за какое время, а что не выполняется. Написание кода для средств контроля – это тривиальная задача, поэтому в Amazon с годами выработались методы для распространенных закономерностей: стандартизация общих библиотек средств контроля и стандартизация структурированных отчетов о показателях на основе журналов.

Стандартизация библиотек для средств контроля и получения показателей помогает авторам библиотек демонстрировать клиентам, как работают библиотеки. Например, широко используемые HTTP-клиенты интегрируются с распространенными библиотеками, поэтому если команда сервиса внедряет удаленный вызов к другому сервису, она автоматически получает средства контроля для таких вызовов.

Когда приложение со средствами контроля выполняет работу, полученные телеметрические данные записываются в структурированный файл журнала. В общем случае они генерируются как одна запись журнала на «единицу работы», будь то запрос в HTTP-сервис или сообщение, полученное из очереди.

В компании Amazon измерения в приложении не объединены и время от времени передаются в систему объединения показателей. Все таймеры и счетчики для каждого элемента работы записываются в файле журнала. Затем журналы обрабатываются, и уже в другой системе производятся вычисления с использованием объединенных показателей. Таким образом, мы получаем всё – от высокоуровневых объединенных операционных показателей до подробных данных для устранения проблем на уровне запроса – с помощью единственного обращения к коду средств контроля. В компании Amazon сначала создается журнал, а затем генерируются объединенные показатели.

Контроль с помощью журналов

Чаще всего мы оснащаем сервисы средствами контроля для создания двух типов данных журналов: данных запросов и данных отладки. Данные журнала запроса обычно представлены как единая запись структурированного журнала для каждой единицы работы. Эти данные содержат свойства, касающиеся запроса, его автора и цели, счетчики частоты событий и таймеры длительности событий. Журнал запросов используется для аудита, он отслеживает всё происходящее в сервисе. Данные отладки включают неструктурированные или незначительно структурированные данные всех строк отладки, сгенерированных приложением. Обычно это неструктурированные записи журналов, например ошибка Log4j или строки журнала с предупреждениями. В Amazon эти два типа данных обычно записываются в отдельные файлы журналов – не только для учета, но и потому, что журналы с записями в едином формате удобнее анализировать.

Такие агенты, как CloudWatch Logs Agent, обрабатывают данные журналов обоих типов в режиме реального времени и передают журналы в CloudWatch Logs. В свою очередь, CloudWatch Logs генерирует объединенные показатели о сервисе в режиме, близком к реальному времени. Amazon CloudWatch Alarms считывает объединенные показания и создает оповещения.

Хотя могут потребоваться значительные затраты для регистрации такого большого количества информации о каждом запросе, в Amazon считают, что это невероятно важно. В конце концов, нам нужно исследовать случаи уменьшения доступности, пики задержки и проблемы, о которых сообщили клиенты. Без подробных журналов мы не сможем ответить на вопросы клиентов и улучшить обслуживание.  

Изучение подробных сведений

Мониторинг и оповещения – тема достаточно обширная. В этой статье не рассматриваются вопросы установки и настройки порогов для оповещений, организация операционных информационных панелей, измерение производительности на стороне сервера и стороне клиента, постоянное выполнение «канареечных» приложений и выбор правильной системы для объединения показателей и анализа журналов.

Статья посвящена необходимости оснащения наших приложений средствами контроля для получения правильных необработанных данных измерений. В статье также рассказано, что включают команды Amazon в средства контроля приложений (и исключают из них).

Рекомендации для журналов запросов

В этом разделе я опишу рекомендуемые методы ведения журналов структурированных данных «для каждой единицы работы». Об этих методах я узнал за время работы в Amazon. Журнал, который соответствует таким критериям, содержит счетчики частоты возникновения событий, таймеры с информацией о длительности, а также свойства с метаданными о каждой единице работы.

Методы ведения журналов

Одна запись в журнале запросов для каждой единицы работы. Единица работы – это, как правило, запрос, отправленный нашему сервису, или сообщение, полученное из очереди. Мы создаем одну запись в журнале сервиса для каждого запроса, полученного сервисом. Мы не объединяем несколько единиц работы. Таким образом, при устранении проблем с невыполненным запросом мы изучаем единственную запись журнала. Запись содержит соответствующие вводные параметры запроса, на их основе можно понять, какие действия пытались предпринять, кто был оператором, увидеть всю хронику событий и информацию счетчика.
Создание не более одной записи в журнале запросов для одного запроса. При внедрении сервиса без блокировки может показаться удобным создавать отдельную запись в журнале для каждого этапа обработки. Но мы добивались лучших результатов при устранении проблем в таких системах, применяя один «объект показателя» на разных этапах процесса, а затем сериализируя показатели как единицу после выполнения всех этапов. Наличие нескольких записей в журнале для каждой единицы работы затрудняет анализ журнала и во много раз повышает и без того высокие накладные расходы на ведение журналов. Если мы пишем новый сервис без блокировки, то стараемся заранее запланировать жизненный цикл ведения журналов для показателей, поскольку выполнять рефакторинг кода и вносить исправления на более поздних этапах очень сложно.
Разбивка долго выполняемых задач на несколько записей журнала. Эта рекомендация отличается от предыдущей. Если задача, похожая на рабочий процесс, выполняется долго – несколько минут или часов, – мы можем периодически создавать отдельную запись в журнале, чтобы видеть прогресс или замедление.
Запись сведений о запросе перед проверкой и другими процедурами. Мы считаем, что для ведения журналов об устранении проблем и аудите важно собрать достаточно информации о запросе, чтобы было понятно, какие действия планировали выполнить. Мы также обнаружили, что важно регистрировать такую информацию как можно раньше – до возможного отклонения запроса в ходе проверки, аутентификации или применения логики регулирования количества запросов. Если мы регистрируем информацию из входящего запроса, то заносим входящие данные в журнал только после удаления секретных сведений (применяем шифрование, устранение и усечение). Например, мы не включаем в запись журнала сервиса строки размером 1 МБ, переданные оператором. Если мы будем так делать, возникнет риск переполнения дисков, из-за чего будут превышены ожидаемые расходы на хранение журналов. Другой пример удаления секретных сведений – фильтрование управляющих символов ASCII или escape-последовательностей, связанных с форматом журнала. Если оператор передаст собственную запись журнала и сможет добавить ее в наши журналы, это может сбить с толку! Дополнительные сведения: https://xkcd.com/327/.
План внесения в журнал большего объема информации. Для устранения определенных проблем и выявления их причин может быть недостаточно сведений журнала о проблемных запросах. Такая информация может быть доступной в сервисе, но иногда ее объем слишком велик, поэтому постоянное ведение журналов нецелесообразно. Неплохо иметь возможность регулировать объем регистрируемой информации и временно его увеличивать в период изучения проблемы. Такой регулятор можно применять к отдельным хостам или клиентам, а также к частоте выборки в масштабах всего парка. Важно не забывать возвращать регулятор в прежнее положение по окончании работ.
Короткие имена показателей (но не слишком). Сериализация журналов сервисов не меняется в Amazon вот уже больше 15 лет. В сериализации имя каждого счетчика и таймера повторяется в формате обычного текста в каждой записи журнала сервиса. Чтобы свести к минимуму накладные расходы на ведение журнала, мы используем короткие, но содержательные имена таймеров. Amazon начинает внедрять новые форматы сериализации на основе протокола бинарной сериализации Amazon Ion. В конце концов, важно выбрать формат, понятный средствам анализа журналов для максимально эффективного выполнения сериализации, десериализации и хранения.
Убедитесь, что объемы журналов достаточно велики, чтобы справиться с максимальным потоком. Мы проверяем наши сервисы при максимально допустимой нагрузке (или даже более высокой) в течение нескольких часов. Нам нужно убедиться, что при обработке чрезмерного трафика у сервиса будет достаточно ресурсов для отправки журналов на другой сервер с той же скоростью, с которой создаются новые записи журналов. В противном случае диски постепенно заполнятся. Также можно настроить ведение журналов не в корневом разделе файловой системы, чтобы система не вышла из строя в случае чрезмерно интенсивного ведения журналов. Позже мы рассмотрим другие способы смягчения, например использование динамической выборки, пропорциональной потоку. Но тестирование критически важно при любой стратегии.
Изучение поведения системы при заполнении дисков. Когда серверный диск заполнен, на него невозможно записывать журналы. Что в таком случае должен делать сервис? Перестать принимать запросы или удалять журналы и продолжать работу без мониторинга? Работать без ведения журналов рискованно, поэтому мы тестируем системы с целью выявлять серверы с почти заполненными дисками.
Синхронизация часов. В распределенных системах время учитывается очень сложным образом. Мы не полагаемся на синхронизацию часов в распределенных алгоритмах, но она необходима, иначе журналы станут бессмысленными. Для синхронизации часов мы запускаем такие управляющие программы, как Chrony или ntpd, и контролируем серверы для выявления рассинхронизации. Для облегчения этой задачи используется сервис Amazon Time Sync.
Генерирование нулевых счетчиков для показателей доступности. Счетчики ошибок полезны, но процент ошибок тоже полезен. Чтобы измерить «процент доступности», мы применяем следующую полезную стратегию: если запрос успешно выполнен, генерируется 1, если нет – 0. Получившийся в результате «средний» статистический показатель и будет коэффициентом доступности. Намеренное генерирование точки данных 0 может быть полезным и в других ситуациях. Например, если приложение выполняет выбор лидера, периодическое генерирование 1 в период, когда один процесс является лидером, и 0, когда процесс не является лидером, может помочь в мониторинге состояния кандидатов. Таким образом, если процесс перестанет генерировать 0, легче будет узнать о возникшем в нем сбое. Кроме того, такой процесс не сможет прийти на смену лидеру, если с последним что-либо случится.

Сведения, регистрируемые в журнале

Регистрация в журнале сведений о доступности и задержках всех зависимостей. Мы обнаружили, что это особенно полезно при ответе на вопросы «почему запрос выполнялся медленно?» и «почему запрос не был выполнен?». Без такого журнала мы можем только сравнивать графики зависимостей с графиками сервиса и догадываться, привел ли один пик в задержке зависимого сервиса к невыполнению запроса, которое мы расследуем. Многие сервисные и клиентские платформы измеряют показатели автоматически, но другие платформы (например, SDK AWS) требуют оснащения средствами контроля вручную.
Разбивка показателей зависимостей по вызовам, по ресурсам, по коду статуса и т. д. Если мы взаимодействуем с одной зависимостью много раз в одной единице работы, то включаем показатели каждого вызова по отдельности, а также уточняем, с какими ресурсами взаимодействует каждый запрос. Например, при вызове Amazon DynamoDB некоторые команды считали полезным включать показатели времени и задержки для каждой таблицы, каждого кода ошибки и даже каждого номера повторных попыток. Это упрощает устранение проблем, когда сервис замедляется из-за повторных попыток, вызванных непройденными проверками условий. Благодаря этим показателям были также выявлены случаи, когда воспринимаемая клиентом задержка увеличивалась из-за повторных попыток регулировки количества запросов или из-за разбивки набора результатов на страницы, а не из-за потери пакетов или задержки в сети.
Запись глубины очередей памяти при обращении к ним. Если при взаимодействии запроса с очередью мы извлекаем из нее объект или помещаем в нее объект, в этот объект записывается текущая глубина очереди. Для очередей в памяти получение такой информации требует минимальных затрат. Для распределенных очередей эти метаданные могут быть доступны бесплатно в ответах на вызовы API. Такое ведение журналов поможет выявить накопления невыполненных заданий и будущие источники задержек. Кроме того, при извлечении объектов из очереди мы измеряем период, в течение которого они находились в очереди. Это означает, что нам нужно добавить собственный показатель «время помещения в очередь» к сообщению до помещения в очередь.
Добавление счетчика для каждой причины ошибки. Рассмотрим добавление кода, который учитывает конкретную причину ошибки для каждого невыполненного запроса. Журнал приложения будет включать информацию для выявления сбоя, а также сообщение с подробным описанием исключения. Но мы также поняли, что полезно видеть, как меняются со временем причины ошибок в показателях, не выискивая эти сведения в журнале приложения. Удобно начать с отдельного показателя для каждого класса исключения сбоя.
Упорядочение ошибок по категориям причин. Если все ошибки регистрировать в одном показателе, будет много помех и мало пользы. Мы выяснили, что важно как минимум отделять ошибки «по вине клиента» от ошибок «по вине сервера». Может быть полезной и дополнительная разбивка. Например, в DynamoDB клиенты могут создавать запросы с записью при соблюдении условия. Такие запросы возвращают ошибку, если модифицируемый ими элемент не соответствует предварительным условиям в запросе. Эти ошибки не случайны, и мы понимаем, что время от времени они будут возникать. В то же время ошибки «недопустимый запрос» от клиентов обычно относятся к программным, и их нужно устранять.
Занесение в журнал важных метаданных о единице работы. В структурированный журнал показателей мы вносим также достаточный объем метаданных о запросе, чтобы позже можно было определить, от кого он исходил и с какой целью. Клиент, обращающийся к нам для решения проблем, ожидает, что мы храним такие метаданные в журнале. Например, DynamoDB регистрирует в журнале имя таблицы, с которой взаимодействует запрос, и, в частности, метаданные с информацией о том, была ли операция чтения выполнена без ошибок. Но DynamoDB не регистрирует данные, сохраняемые в базе данных или получаемые из нее.
Защита журналов путем контроля доступа и шифрования. Журналы содержат информацию, которая в некоторой степени конфиденциальна, поэтому мы приняли меры для ее защиты. К таким мерам относятся шифрование журналов, предоставление доступа только тем операторам, которые занимаются устранением проблем, а также регулярный пересмотр правил доступа.
Недопущение записи абсолютно конфиденциальной информации в журналы. В журналы приходится записывать информацию, которая в некоторой степени конфиденциальна. В противном случае журналы будут бесполезны. Для компании Amazon важно, чтобы журналы содержали достаточный объем информации для определения источника конкретного запроса. Тем не менее мы не записываем абсолютно конфиденциальную информацию, например параметры запроса, которые не влияют на маршрутизацию или поведение при его обработке. Например, если с помощью кода выполняется синтаксический анализ клиентского сообщения, который завершается неудачей, для защиты конфиденциальности клиента важно не записывать в журнал полезные данные, несмотря на то что это может осложнить устранение проблемы в дальнейшем. С помощью инструментов мы принимаем решения о том, что можно записывать в журналах. Наш принцип таков: нельзя ничего, кроме того, что разрешено, а не наоборот. Таким образом мы не допускаем включения в журнал добавленных позже конфиденциальных параметров. С помощью специальных сервисов, например Amazon API Gateway, можно указать, какие данные нужно включить в журнал доступа. Это неплохой механизм для реализации принципа «нельзя ничего, кроме того, что разрешено».
Занесение идентификатора трассировки в журнал и распространение в серверных вызовах. Для выполнения одного запроса клиента, скорее всего, понадобится взаимодействие многих сервисов. Для многих запросов AWS это может быть два или три сервиса, а для запросов amazon.com – гораздо больше. Чтобы можно было разобраться в произошедшем при устранении проблем с распределенной системой, мы распространяем один и тот же идентификатор трассировки по таким системам. Это дает возможность собрать журналы из разных систем и увидеть, где произошли сбои. Идентификатор трассировки – это разновидность идентификатора мета-запроса. Он помещается на распределенную единицу работы «парадным» сервисом, который начал единицу работы. AWS X-Ray – один из вспомогательных сервисов, способствующих такому распространению в некоторых случаях. Мы обнаружили, что важно передавать трассировку для нашей зависимости. Распространение идентификатора платформой в многопоточной среде сопряжено с большими сложностями и ошибками, поэтому мы завели привычку передавать идентификаторы трассировки и другой контент запросов (в частности, объект показателей!) в наших подписях методов. Мы обнаружили также, что удобно передавать объект Context в подписях наших методов, чтобы не приходилось выполнять рефакторинг при обнаружении аналогичной передаваемой закономерности в будущем. Для команд AWS это не только вопрос устранения проблем в наших системах – клиенты должны устранить проблемы и в собственных. Клиенты ожидают, что трассировки AWS X-Ray передаются между сервисами AWS, когда те взаимодействуют друг с другом в интересах клиента. Для этого мы должны распространять клиентские идентификаторы трассировки AWS X-Ray между сервисами, чтобы они получали полные данные.
Занесение в журнал разных показателей задержки с учетом кода состояния и размера. Ошибки часто возникают быстро. Это могут быть ошибочные ответы при проверке, отказ в доступе и ограничение количества запросов. Если клиент устанавливает высокое значение для ограничения количества запросов, может возникнуть иллюзия хорошего показателя задержки. Чтобы избежать таких помех во время измерений, мы регистрируем показания отдельного таймера для успешных ответов и уделяем большое внимание этому показателю на информационных панелях и в оповещениях, а не используем общий показатель времени. Аналогично, если операция может выполняться медленнее при определенном размере входных данных или ответа, рекомендуется генерировать показатель задержки с учетом категории, например SmallRequestLatency и LargeRequestLatency. Кроме того, мы обеспечиваем ограничение запросов и ответов во избежание сложных режимов понижения производительности и сбоев. Но даже в тщательно разработанном сервисе такая технология пакетных показателей может изолировать поведение клиента и не допускать влияния помех на информационные панели.

Рекомендации для журналов приложений

В этом разделе описаны рекомендуемые методы, обычно используемые в Amazon для записи неструктурированных данных журнала отладок.

Отсутствие спама в журнале приложений. Хотя у нас могут быть записи журнала уровней INFO и DEBUG в пути запроса, что упрощает разработку и отладку в тестовых средах, рекомендуется отключать эти уровни журналов в производственной среде. Вместо того чтобы полагаться на журнал приложений при запросе информации о трассировке, мы рассматриваем журнал сервиса как место для информации о трассировке, где мы можем легко создавать показатели и видеть общие тенденции с учетом времени. Но четких и однозначных правил здесь нет. Наш подход заключается в постоянной проверке наших журналов. Мы смотрим, не слишком ли много в них лишнего (или, может быть, мало лишнего), и корректируем со временем уровни ведения журналов. Например, при подробном изучении журналов мы часто обнаруживаем много лишнего в их записях, а также отсутствие очень нужных показателей. К счастью, улучшения часто не требуют больших усилий, поэтому мы выработали привычку архивировать невыполненные задания при быстром последующем контроле, чтобы журналы оставались чистыми.
Добавление соответствующего идентификатора запроса. При устранении ошибки, указанной в журнале приложения, часто нужно видеть сведения о запросе или операторе, из-за которого возникла ошибка. Если оба журнала содержат один и тот же идентификатор запроса, между ними легко переходить. Библиотеки для ведения журналов приложений будут записывать соответствующий идентификатор запроса при правильной настройке и установленном идентификаторе запроса ThreadLocal. Если приложение многопоточное, нужно внимательно следить за тем, чтобы установить правильный идентификатор запроса, когда поток начнет работать с новым запросом.
Ограничение частоты внесения лишних записей в журнал приложения. Обычно сервис генерирует незначительный объем информации для журнала приложений, но если он вдруг начинает выдавать большой объем ошибок, то возможна регистрация с высокой скоростью очень больших записей журнала с трассировкой стека. Один из наших способов защититься от этого – ограничить частоту внесения записей для определенного средства ведения журнала.
Предпочитаемый формат: строки, а не String#format или конкатенация строк. Более старые операции API журнала приложений принимают однострочное сообщение в отличие от API со строками формата varargs log4j2. Если в коде используются операторы DEBUG, но в производственной среде установлен уровень ERROR, есть риск выполнения напрасной работы – форматирования строк сообщений DEBUG, которые будут проигнорированы. Некоторые операции API для ведения журналов поддерживают передачу произвольных объектов, у которых методы toString() вызываются, только если будет создана запись журнала.
Занесение в журнал идентификаторов запросов от невыполненных вызовов сервисов. В случае вызова сервиса и возврата ошибки сервис, скорее всего, вернет идентификатор запроса. Мы обнаружили, что есть смысл включать идентификатор запроса в наш журнал, чтобы мы могли легко найти соответствующие записи в журнале сервиса, если понадобится связаться с владельцем сервиса. Из-за ошибок тайм-аута эта задача усложняется, так как сервис мог еще не вернуть идентификатор запроса или клиентская библиотека могла еще не выполнить его синтаксический анализ. Но если у нас есть идентификатор запроса, возвращенный сервисом, мы в любом случае вносим его в журнал.

Рекомендации для сервисов с высокой пропускной способностью

Для подавляющего большинства сервисов Amazon ведение журнала с учетом каждого запроса не приводит к неразумному увеличению накладных расходов. Чем выше пропускная способность сервисов, тем меньше предсказуемость, но мы все равно часто регистрируем в журналах все запросы. Например, вполне естественно предположить, что DynamoDB, обслуживающий в пиковые периоды свыше 20 миллионов запросов в секунду только внутреннего трафика Amazon, не вносит в журналы большой объем информации. Но на самом деле он регистрирует все запросы, связанные с устранением неполадок, аудитом и соответствием нормативным требованиям. Ниже приведены некоторые рекомендации высокого уровня, которым следуют в компании Amazon для более эффективного ведения журналов при повышенной пропускной способности из расчета на один хост:

Выборка журналов. Вместо регистрации всех записей можно регистрировать каждую N-ю запись. Каждая запись также содержит сведения о том, сколько записей было пропущено, чтобы системы объединения показателей могли оценить реальный объем журнала в рассчитываемых показателях. С помощью других алгоритмов, например резервуарной выборки, можно получить более репрезентативные данные. Другие алгоритмы присваивают регистрации ошибок или медленных запросов более высокий приоритет, чем регистрации успешных и быстро выполненных запросов. Но в случае применения выборки теряется возможность помогать клиентам и устранять определенные сбои. Некоторые нормативные акты полностью запрещают подобную практику.
Перемещение нагрузки сериализации и ведения журнала в отдельный поток. Это легкое и широко применяемое изменение.
Частая ротация журналов. Ежечасная ротация файлов журналов может показаться удобным способом уменьшить количество файлов, но ежеминутная ротация улучшает несколько аспектов. Например, агент, который считывает и сжимает файл журнала, будет считывать его из кэша страницы, а не с диска, а процессор и устройства ввода-вывода будут загружаться сжатием и отправкой журналов равномерно в течение часа. Не будет пиковой загрузки в конце каждого часа.
Запись журналов с предварительным сжатием. Если агент отправки журналов сжимает их до передачи в архивный сервис, процессор и диск системы периодически испытывают пиковую нагрузку. Эти затраты можно уменьшить, снизив также вдвое количество операций ввода-вывода на диске, если выводить с диска сжатые журналы. Но такой подход сопряжен с некоторыми рисками. Мы обнаружили, что целесообразно использовать алгоритм сжатия, который может работать с усеченными файлами в случае аварийного завершения работы приложения.
Запись на ramdisk/tmpfs. Для сервиса может быть проще записывать журналы в память до тех пор, пока они не будут отправлены с сервера, чем записывать журналы на диск. Наш опыт показывает, что этот подход приносит наилучшие результаты, когда ротация журналов выполняется каждую минуту, а не каждый час.
Объединения в памяти. Если нужно обрабатывать сотни тысяч транзакций в секунду на одном компьютере, может быть слишком дорого регистрировать одну запись журнала на каждый запрос. Но если так не делать, будут упущены возможности наблюдения, поэтому мы считаем целесообразным не проводить оптимизацию преждевременно.
Мониторинг использования ресурсов. Мы следим за тем, насколько близко подходим к пределу масштабирования. Мы измеряем количество операций ввода-вывода на сервер и нагрузку процессора, а также количество ресурсов, потребляемое агентами ведения журналов. Мы выполняем тесты нагрузок в течение достаточно длительных периодов. Таким образом мы знаем, смогут ли агенты отправки журналов справиться с нашей пропускной способностью.

Наличие нужных средств для анализа журналов

В компании Amazon мы управляем собственными сервисами, поэтому нам приходится хорошо разбираться в устранении проблем. Это подразумевает умение легко анализировать журналы. В нашем распоряжении есть множество средств, от анализа сравнительно небольшого количества локальных журналов до анализа распределенных журналов для сортировки и объединения результатов, полученных из огромного объема журналов.

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

Анализ локальных журналов

Для анализа журналов может понадобиться опыт работы с различными утилитами командной строки Linux. Например, распространенная команда «найти в журнале IP-адреса наиболее активных пользователей сети» – это просто:

cat log | grep -P "^RemoteIp=" | cut -d= -f2 | sort | uniq -c | sort -nr | head -n20

Но есть ряд других инструментов, полезных для ответа на более сложные вопросы о наших журналах, в частности:

• jq: https://stedolan.github.io/jq/
• RecordStream: https://github.com/benbernard/RecordStream

Анализ распределенных журналов

Любой сервис для аналитики больших данных можно использовать для анализа распределенных журналов (например, Amazon EMR, Amazon Athena, Amazon Aurora и Amazon Redshift). Но некоторые сервисы оснащены системами ведения журналов, например Amazon CloudWatch Logs.

CloudWatch Logs Insights
• AWS X-Ray: https://aws.amazon.com/xray/.
• Amazon Athena: https://aws.amazon.com/athena/.

Выводы

Будучи владельцем сервиса и разработчиком программного обеспечения, я провел колоссальное время за анализом результатов средств контроля – графиков на информационных панелях и отдельных файлов журналов, а также за работой с такими инструментами для анализа распределенных журналов, как CloudWatch Logs Insights. Вот некоторые из моих любимых занятий. Когда мне нужен перерыв после завершения сложной задачи, я восстанавливаю силы и с головой окунаюсь в анализ журналов – для меня это как приз. Я начинаю с вопроса «почему здесь у показателя пиковое значение?» или «могла ли задержка этой операции быть ниже?». Когда вопросы заводят в тупик, я часто понимаю, что некоторые измерения были бы полезны в коде, поэтому добавляю средства контроля, выполняю тест и отправляю пересмотренный код коллегам.

Хотя многие управляемые сервисы, которые мы используем, уже содержат целый ряд показателей, нам нужно основательно изучать оснащение собственных сервисов средствами контроля, чтобы добиться необходимой видимости для эффективной эксплуатации. Во время событий, связанных с эксплуатацией, нам нужно быстро определить, почему возникает проблема и что можно предпринять для ее устранения. Для быстрой диагностики крайне важно видеть необходимые показатели на информационных панелях. Кроме того, мы постоянно меняем наши сервисы, добавляем новые функции и способ их взаимодействия с зависимостями. Поэтому обновление и добавление нужных средств контроля продолжается бесконечно.

• “Look at your data”, John Rauser, бывший сотрудник Amazon: https://www.youtube.com/watch?v=coNDCIMH8bk (особенно 13:22, где он распечатывает журналы, чтобы лучше их изучить)
• “Investigating anomalies”, John Rauser, бывший сотрудник Amazon: https://www.youtube.com/watch?v=-3dw09N5_Aw
• “How humans see data”, John Rauser, бывший сотрудник Amazon: https://www.youtube.com/watch?v=fSgEeI2Xpdc
https://www.akamai.com/uk/en/about/news/press/2017-press/akamai-releases-spring-2017-state-of-online-retail-performance-report.jsp


Об авторе

Дэвид Янацек работает старшим главным инженером в AWS Lambda. Дэвид разрабатывает программное обеспечение в Amazon с 2006 года, раньше работал над Amazon DynamoDB и AWS IoT, а также внутренними платформами веб-сервисов и системами автоматизации операций парка. Одно из любимых занятий Дэвида – анализ журналов и тщательная проверка операционных показателей. Таким образом он ищет способы сделать работу систем беспроблемной.

Сброс нагрузки во избежание перегрузок Избежание огромного количества невыполненных заданий в очередях