Скорость выполнения запросов играет очень важную роль и её мониторинг может очень помоч при оптимизации работы приложения. Такие продукты как, например MySQL или PHP-FPM имеют встроенный функционал по логированию медленных завросов. Но что если нужно вести подобный access_log в NginX?

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

Nginx непосредственно не умеет записывать запросы относительно скорости их выполнения, но есть очень гибкий функционал управление логированием который поможет в этом.

Идея взята из этой статьи.

Из официальной документации можно узнать:

Параметр if включает условную запись в лог. Запрос не будет записываться в лог, если результатом вычисления условия является “0” или пустая строка. В следующем примере запросы с кодами ответа 2xx и 3xx не будут записываться в лог:

map $status $loggable { 
	~^[23] 0; 
    default 1; 
} 
access_log /path/to/access.log combined if=$loggable;

Суть идеи для логирования медленных запросов такова — нужно модифицировать вид логируемого сообщения, добавив время выполнения запроса и на него применять map.

В итоге получаем такой конфиг:

http {
  log_format upstream_time '$remote_addr - $remote_user [$time_local] '
                           '"$request" $status $body_bytes_sent '
                           '"$http_referer" "$http_user_agent"'
                           'rt=$request_time uct="$upstream_connect_time" uht="$upstream_header_time" urt="$upstream_response_time"';

  map $request_time $loggable {
    ~^0.[012345] 0;
    default 1;
  }

  server {
    ...
    access_log /var/log/nginx/slow.log upstream_time if=$loggable;
    ...
  }
}

Происходит следующее — в формат сообщения лога добавлен параметр «rt=$request_time» (общее время, потраченное на обработку запроса), создан map который выдаёт «0» (то есть сообщение не будет записано) если $request_time равно любому числу от 0.0 до 0.5. Таким образом в лог будут записаны запросы $request_time которых > 0.6 секунд (600мс). Строка с access_log подключает всю вышеописанную логику.