Логирование#

Логирование компонента Pangolin Pooler происходит в отдельном лог-файле по пути:

/pangolinlogs/pangolin-pooler/pangolin-pooler.log

Пример команды для просмотра лога компонента:

timeout 60s tail -f /pangolinlogs/pangolin-pooler/pangolin-pooler.log

Ротация файлов логирования#

Файл для ротации файлов логирования компонента:

расположение при установке rpm/deb-пакета компонента:
```
/opt/pangolin-pooler/share/doc/logrotate/pangolin-pooler/
```
конечное целевое расположение файла:
```
/etc/logrotate.d/pangolin-pooler
```

Пример настроенного файла /etc/logrotate.d/pangolin-pooler для ротации:

/pangolinlogs/pangolin-pooler/pangolin-pooler.log {
      rotate 10
      su postgres postgres
      missingok
      sharedscripts
      notifempty
      compress
      daily
      create 0600 postgres postgres
      postrotate
           /bin/kill -HUP `cat /var/run/user/984/pangolin-pooler/pangolin-pooler.pid 2> /dev/null` 2>/dev/null ||true
      endscript
}

Настройка вывода команды SHOW POOLS в лог Pangolin Pooler#

Для анализа ошибок сессий при работе Pangolin Pooler в СУБД Pangolin реализована возможность вывода результата команды SHOW POOLS в лог Pangolin Pooler.

Включение/отключение вывода информации осуществляется через настройку параметра show_period конфигурационного файла pangolin-pooler.ini. Значение по умолчанию - 0 (запись в лог Pangolin Pooler отключена). В данном параметре устанавливается период (в секундах), с которым происходит запись в лог. Параметр рекомендуется настраивать на подготовительном этапе, чтобы в процессе исследования инцидента не получить отказ запуска сервиса при некорректных названиях/значениях параметра. В случае, если значение параметра show_period не задано, будет использоваться значение по умолчанию, что соответствует отключенному состоянию функциональности.

Также параметр может быть установлен командой: SET show_period = value администратором в консоли.

После изменения значения параметра перечитайте конфигурационный файл Pangolin Pooler для применения нового значения.

Внимание

Установка некорректных (нечисловых) значений параметра show_period приводит к невозможности запуска сервиса pangolin-pooler.

Вывод производится в лог-файл, который указывается в файле конфигурации Pangolin Pooler, по умолчанию - pangolin-pooler.log, при этом вывод не может быть перенаправлен.

Пример формата вывода данных в лог-файл pangolin-pooler.log (маркер LOG POOLS):

2024-02-20 13:23:18.859 MSK [21524] LOG POOLS +-----------+-----------+-----------+------------+----------------------+-----------------------+-----------+------------------+-------------------+---------+---------+-----------+----------+---------+------------+----------+-------------+----------+-------------+-------------+
2024-02-20 13:23:18.859 MSK [21524] LOG POOLS | database  |   user    | cl_active | cl_waiting | cl_active_cancel_req | cl_waiting_cancel_req | sv_active | sv_active_cancel | sv_being_canceled | sv_idle | sv_used | sv_tested | sv_login | maxwait | maxwait_us | avg_time | avg_time_us | max_time | max_time_us |  pool_mode  |
2024-02-20 13:23:18.859 MSK [21524] LOG POOLS +-----------+-----------+-----------+------------+----------------------+-----------------------+-----------+------------------+-------------------+---------+---------+-----------+----------+---------+------------+----------+-------------+----------+-------------+-------------+
2024-02-20 13:23:18.859 MSK [21524] LOG POOLS | pgbouncer | pgbouncer |         0 |          0 |                    0 |                     0 |         0 |                0 |                 0 |	 0 |	   0 |         0 |        0 |       0 |          0 |        0 |           0 |        0 |           0 | statement   |
2024-02-20 13:23:18.859 MSK [21524] LOG POOLS | postgres  | postgres  |         1 |          0 |                    0 |                     0 |         0 |                0 |                 0 |	 0 |	   1 |         0 |        0 |       0 |          0 |        0 |       46541 |        0 |       46541 | transaction |
2024-02-20 13:23:18.859 MSK [21524] LOG POOLS +-----------+-----------+-----------+------------+----------------------+-----------------------+-----------+------------------+-------------------+---------+---------+-----------+----------+---------+------------+----------+-------------+----------+-------------+-------------+

Диагностика ошибок#

Сообщения системного журнала#

Примеры и типы сообщений из лог-файла представлены в данном разделе.

Информационные сообщения:

Тип сообщения	Сообщение	Диагностика
`INFO`
	`Authentication method "md5" isn't allowed for non security admin role "<username>"`	Доступ в БД через Pooler с использованием сквозной аутентификации с использованием запрещенных слабых методов аутентификации (например, `md5`)
	`<command_name> command issued`	Выполнение команды из административной консоли Pangolin Pooler. Список команд доступен в разделе «Управление и использование»
	`Admin disappeared when suspended, doing RESUME`	Администратор отключился во время приостановки — выполняется команда `RESUME`
	`Zone '<name>' serial changed: old=<n> new=<n>`	Обновлена DNS-зона
	`User '<user>' removed from locked user list.`	Пользователь разблокирован
	`Server connections dropped, exiting`	Все серверные соединения завершены
	`NDC mode switched to '<mode>'`	Переключен режим NDC
	`Got SIGTERM/SIGINT/SIGQUIT/...`	Получен системный сигнал — выполнение остановки или паузы
	`Got SIGUSR1/SIGUSR2, pausing/resuming activity`	Управление активностью через сигналы — пауза или возобновление
	`Kernel file descriptor limit: <soft>/<hard>;...`	Диагностика лимитов ОС — дескрипторы и ожидаемое использование
	`Stale pidfile, removing`	Найден устаревший PID-файл, который будет удален
	`Got SIGHUP, re-reading config`	Получен сигнал перечитать конфигурацию
	`Old process not found, try to continue normally`	Старый процесс не найден
	`Listening on <addr>`	Pooler слушает на указанном адресе
	`Socket passed from service manager (fd <n>)`	Получен сокет от управляющего процесса
	`Got pooler socket: <addr>`	Получено сокет соединение
	`Plugin to get passphrase for PKCS#12 file is loaded`	Загружен плагин расшифровки PKCS#12
	`Plugin to get certificate from Secret storage is loaded`	Загружен плагин извлечения TLS-сертификата
	`Client certificates caching: <on/off>`	Состояние кеширования клиентских TLS-сертификатов
	`Sending SHUTDOWN`	Инициировано завершение работы
	`Waiting for old pidfile to go away`	Ожидание завершения предыдущего процесса
	`Old process killed, resuming work`	Предыдущий процесс завершен
	`Disko over, going background`	Завершение и переход в фоновый режим
	`SUSPEND finished, sending SHOW FDS`	После завершения `SUSPEND` выполняется диагностика
	`SHOW FDS finished`	Команда `SHOW FDS` завершена
	`takeover_init: launching connection`	Инициализация takeover-соединения
`AUDIT`
	`Login attempt tls=<yes/no>`	Использование TLS при подключении пользователя
	`Connection received`	Зафиксировано входящее подключение
	`Login failed`	Неуспешная попытка подключения
	`Closing because: client close request (age=<N>s)`	Клиент самостоятельно завершил соединение. `age` — продолжительность соединения в секундах
	`Send auth startup packet`	Отправка стартового пакета аутентификации клиентом. Обычно предшествует проверке пользователя
	`Auth server login ok`	Успешная аутентификация пользователя сервером базы данных
`DEBUG`
	`RESET_AUTH reset context: user=<user> dbname=<db> ...`	Контекст аутентификации сброшен с помощью команды `RESET_AUTH`
	`Got admin query: <query>`	Получен административный запрос
	`TLS cert login: <subject>`	Подключение с TLS-сертификатом
	`Admin console connection for user: <user>`	Установлено соединение с административной консолью
	`DNS lookup failed: <name> - <error>`	Ошибка DNS-запроса
	`zone_register(<zone>): <name>`	Зарегистрирована DNS-зона
	`Send notify message (PAUSE MODE is enabled)`	Отправлено уведомление в режиме `PAUSE`
	`NDC suspending timeout has ended`	Таймер приостановки NDC завершен
	`Launching new connection to satisfy min_pool_size`	Установлено новое соединение для `min_pool_size`
	`locked_user_list removing 2 for: <user>`	Пользователь удален из списка заблокированных
	`Loading auth_file: "<file>"`	Загрузка конфигурационного файла аутентификации
	`NDC mode did not change: mode='<mode>'`	Режим NDC остался прежним

Предупреждающие сообщения (тип WARNING):

Тип сообщения	Сообщение	Диагностика
`WARNING`
	`TLS certificate does not contain DNS or IP`	Сертификат TLS не содержит IP или DNS. Возможны ошибки проверки подлинности
	`Unsupported startup parameter in options: <key>=<value>`	Использован неподдерживаемый параметр запуска
	`Authentication context expired. user: db=<db> user=<user>`	Истек срок действия контекста аутентификации. Пользователю потребуется повторная аутентификация
	`dns(<name>): req failed, no mem`	Ошибка DNS-запроса из-за нехватки памяти
	`DNS lookup failed: <name>: result=<code>`	Ошибка разрешения DNS-имени. Проверьте сетевые настройки
	`samerole is not supported`	Условие доступа `samerole` не поддерживается Pangolin Pooler
	`samegroup is not supported`	Условие доступа `samegroup` не поддерживается Pangolin Pooler
	`hba line <n>: Ident map <name> is malformed. It is not in map=value format.`	Ошибка формата карты `ident` в конфигурации pg_hba
	`hba line <n>: Ident map <name> is not found in ident config file`	Указанная карта `ident` отсутствует в конфигурации
	`hba line <n>: Unknown type`	Указан неизвестный тип подключения в `pg_hba`
	`hba line <n>: Did not find address`	Пропущен IP-адрес или CIDR-маска в `pg_hba`
	`hba line <n>: Invalid mask`	Некорректная маска подсети в `pg_hba`
	`Ignore 'user' for database '<database_name>' because auth_proxy is on`	Параметр `user` игнорируется, так как включен режим прокси-аутентификации
	`Ignore 'auth_username' for database '<database_name>' because auth_proxy is on`	Параметр `auth_username` игнорируется в режиме сквозной аутентификации
	`Ignore 'auth_dbname' for database '<database_name>' because auth_proxy is on`	Параметр `auth_dbname` игнорируется врежиме сквозной аутентификации
	`Invalid SCRAM secret for user <username>`	Задан некорректный SCRAM-секрет
	`Invalid grace SCRAM verifier for user "<username>"`	Неверный SCRAM grace-пароля верификации
	`Invalid salt length in grace SCRAM verifier for user <username>`	Некорректная длина `salt`
	`Wrong salt in grace SCRAM verifier for user <username>`	Неправильное значение `salt` в верификации
	`Wrong iterations in grace SCRAM verifier for user <username>`	Некорректное количество итераций SCRAM верификаций
	`Server login failed: <level> <message>`	Неудачный вход на сервер
	`show_stats_setup: initialization failed`	Не удалось инициализировать показ статистики
	`event_add failed: <reason>`	Ошибка добавления события в цикл обработки. Возможная причина — ошибка ОС
	`Hostname cannot be received`	Ошибка получения имени хоста. Возможна сетевая или системная ошибка
	`Unix peer uid failed: <reason>`	Ошибка получения UID клиента при соединении по Unix-сокету

Сообщения об ошибке:

Тип сообщения	Сообщение	Диагностика
`FATAL`
	`No pg_hba.conf entry for host "<IP-Address>", user "user1", database "postgres", SSL on`	Убедитесь, что в `pg_hba.conf` есть правило, разрешающее подключение от указанного пользователя, хоста и к нужной базе
	`Password authentication failed for user "user1" DETAIL: User "user1" has no password assigned`	У пользователя отсутствует пароль, либо он не задан в системе или в файле аутентификации
	`Role is blocked due to fail authentication attempts`	Учетная запись заблокирована из-за превышения количества неуспешных попыток входа
	`Token authentication failed for user "<username>"`	Аутентификация не удалась из-за изменения пароля пользователя в СУБД. Требуется выполнить переподключение
	`PgBouncer does not allow to use weak authentication type: "trust"`	Использование слабых типов аутентификации (таких как, например, `trust`) запрещено при активном механизме сквозной аутентификации
	`The userlist file contains a password that cannot be represented as plain text`	Pangolin Pooler, с активным механизмом сквозной аутентификации, не работает с файлом `userlist.txt`, содержащим пароль в открытом виде
	`The '<username>' user cannot be used as he is not admin_users or stat_users`	Ошибка после добавления пользователя в `userlist.txt`. Pangolin Pooler разрешает указывать пользователей в файле `userlist.txt` только предварительно заданных в `admin_users` и `stat_users`
	`cmd regex compilation error`	Ошибка компиляции регулярного выражения команды. Проверьте корректность шаблона
	`Set/word/str regex compilation error`	Некорректное регулярное выражение в команде `SET` (ключ, значение)
	`Why waiting client in client_proto()`	Некорректное состояние клиента, `WAITING` при обработке протокола
	`Why canceling client in client_proto()`	Некорректное состояние клиента, `CANCEL` при обработке протокола
	`Bad client state: <int>`	Обнаружено некорректное внутреннее состояние клиента. Возможна ошибка в логике соединений
	`Cannot create initial caches`	Ошибка инициализации кеша Pooler (пользователи, БД, соединения и другое)
	`Cannot initialize snowflake generator`	Не удалось инициализировать генератор уникальных идентификаторов
	`sbuf_pause failed`	Ошибка при приостановке работы буфера сокета. Возможна проблема на уровне ОС
	`Broken fd packet`	Получен поврежденный пакет на файловом дескрипторе
	`Failed to convert address: <addr>`	Не удалось интерпретировать сетевой адрес. Проверьте формат и данные
	`Unknown task: <task_name>`	Попытка выполнить неизвестную задачу. Возможен сбой конфигурации
	`Socket takeover failed`	Ошибка при захвате сокета (при миграции или перезапуске)
	`takeover_create_link: failed to find pair`	Не удалось найти «парное» соединение для takeover
	`Got bad CMD from old bouncer: <cmd>`	Старый экземпляр Pangolin Pooler передал неизвестную или недопустимую команду
	`Command send failed`	Не удалось отправить команду в backend или другой компонент
	`Cannot create initial auth caches`	Ошибка инициализации кеша аутентификации
	`PgBouncer does not allow to use unix socket if auth_proxy = on`	При включенной сквозной аутентификации нельзя использовать Unix-сокеты. Используйте TCP/IP
	`Failed to load a legacy provider introduced in OpenSSL 3.0.0`	OpenSSL не может загрузить старый провайдер. Проверьте OpenSSL-конфигурацию
	`TLS setup failed`	Ошибка реализации TLS-соединения. Проверьте сертификаты и параметры подключения
	`PgBouncer should not run as root`	Запуск под пользователем `root` завершился неудачно
`ERROR`
	`TLS certificate name mismatch`	Имя, указанное в TLS-сертификате, не совпадает с ожидаемым именем пользователя/сервера. Проверьте сертификат
	`TLS configuration could not be reloaded, keeping old configuration`	Ошибка при перезагрузке TLS-конфигурации. Используется предыдущее значение
	`Authentication database "<database_name>" is not configured`	Указанная база данных не настроена как источник аутентификации
	`Cannot use the reserved "<database_name>" database as an auth_dbname`	Попытка использовать зарезервированную БД как `auth_dbname`. Выберите другую БД
	`TLS connection required`	Подключение должно выполняться по защищенному TLS-каналу. Проверьте настройки клиента
	`TLS client certificate required`	Сервер ожидает клиентский TLS-сертификат, но он не был предоставлен
	`Certificate authentication failed`	Аутентификация на основе сертификата завершилась неудачно. Возможные причины: имя не совпадает или отсутствует сертификат
	`Ident map: <map_name> does not have a match`	Значение из карты соответствия (`ident map`) не может быть сопоставлено. Проверьте файл конфигурации
	`Incorrect auth type <type_code>`	Указан неподдерживаемый тип аутентификации. Проверьте настройки
	`'set_pool():' failed to allocate new user`	Превышен лимит подключений или исчерпаны ресурсы Pooler для выделения пула
	`PAM can't be used together with database authentication`	Одновременное использование PAM и встроенной аутентификации запрещено. Используйте только один механизм
	`SCRAM authentication failed: user has MD5 secret`	Пользователь имеет MD5-хеш пароля, а клиент требует SCRAM. Обновите формат пароля
	`Invalid SCRAM response (nonce does not match)`	SCRAM пароля клиента некорректен. Проверьте и повторите попытку
	`Password authentication failed`	Некорректный пароль. Убедитесь в правильности введенных данных
	`SASL authentication failed`	Аутентификация SASL не удалась. Возможно, ошибка со стороны клиента или несовместимый формат
	`'ids' of peers must be a number larger than 0 and at most 65536`	ID узла должен быть числом от 1 до 65536. Проверьте настройки репликации или кластера
	`Out of memory`	Недостаточно памяти для выполнения операции. Проверьте настройки или нагрузку на систему
	`Syntax error in connection string`	Обнаружена синтаксическая ошибка в строке подключения. Проверьте формат и параметры
	`Invalid port: <val>`	Значение порта в строке подключения некорректно. Ожидается числовое значение
	`Unrecognized connection parameter: <key>`	Найден неподдерживаемый параметр в строке подключения
	`Host was not provided for peer <peer_id>`	В конфигурации не указан обязательный параметр `host` для указанного узла
	`Cannot create peer, no memory?`	Не удалось создать подключение к пирингу. Возможная причина — нехватка памяти
	`Invalid pool mode: <val>`	Указан неверный режим пула. Поддерживаемые значения: `session`, `transaction`, `statement`
	`Broken auth file`	Файл аутентификации поврежден или содержит ошибки. Проверьте его целостность
	`Username too long in auth file`	Имя пользователя в файле аутентификации превышает допустимую длину
	`Password too long in auth file`	Пароль в файле аутентификации превышает допустимую длину
	`Cannot do MD5 authentication: wrong password type`	Требуется формат MD5, но пароль задан в другом формате
	`Cannot do SCRAM authentication: password is SCRAM secret but client authentication did not provide SCRAM keys`	SCRAM не является поддерживаемым методом, но пароль пользователя — в формате SCRAM
	`Server login failed: wrong password type`	Ошибка входа из-за несовпадения типа пароля
	`SCRAM exchange protocol error`	Нарушение протокола SCRAM
	`Could not load plugin to get PKCS#12 file specified in file "<file_path>"`	Ошибка загрузки плагина для обработки PKCS#12-файла. Проверьте путь к файлу и совместимость плагина
	`Unknown client`	Клиент не распознан. Возможно, используется устаревшая или несовместимая версия

Пример команды для проверки вывода лога компонента, файла pangolin-pooler.log:

timeout 60s tail -f /pangolinlogs/pangolin-pooler/pangolin-pooler.log

Коды возврата при использовании сквозной аутентификации#

В таблице ниже приведены возможные коды возврата, которые возникают в логе Pangolin Pooler при использовании сквозной аутентификации.

Состояние	Название	Pangolin Pooler	Pangolin DBMS
`STATUS_OK (0)`	Аутентификация выполнена успешно		+
`STATUS_ERROR (-1)`	Аутентификация не прошла		+
`STATUS_EOF (-2)`	Произошел разрыв между Pooler и Pangolin DBMS		+
`STATUS_HANDSHAKE_OK (10)`	Выполнился обмена пакетами на старте между Pooler и Pangolin DBMS		+
`STATUS_WAITING_DATA (11)`	Выполняется обмен данными		+
`STATUS_TIMEOUT_EXPIRED (12)`	Сработал таймер аутентификации	+	+

Пример записи в логе#

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

Попытка входа пользователя test в базу test_db с клиента по адресу <IP-Address>, порт <port>. Аутентификация выполняется без использования TLS:
```
2022-08-17 14:12:48.194 MSK AUDIT test_db/test@<IP-Address>:<port> login attempt tls=no
```
Регулярная статистика соединения: число транзакций и запросов в секунду, входящий/исходящий трафик, среднее время выполнения транзакции, запроса и ожидания. В данном случае активность низкая:
```
2022-08-17 14:13:46.990 MSK [1230] LOG stats: 0 xacts/s, 0 queries/s, in 3 B/s, out 4 B/s, xact 3284 us, query 355 us, wait 6 us
```

Отсутствует активность — соединение не используется, трафик и задержки нулевые:

2022-08-17 14:15:46.991 MSK [1230] LOG stats: 0 xacts/s, 0 queries/s, in 0 B/s, out 0 B/s, xact 0 us, query 0 us, wait 0 us

Соединение с клиентом закрывается по его инициативе (client close request). Продолжительность соединения — 1789 секунд (~30 минут):
```
2022-08-17 14:16:42.393 MSK AUDIT test_db/test@<IP-Address>:<port> closing because: client close request (age=1789s)
```
Получено новое соединение от того же клиента (порт <port>):
```
2022-08-17 14:16:42.414 MSK AUDIT test_db/test@<IP-Address>: connection received
```
Предупреждение: истек срок действия аутентификационного контекста клиента. Возможно, между соединениями прошло слишком много времени, либо внутренний кеш аутентификации обновился:
```
2022-08-17 14:16:42.414 MSK [1230] WARNING C-0x2278d78 (21474): (nodb)/test@<IP-Address>:<port> authentication context expired. user: db=test_db user=test
```

Новая попытка входа без TLS:

2022-08-17 14:16:42.414 MSK AUDIT test_db/test@<IP-Address>:<port> login attempt tls=no

Отправка стартового пакета аутентификации от клиента:

2022-08-17 14:16:42.414 MSK AUDIT test_db/test@<IP-Address>:<port> send auth startup packet

Аутентификация клиента прошла успешно:

2022-08-17 14:16:42.492 MSK AUDIT test_db/test@<IP-Address>:<port> auth server login ok

Сводка статистики показывает, что клиент ведет небольшую активность:

2022-08-17 14:16:46.991 MSK [1230] LOG stats: 0 xacts/s, 0 queries/s, in 3 B/s, out 4 B/s, xact 3962 us, query 450 us, wait 12 us

Снова отсутствие активности на соединении:

2022-08-17 14:17:46.991 MSK [1230] LOG stats: 0 xacts/s, 0 queries/s, in 0 B/s, out 0 B/s, xact 0 us, query 0 us, wait 0 us

Такие логи позволяют анализировать жизненный цикл соединения: от момента подключения до закрытия. Особенно полезны события AUDIT — они показывают каждое подключение, аутентификацию и причину завершения соединения. LOG stats помогает отслеживать нагрузку и поведение клиента.