PostgreSQL: продуктивність і моніторинг AWS RDS

💡 Усі статті, обговорення, новини про DevOps — в одному місці. Приєднуйтесь до DevOps спільноти!

Привіт! Мене звати Арсеній, працюю на позиції DevOps Engineer з 2013 (а загалом в IT з 2005).

Веду свій власний блог RTFM: Linux, DevOps та системне адміністрування з 2011 року.

Зараз ми мігруємо наш Backend API з DynamoDB на AWS RDS PostgreSQL, і кілька раз RDS падав.

Власне, враховуючи те, що ми задля економії взяли db.t3.small з двома vCPU і двома гігабайтами пам’яті — то доволі очікувано, але стало цікаво чому ж саме все падало.

Через кілька днів почав цю тему дебажити, і хоча причини поки не знайшли — але з’явилась непогана чернетка того, як можна поінвестигейтити проблеми з перформансом в RDS PostgreSQL.

Пост — не звичайний «як зробити», а скоріше просто записати для себе — куди і на що наступного разу дивитись, і які зміни в моніторингу можна зробити, аби наступного разу побачити проблему раніше, ніж вона стане критичною.

The Issue

Отже, як все починалось.

Backend API запущений в AWS Elastic Kubernetes Service, і в якийсь момент посипались алерти по 503 помилкам:

З’явились алерти на використання Swap на Production RDS:

В Sentry з’явились помилки про проблеми з підключенням до серверу баз даних:

Починаємо перевіряти моніторинг RDS, і бачимо, що в якийсь момент Freeable Memory впала до 50 мегабайт:

Коли сервер впав, ми його перезапустили — але проблема тут же виникла знов.

Тому вирішили поки що переїхати на db.m5.large — на графіку видно, як вільна пам’ять стала 7.25 GB.

Ну і давайте глянемо, що цікавого ми можемо побачити з всієї цієї історії.

Set «Application Name»

В Performance Insights можна відобразити статистику по окремим Applications:

У нас цього зроблено не було, але, думаю, є сенс налаштувати окремі Applications для підключень експортерів моніторингу та з сервісів Backend API.

Є кілька варіантів, як це зробити — або передавати параметрами в connection strings:

"postgresql://user:password@host:port/database?application_name=MyApp"

Або виконувати прямо з коду при ініціалізації підключень:

with engine.connect() as conn:
 conn.execute("SET application_name TO 'MyApp'")

Другий варіант виглядає привабливішим, бо connection string до Backend API передається змінною оточення з AWS Secret Store, і робити окремий URL тільки заради одного параметру application_name для кожного сервісу API виглядає трохи костильно.

Тому краще в кожній апці бекенду задавати власний параметр при створенні підключення.

Корисні PostgreSQL Extentions

По ходу справи додавав кілька PostgreSQL Extentions, які прям дуже корисні в таких справах для моніторингу і інвестігейту.

Ввімкнення pg_stat_statements

Теж на жаль не було ввімкнено на момент проблеми, але в цілому must have штука.

Документація: pg_stat_statements — track statistics of SQL planning and execution та SQL statistics for RDS PostgreSQL.

В RDS PostgreSQL версій 11 і вище бібліотека включена по дефолту, тому все, що треба зробити — це створити EXTENSION, див. CREATE EXTENSION.

Перевіряємо, чи є extention зараз:

dev_kraken_db=> SELECT *
FROM pg_available_extensions
WHERE
   name = 'pg_stat_statements' and
   installed_version is not null;
name | default_version | installed_version | comment
------+-----------------+-------------------+---------
(0 rows)

(0 rows) — окей, пусто.

Створюємо його:

dev_kraken_db=> CREATE EXTENSION pg_stat_statements;
CREATE EXTENSION

Перевіряємо ще раз:

dev_kraken_db=> SELECT *                           
FROM pg_available_extensions
WHERE
   name = 'pg_stat_statements' and
   installed_version is not null;
       name        | default_version | installed_version |                                comment                                
--------------------+-----------------+-------------------+------------------------------------------------------------------------
pg_stat_statements | 1.10            | 1.10              | track planning and execution statistics of all SQL statements executed
(1 row)

І спробуємо отримати якусь інформацію з pg_stat_statements і таким запитом:

SELECT query
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;

Далі в цьому пості будуть ще приклади того, яку інформацію з pg_stat_statements можемо отримати.

Включення pg_stat_activity

Окрім pg_stat_statements, корисну інформацію за поточною активністю можна отримати з pg_stat_activity, включена по дефолту.

Обидві являють собою views, хоча в різних схемах бази:

dev_kraken_db=> \dv *.pg_stat_(statements|activity)
                List of relations
  Schema   |        Name        | Type |  Owner  
------------+--------------------+------+----------
pg_catalog | pg_stat_activity   | view | rdsadmin
public     | pg_stat_statements | view | rdsadmi

Різниця між pg_stat_activity та pg_stat_statements у PostgreSQL

Обидві допомагають аналізувати запити, але pg_stat_activity — це поточна активність, а pg_stat_statements— «історична»:

Включення pg_buffercache

Ще один корисний extension — це pg_buffercache, який може відобразити інформацію по стану пам’яті в PosgtreSQL.

Включається аналогічно до pg_stat_statements:

CREATE EXTENSION IF NOT EXISTS pg_buffercache;

Далі теж подивимось на цікаві запити для перевірки стану пам’яті в PostgreSQL.

Окей. Повертаємось до нашої проблеми.

CPU utilization та DBLoad

Перше, на що звернули увагу — це навантаження на CPU.

В Performance Isights це виглядало так:

А в Monitoring самого інстансу — так:

DBLoad (Database Load)

Документація по DBLoad в CloudWatch — тут.

У PostgreSQL кожна клієнтська сесія створює окремий процес (backend process).

DBLoad — це метрика AWS RDS PostgreSQL, яка відображає значення активних сесій, які виконуються або очікують на ресурси — CPU, disk I/O, Locks. Не враховуються сесії в статусі idle, але враховуються сесії в статусі active, idle in transaction або waiting.

DBLoad схожий на Load Average у Linux, але враховує тільки PostgreSQL-сесії:

• У Linux Load Average показує кількість процесів на Linux-сервері, які або використовують CPU, або чекають на нього чи на I/O
• У RDS DBLoad відображає середню кількість активних сесій на сервері PostgreSQL, які або працюють, або чекають ресурси

Тобто в ідеалі кожен backend-процес, який виконує запити від підключеного клієнта, має мати доступ до «власного» ядра vCPU, отже DBLoad має бути ~= кількості vCPU або менше.

Якщо ж DBLoad значно перевищує кількість доступних ядер — то це показник, що система перевантажена і процеси (сесії) очікують в черзі на CPU або інші ресурси.

DBLoad включає в себе ще два показники:

• DBLoadCPU: сесії, які знаходяться саме в очікуванні вільного CPU
• DBLoadNonCPU: сесії, які знаходяться в очікуванні диску, database table locks, networking, etc

Перевірити сесії, які будуть вважатись активними і будуть включені в DBLoad можемо так:

SELECT pid, usename, state, wait_event, backend_type, query
FROM pg_stat_activity
WHERE state != 'idle'

Нормальне значення для DBLoad

DBLoad має бути приблизно рівним або нижче кількості доступних vCPU.

DBLoad vs CPU Utilization

Чому на першому скріні ми бачимо «100%», а на другому просто кількість в 17.5?

• CPU Utilization: відсоток використання CPU від загальної доступної потужності
• DBLoad: кількість активних сесій

Враховуючи, що на сервері в той момент було 2 доступних vCPU, і при цьому 17 активних сесій — то маємо 100% використання процесорного часу.

Окремо варто завернути увагу на DBLoadRelativeToNumVCPUs — це DBLoad поділений на кількість доступних vCPU, тобто середнє навантаження на кожне ядро CPU.

DBLoadCPU (Database Load on CPU Wait)

DBLoadCPU відображає кількість активних сесій, які очікують на CPU, тобто процеси, які не можуть виконуватись, бо всі доступні CPU зайняті.

В ідеалі має бути близько нуля — тобто, на сервері не має бути процесів, які очікують CPU.

Якщо DBLoadCPU має значення близько DBLoad, то RDS не встигає обробити всі запити — не вистачає CPU time, і вони стають в чергу.

Перевірити можемо тим самим запитом з pg_stat_activity, як вище: якщо в wait_event = «CPU», то це процеси, які чекають вільного CPU.

Нормальне значення для DBLoadCPU

DBLoadCPU має бути якнайнижчим (близьким до нуля).

Якщо DBLoadCPU майже дорівнює DBLoad, то:

• основне навантаження саме на процесор
• сесії не блокуються через Table Locks або повільний диск (I/O), а просто чекають CPU

DBLoadNonCPU (Database Load on Non-CPU)

DBLoadNonCPU, власне, відображає інформацію очікування ресурсів, не пов’язаних з CPU.

Це можуть бути:

• блокування (Locks): очікування доступу до таблиці або рядка
• I/O очікування (I/O Wait): повільне читання або запис через дискові обмеження
• Network Wait: затримки через мережеві операції (наприклад, реплікація або передача даних)
• Other Wait Events: інші очікування, такі як процеси фонового обслуговування

Перевірити такі сесії можемо аналогічно до попередніх запитів з pg_stat_activity, але додамо виборку wait_event_type та wait_event:

SELECT pid, usename, state, wait_event_type, wait_event, query
FROM pg_stat_activity
WHERE state != 'idle'
ORDER BY query_start;

Тут wait_event_type вказує на тип ресурсу, на який очікує процес (CPU, IO, Lock, WAL, Client), а wait_event деталізує яку конкретно операцію процес очікує.

Наприклад, wait_event_type може бути «IO», тоді в wait_event_type можуть бути значення «DataFileRead» (очікування читання з диска) або «DataFileWrite» — очікування запису на диск.

Або, якщо wait_event_type == Client, тоді wait_event_type може бути «ClientRead», «ClientWrite», «ClientSocket».

Див. RDS for PostgreSQL wait events.

Повернемось до наших графіків:

• CPU Utilization 100%: система перенавантажена
• DBLoad 17.5: при двох vCPU — маємо багато активних сесій, процесор не встигає обробити всі запити
• DBLoadCPU 13.9: багато сесій очікують на доступний CPU
• DBLoadNonCPU 3.59: частина запитів очікували диск, блокування, або якісь мережеві запити

Operating System CPU utilization

Окрім метрик DBLoad, які відносяться саме до RDS та PostgreSQL, у нас ще є інформація по самій операційній системі, де маємо інформацію і по диску, і по пам’яті, і по CPU.

Власне в CPU utilization ми маємо графік у відсотках з використання CPU, який складається з кількох метрик, кожна з яких відображає окремий режим:

• os.cpuUtilization.steal.avg (Steal Time): очікування фізичного CPU, якщо AWS виділила його іншому інстансу на цьому фізичному сервері, або якщо CPU Credits використано, і AWS обмежує ваш інстанс
• os.cpuUtilization.guest.avg (Guest Time): CPU, який «з’їла» гостьова операційна система — якщо на сервері є Virtual Machine або Docker, але не про RDS
• os.cpuUtilization.irq.avg (Interrupt Requests, IRQ Time): очікування Interrupt Requests, IRQ Time — обробка апаратних переривань (мережеві запити або диск), може бути пов’язана з високим IOPS на EBS
• os.cpuUtilization.wait.avg (I/O Wait Time): час I/O Wait Time, дискові операції, наприклад — зчитування файлів
• os.cpuUtilization.user.avg (User Time): час на юзер-процеси, в даному випадку це можуть бути обробка запитів PostgreSQL
• os.cpuUtilization.system.avg (System Time): робота ядра операційної системи (обробка процесів з user space, дискові операції, операції з пам’яттю)
• os.cpuUtilization.nice.avg (Nice Time): час на процеси з пріоритетом nice — низькопріоритетні фонові завдання

Схожі дані ми маємо в Linux top:

Tasks: 611 total, 7 running, 603 sleep, 1 d-sleep, 0 stopped, 0 zombie
%Cpu(s):  5.9 us,  3.6 sy,  0.0 ni, 89.8 id,  0.2 wa,  0.0 hi,  0.5 si,  0.0 st

Тут us — user, sy — system, ni — nice, id — idle і так далі.

З нашого графіку в RDS Performance Insights ми маємо найбільшу частину саме по wait — і в той час є спайки по EBS IO operations:

Тобто, «прилетів» якийсь запит, який почав активно вичитувати з диска:

І поки CPU чекав на завершення операцій з диском — решта запитів виконувались повільніше.

В той самий час маємо «провал» по Freeable memory — бо дані з диска записувались в пам’ять.

І хоча саме значення в 460 IOPS не виглядає якимось зависоким, але схоже, що саме в цей момент ми «з’їли» доступну пам’ять.

На що нам в даному випадку може вказувати високий os.cpuUtilization.wait.avg?

• повільний EBS: все ж не наш кейс, бо маємо швидкість до 3000 IOPS; хоча очікування читання з диску в пам’ять могло спричинити ріст I/O Waits на CPU
• блокування/Locks: як варіант, але у нас є метрика db.Transactions.blocked_transactions.avg — і там все було добре, тобто PostgreSQL не чекав на звільнення locks — на транзакції теж зараз глянемо
• мало оперативної пам’яті: читання нових даних з диску в пам’ять витіснило існуючі там дані в Swap, і потім вичитувало їх звідти назад, при цьому скидуючи дані з пам’яті обратно в Swap, аби завантажити зі swap нові (swap storm)

Використання Swap в цей час теж виросло:

До Swap і ReadIOPS зараз перейдемо, але спочатку давайте глянемо на транзакції.

Transactions

Ще з цікавого — активність транзакцій:

Бачимо, що як тільки почались проблеми з CPU — у нас xact_commit та xact_rollback (графік зліва) впали до нуля, і в той же час кількість active_transactions виросла до ~20, але при цьому blocked_transactions було 0.

Вже не можу зробити скрін, але ще був спайк по «idle in transaction» — тобто, транзакції починались (BEGIN), але не завершувались (не виконали COMMIT або ROLLBACK).

Але як так може бути? Навіть при високому CPU Waits хоча б частина транзакцій мали б завершитись.

• зависокий Read IOPS: система не могла отримати дані з диску?
  • ні — ReadIOPS виріс, але не прям настільки критично
  • однак через те, що FreeableMemory був занизьким, дані з shared_buffers могли бути скинуті до swap, що викликало ще більші затримки у процесів, які ці дані очікували
• зависокий Write IOPS: система не могла виконати запис WAL (Write Ahead Logs, будемо розбирати далі), якого потребує завершення транзакцій
  • але ми бачили, що Write IOPS був в нормі
• багато table locks, і процеси очікували вивільнення ресурсів?
  • теж ні, бо ми бачили, що blocked_transactions було на нулі
• робота autovacuum або ANALYZE, які могли заблокувати транзакції?
  • але знов-таки — db.Transactions.blocked_transactions.avg був на нулі
• Swap storm: оце вже більше схоже на правду:
  • читання з диску витіснило активні дані на Swap (впав показник FreeableMemory)
  • Swap Usage виріс майже до 3-х гігабайт
  • PostgreSQL не міг отримати сторінки з shared_buffers, бо вони були в SWAP (про пам’ять теж далі буде)
  • через це транзакції «зависли» в очікуванні читання з диска, замість того щоб працювати у RAM

Що ми можемо перевірити в таких випадках?

I/O Waits або Blocks

SELECT pid, usename, query, wait_event_type, wait_event, state
FROM pg_stat_activity
WHERE state = 'active';

Якщо в wait_event маємо «I/O» або «Locks» — то причина може бути тут.

WAL — Write Ahead Logs

• при кожній операції DML (Data Manipulation Language), наприклад при INSERT, UPDATE або DELETE, дані спочатку змінюються в пам’яті (shared_buffers — будемо далі про них говорити), де створюється «контекст операції»
• одночасно ця операція заноситься у WAL-буфер (wal_buffers — буфер пам’яті)
• коли wal_buffers заповнюється, або коли транзакція завершена, PostgreSQL-процес wal_writer за допомогою системного виклику fsync() записує дані з буфера у wal-файл (директорія pg_wal/) — це журнал всіх змін, що відбулися перед COMMIT
• клієнт, який запустив виконання запиту отримує повідомлення COMMIT — операція успішно завершена
  • якщо параметр synchronous_commit = on, PostgreSQL чекає завершення fsync() перед відправкою COMMIT
  • якщо synchronous_commit = off, PostgreSQL не чекає fsync() і COMMIT відбувається швидше, але з ризиком втрати даних
  • при неможливості виконати транзакцію — клієнт отримає помилку «could not commit transaction»
• дані з shared_buffers записуються до файлів самої бази даних (каталог base/) — цим займається процес checkpointer, який записує модифіковані в пам’яті дані (dirty pages) на диск
  • це відбувається за допомогою процесу CHECKPOINT не одразу після COMMIT, а періодично
  • після виконання CHECKPOINT — PostgreSQL виконує архівацію або видалення WAL-файлів

Дуже класний матеріал на тему WAL, memory та checkpoint: PostgreSQL: What is a checkpoint?

Отже, якщо EBS був перенавантажений з Write IOPS — то WAL міг перестати писатись, і це могло призвести до зупинки виконання транзакцій.

Але в нашому випадку ми бачимо, що і db.Transactions.xact_rollback.avg був на нулі, а він не залежить від WAL і Write-операцій на диску.

В PostgreSQL Exporter є кілька корисних метрик, які відображаються активність WAL:

• pg_stat_archiver_archived_count: загальна кількість успішно заархівованих WAL-файлів (що скаже нам, що WAL працює коректно)
• pg_stat_archiver_failed_count: кількість невдалих спроб архівування WAL-файлів
• pg_stat_bgwriter_checkpoint_time: час, витрачений на виконання CHECKPOINTs

Ще можна зробити такий запит:

SELECT * FROM pg_stat_wal;

Якщо wal_buffers_full високий і росте, то, можливо, транзакції чекають на виконання fsync(), або що значення wal_buffers замале, і його треба збільшити аби зменшити частоту примусових записів WAL на диск.

В PostgreSQL такої метрики наче нема, але можемо зробити власну з custom.yaml:

pg_stat_wal:
 query: "SELECT wal_buffers_full FROM pg_stat_wal;"
 metrics:
   - wal_buffers_full:
       usage: "COUNTER"
       description: "Number of times the WAL buffers were completely full, causing WAL data to be written to disk."

Read IOPS та Swap

Добре.

Давайте повернемось до питання з Read IOPS та Swap.

Що тут могло відбутись:

• якийсь запит почав активно зчитувати дані з диску
• вони заносились в shared_buffers, в пам’яті не вистачило місця, і дані, які там були до цього були винесені в Swap
• запити в PostgreSQL продовжують виконуватись, але тепер замість того, аби просто взяти дані з пам’яті — PostgreSQL має йти до Swap, і тому маємо високий ReadIOPS та CPU I/O Waits — тобто CPU чекає, поки дані будуть зчитані з диску

Але тоді наче мало б бути спайк по db.IO.blks_read.avg, раз читаємо з диска?

Але ні, бо db.IO.blks_read — це запити від самого PostgreSQL на читання данних.

Коли ж він оперує зі свапом — він все одно вважає, що працює з оперативною пам’яттю.

А от метрика ReadIOPS — це вже від самої операційної системи/EBS, і вона як раз показує всі операції читання, а не тільки від процесів PostgreSQL.

Що цікаво, що в момент проблеми у нас db.Cache.blks_hit впав до нуля. Про що це каже? Зазвичай, що backend-процеси (сесії) не знаходили дані в shared_buffers.

Але знаючи, що у нас взагалі всі транзакції зупинились, а db.IO.blks_read теж впав до нуля — то скоріш PostgreSQL просто перестав звертатись до кешу взагалі, бо всі чекали на вільний CPU.

Окей, гугл...

А що зі свапом?

SWAP та Enhanced monitoring

Що у нас є на графіках?

Тут нам буде корисний Enhanced monitoring:

Вибираємо там Swap (Manage graphs), і бачимо цікаву картину:

• Free Memory падає
• Free Swap падає
• але Swaps in та Swaps out без змін

Тобто виглядає так, наче пам’ять закінчується — система скидає дані з RAM у Swap — але при цьому саме операції Swaps in/out «не було».

Виглядає наче цікаво, і варто було б тут копнути далі — але AWS Console на цих графіках постійно падає:

Див. OS metrics in Enhanced Monitoring.

Втім, хоча ми не можемо отримати метрики з Enhanced monitoring напряму, але — сюрпрайз! вони пишуться до CloudWatch Logs! А вже з логів ми можемо нагенерити собі будь-які метрики з VictoriaLogs або Loki:

І вже в логах бачимо, що Swap In/Out таки відбувався. Тільки простих графіків вже не побачити. Але в майбутньому зробити собі якихось метрик з цих логів було б корисно.

В Log Groups шукаємо RDSOSMetrics, а потім вибираємо лог по RDS ID:

Operating system process list

Ще дуже корисним може бути список процесів:

Якщо починає падати вільна пам’ять — йдемо сюди, дивимось Resident memory, знаходимо PID процесу який жере пам’ять — і дивимось, що саме там за запит:

prod_kraken_db=> SELECT user, pid, query FROM pg_stat_activity WHERE pid = '26421';
      user       |  pid  |  query  
------------------+-------+----------
prod_kraken_user | 26421 | ROLLBACK

Всі ці процеси ми також маємо в логах, про які згадував вище — але це краще перевіряти в момент, коли виникає проблема, аби знайти який саме виконувався.

Бо так, ми можемо включити slow queries logs — але в тих логах ми не побачимо PID, і не зможемо дізнатись скільки пам’яті цей запит використав.

Пам’ять в PostgreSQL

Давайте трохи копнемо в те, що взагалі в пам’яті PostgreSQL.

Див. RDS for PostgreSQL memory та Tuning memory parameters.

Пам’ять в PostgreSQL ділиться на два основні типи — це «shared memory», та «local memory» — пам’ять кожного бекенд-процесу (сесії).

В shared memory ми маємо:

• shared_buffers: основна пам’ять, де PostgreSQL тримає кеш даних, які він зчитує з диску при обробці запитів — кешування сторінок таблиць та індексів
  • аналог Heap Memory (Java Heap)
  • shared_buffers за замовчуванням становить 25% від загальної RAM, але можна змінити
• wal_buffers: вже бачили вище — використовується для тимчасового зберігання WAL-записів для буферизації транзакції перед записом у WAL-файл

Із shared_buffers змінені дані (dirty pages) записуються на диск двома процесами:

• Background Writer (bgwriter): працює в фоні, поступово записує дані на диск
• Checkpointer (checkpoint): примусово записує всі сторінки під час CHECKPOINT

Пам’ять процесів має:

• work_mem: виділяється запитам, які виконують сортувань (ORDER BY), хеш-операцій (HASH JOIN) та агрегацій
  • кожен запит отримує свою копію work_mem, тому при великій кількості одночасних запитів пам’ять може швидко закінчитись
  • якщо work_mem процесу не вистачає — PostgreSQL починає записувати тимчасові файли на диск (temp_blks_written), що уповільнює виконання запитів
• maintenance_work_mem: власне, maintenance operations — операції по vacuuming, створення індексів, додавання foreign keys
• temp_buffers: виділяється для тимчасових таблиць (CREATE TEMP TABLE).

Ми можемо отримати всі дані з pg_settings так:

SELECT
   name,
   setting,
   unit,
   CASE
       WHEN unit = '8kB' THEN setting::bigint * 8
       WHEN unit = 'kB' THEN setting::bigint
       ELSE NULL
   END AS total_kb,
   pg_size_pretty(
       CASE
           WHEN unit = '8kB' THEN setting::bigint * 8 * 1024
           WHEN unit = 'kB' THEN setting::bigint * 1024
           ELSE NULL
       END
   ) AS total_pretty
FROM pg_settings
WHERE name IN ('shared_buffers', 'work_mem', 'temp_buffers', 'wal_buffers');

Маємо 238967 shared_buffers, кожен по 8КБ, разом ~1.9 GB.

Але це вже зараз, на db.m5.large.

Перевірка shared_buffers

Cache hit ratio покаже скільки даних було отримано з пам’яті, а скільки з самого диску — хоча у нас це є в метриках db.IO.blks_read.avg та db.Cache.blks_hit.avg (або метрики pg_stat_database_blks_hit та pg_stat_database_blks_read в PostgreSQL Exporter):

SELECT
   blks_read, blks_hit,
   ROUND(blks_hit::numeric / NULLIF(blks_hit + blks_read, 0), 4) AS cache_hit_ratio
FROM pg_stat_database
WHERE datname = current_database();

Якщо cache_hit_ratio < 0.9, значить, кеш PostgreSQL не ефективний, і забагато даних читається з диска замість кеша.

Побачити скільки з виділених shared_buffers зараз використані (активні), а скільки вільні — тут нам знадобиться extention pg_buffercache.

Запит:

SELECT
   COUNT(*) AS total_buffers,
   SUM(CASE WHEN isdirty THEN 1 ELSE 0 END) AS dirty_buffers,
   SUM(CASE WHEN relfilenode IS NULL THEN 1 ELSE 0 END) AS free_buffers,
   SUM(CASE WHEN relfilenode IS NOT NULL THEN 1 ELSE 0 END) AS used_buffers,
   ROUND(100.0 * SUM(CASE WHEN relfilenode IS NOT NULL THEN 1 ELSE 0 END) / COUNT(*), 2) AS used_percent,
   ROUND(100.0 * SUM(CASE WHEN relfilenode IS NULL THEN 1 ELSE 0 END) / COUNT(*), 2) AS free_percent
FROM pg_buffercache;

Маємо 238967 буферів загалом, з яких використано лише 12280, або 5%.

Або інший варіант — подивитись, скільки всього сторінок зараз в shared_buffers:

prod_kraken_db=> SELECT
   count(*) AS cached_pages,
   pg_size_pretty(count(*) * 8192) AS cached_size
FROM pg_buffercache;
cached_pages | cached_size
--------------+-------------
      117495 | 918 MB

При тому, що всього під shared_buffers виділено:

prod_kraken_db=> SHOW shared_buffers;
shared_buffers
----------------
939960kB

918 мегабайт.

Але чому тоді в попередньому запиті ми бачили, що «зайнято 5%»?

Бо в результаті з pg_buffercache в полях used_buffers та used_percent враховуються тільки активні сторінки (used), тобто ті, які або мають прив’язку до файлу (relfilenode), або були нещодавно використані.

Використання EXPLAIN ANALYZE

Див. EXPLAIN.

EXPLAIN (ANALYZE, BUFFERS) покаже нам скільки даних в буферах зараз, скільки даних буде прочитано з диску:

Тут:

• shared hit: скільки сторінок було прочитано з кешу (shared_buffers)
• shared read: скільки сторінок було прочитано з диска (завантажено в shared_buffers)
• shared dirtied: скільки сторінок було модифіковано

Тема Explain доволі цікава і дає нам багато цікавої інформації, тому написав про неї окремо: PostgreSQL: використання EXPLAIN та налаштування «auto_explain» в AWS RDS.

Подивитись зміст shared_buffers

Отримати кількість буферів по всім таблицям:

SELECT
c.relname, count(*) AS buffers
FROM
pg_buffercache b
INNER JOIN pg_class c ON b.relfilenode = pg_relation_filenode(c.oid)
AND
b.reldatabase IN (0, (SELECT oid FROM pg_database
WHERE
datname = current_database()))
GROUP BY c.relname
ORDER BY 2 DESC
LIMIT 10;

Тут для challenge_progress використано 1636 буферів, що дає нам:

1636*8/1024
12

12 мегабайт.

Або можна отримати з pg_relation_size() — див. System Administration Functions та pg_relation_size():

prod_kraken_db=> SELECT pg_size_pretty(pg_relation_size('challenge_progress'));
pg_size_pretty
----------------
13 MB

Перевірка work_mem

Якщо у нас падає FreeableMemory, то, можливо, використовується забагато work_mem.

Перевірити скільки виділяється на кожен процес:

dev_kraken_db=> SHOW work_mem;
work_mem
----------
4MB

Перевірити чи вистачає процесам цього значення work_mem можна зі значення temp_blks_written, бо коли пам’ять в work_mem закінчується, то процес починає виносити дані в тимчасові таблиці:

Ну і, власне, на цьому, мабуть, все.

Якісь висновки? Складно робити. Ясно, що db.t3.small з двома гігабайтами нам було замало.

Є підозра який саме запит тоді викликав цю «ланцюгову реакцію», в slow queries logs побачили «поганий» SELECT, і девелопери його наче оптимізували.

Спробуємо зменшити тип інстансу до 4 гігабайт пам’яті, і подивимось, чи виникне проблема знов.

Monitoring summary

Замість висновків — кілька ідей того, що треба моніторити, і що в моніторингу можна покращити.

Наші алерти

Накидаю трохи алертів, які у нас вже є зараз.

CloudWatch метрики

Метрики CloudWatch. Збираємо до VictoriaMetrics з YACE-експортером.

CPUUtilization

Алерт:

- alert: HighCPUUtilization
 expr: avg(aws_rds_cpuutilization_average{dimension_DBInstanceIdentifier!="", dimension_DBInstanceIdentifier!~"kraken-ops-rds-.*"}[5m]) by (dimension_DBInstanceIdentifier) > 80
 for: 5m
 labels:
   severity: warning
   component: devops
   environment: ops
 annotations:
   summary: "High CPU utilization on RDS instance"
   description: "CPU utilization is above 80% for more than 5 minutes on RDS instance {{ "{{" }} $labels.instance }}."
DBLoadRelativeToNumVCPUs

DBLoadRelativeToNumVCPUs

Алерт:

- alert: HighCPULoadPerVCPUWarningAll
 expr: avg(aws_rds_dbload_relative_to_num_vcpus_average{dimension_DBInstanceIdentifier!="", dimension_DBInstanceIdentifier!~"kraken-ops-rds-.*"}[5m]) by (dimension_DBInstanceIdentifier) > 0.8
 for: 5m
 labels:
   severity: warning
   component: devops
   environment: ops
 annotations:
   summary: "High per-core CPU utilization on RDS instance"
   description: |
     CPU utilization is above 80% for more than 5 minutes on RDS instance {{ "{{" }} $labels.instance }}
     *DB instance*: `{{ "{{" }} $labels.dimension_DBInstanceIdentifier }}`
     *Per-vCPU load*: `{{ "{{" }} $value | humanize }}`

FreeStorageSpace

Не дуже актуально, якщо маємо динамічний storage, але може бути корисним.

Алерт:

- record: aws:rds:free_storage:gigabytes
 expr: sum(aws_rds_free_storage_space_average{dimension_DBInstanceIdentifier!=""}) by (dimension_DBInstanceIdentifier) / 1073741824
# ALL
- alert: LowFreeStorageSpaceCriticalAll
 expr: aws:rds:free_storage:gigabytes < 5
 for: 5m
 labels:
   severity: warning
   component: devops
   environment: ops       
 annotations:
   summary: "Low Disk Space on an RDS instance"
   description: |-
     Free storage below 5 GB
     *DB instance*: `{{ "{{" }} $labels.dimension_DBInstanceIdentifier }}`
     *Free storage*: `{{ "{{" }} $value | humanize }}`

FreeableMemory

Алерт:

- alert: LowFreeableMemoryDev
 expr: avg(aws_rds_freeable_memory_average{dimension_DBInstanceIdentifier="kraken-ops-rds-dev"}[5m]*0.000001) by (dimension_DBInstanceIdentifier) < 20
 for: 5m
 labels:
   severity: warning
   component: backend
   environment: dev      
 annotations:
   summary: "High memory usage on RDS instance"
   description: |-
     Freeable memory is less than 100mb
     *DB instance*: `{{ "{{" }} $labels.dimension_DBInstanceIdentifier }}`
     *Free memory*: `{{ "{{" }} $value | humanize }}`

ReadLatency, ReadIOPS та WriteLatency і WriteIOPS

Схожі метрики, корисно моніторити.

Алерт:

- alert: HighDiskReadLatencyKrakenStaging
 expr: sum(aws_rds_read_latency_average{dimension_DBInstanceIdentifier="kraken-ops-rds-dev"}) by (dimension_DBInstanceIdentifier) > 0.1
 for: 1s
 labels:
   severity: warning
   component: backend
   environment: dev
 annotations:
   summary: "High Disk Read Latency on RDS instance"
   description: |-
     Reads from a storage are too slow
     *DB instance*: `{{ "{{" }} $labels.dimension_DBInstanceIdentifier }}`
     *Read Latency*: `{{ "{{" }} $value | humanize }}`

SwapUsage

Теж must have метрика.

Алерт:

- record: aws:rds:swap_used:gigabytes
 expr: sum(aws_rds_swap_usage_average{dimension_DBInstanceIdentifier!=""}) by (dimension_DBInstanceIdentifier) / 1073741824
# ALL
- alert: SwapUsedAllWarning
 expr: sum(aws:rds:swap_used:gigabytes{dimension_DBInstanceIdentifier!="", dimension_DBInstanceIdentifier!~"kraken-ops-rds-.*"}) by (dimension_DBInstanceIdentifier) > 0.8
 for: 1s
 labels:
   severity: warning
   component: devops
   environment: ops
 annotations:
   summary: "Swap space use is too high on an RDS instance"
   description: |-
     The RDS instance is using more than *0.8 GB* of swap space
     *DB instance*: `{{ "{{" }} $labels.dimension_DBInstanceIdentifier }}`
     *Swap used GB*: `{{ "{{" }} $value | humanize }}`

DatabaseConnections

Є метрика CloudWatch, але вона нам повертає просто кількість конектів — а ліміт може бути різним для різних типів інстансів.

Тому приклад алерта тут покажу, але далі буде інший — з метрик PostgreSQL Exporter:

# db.t3.micro - 112 max_connections (Backend Dev)
# db.t3.small - 225 max_connections (Backend Prod)
# db.t3.medium - 450 max_connections
# db.t3.large - 901 max_connections
# ALL
- alert: HighConnectionCountWarning
 expr: avg(aws_rds_database_connections_average{dimension_DBInstanceIdentifier!="", dimension_DBInstanceIdentifier!~".*kraken.*"}[5m]) by (dimension_DBInstanceIdentifier) > 50
 for: 1m
 labels:
   severity: warning
   component: devops
   environment: ops
 annotations:
   summary: "High number of connections on RDS instance"
   description: |-
     An RDS instance Connections Pool is almost full. New connections may be rejected.
     *DB instance*: `{{ "{{" }} $labels.dimension_DBInstanceIdentifier }}`
     *Instance type*: `db.t3.micro`
     *Max connections*: `112`
     *Current connections*: `{{ "{{" }} $value | humanize }}`

Loki Recording Rules metrics

Пару метрик генеримо з логів нашого Backend API, наприклад:

- record: aws:rds:backend:connection_failed:sum:rate:5m
 expr: |
   sum(
       rate(
           {app=~"backend-.*"}
           != "token_email"
           |= "sqlalchemy.exc.OperationalError"
           | regexp `.*OperationalError\) (?P<message>connection to server at "(?P<db_server>[^"]+)".*$)`
           [5m]
       )
   ) by (message, db_server)

І потім з них створюємо алерти:

- alert: BackendRDSConnectionFailed
 expr: sum(aws:rds:backend:connection_failed:sum:rate:5m{db_server="dev.db.kraken.ops.example.co"}) by (db_server, message) > 0
 for: 1s
 labels:
   severity: critical
   component: backend
   environment: dev
 annotations:
   summary: "Connection to RDS server failed"
   description: |-
     Backend Pods can't connect to an RDS instance
     *Database server:*: {{ "{{" }} $labels.db_server }}
     *Error message*: {{ "{{" }} $labels.message }}

PostgreSQL Exporter metrcis

pg_stat_database_numbackends

Тут як раз про Connections: в експортері ми маємо метрику pg_settings_max_connections, яка вказує на максимальну кількість конектів в залежності від типу інстансу, і pg_stat_database_numbackends — кількість активних сесій (конектів).

Відповідно можемо порахувати % від max connections.

Єдина проблема, що ці метрики мають різні лейбли, і я забив робити якісь label_replace — тому просто додав три record, на кожен environment:

# 'pg_stat_database_numbackends' and 'pg_settings_max_connections' have no common labels
# don't want to waste time with 'label_replace' or similar
# thus just create different 'records' for Prod and Staging
- record: aws:rds:kraken_dev:max_connections_used:percent
 expr: |
   (
     sum(pg_stat_database_numbackends{datname=~"dev_kraken_db", job="atlas-victoriametrics-postgres-exporter-kraken-dev"})
     /
     sum(pg_settings_max_connections{container=~".*kraken-dev"})
   ) * 100
- alert: ExporterHighConnectionPercentBackendDevWarning
 expr: aws:rds:kraken_dev:max_connections_used:percent > 40
 for: 1s
 labels:
   severity: warning
   component: backend
   environment: dev
 annotations:
   summary: "High number of connections on the Backend RDS instance"
   description: |-
     RDS instance Connections Pool is almost full. New connections may be rejected.
     *DB instance*: `kraken-ops-rds-dev`
     *Connections pool use*: `{{ "{{" }} $value | humanize }}%`
   grafana_rds_overview_url: 'https://{{ .Values.monitoring.root_url }}/d/ceao6muzwos1sa/kraken-rds?orgId=1&from=now-1h&to=now&timezone=browser&var-query0=&var-db_name=kraken-ops-rds-dev'

pg_stat_activity_max_tx_duration

Алерти, коли якісь транзакції виконуються надто довго.

Не сказати, що дуже корисна метрика, бо не маємо PID і кількості пам’яті, але поки що хоч так.

Потім можна буде подумати над кастомними метриками.

Зараз алерт такий:

- alert: ExporterTransactionExecutionTimeBackendDevWarning
 expr: sum(rate(pg_stat_activity_max_tx_duration{datname="dev_kraken_db"}[5m])) by (state, datname) > 0.1
 for: 1m
 labels:
   severity: warning
   component: backend
   environment: dev
 annotations:
   summary: "RDS transactions running too long"
   description: |-
     Too long duration in seconds active transaction has been running
     *Database name*: `{{ "{{" }} $labels.datname }}`
     *State*: `{{ "{{" }} $labels.state }}`
     *Duration*: `{{ "{{" }} printf "%.2f" $value }}` seconds
   grafana_rds_overview_url: 'https://{{ .Values.monitoring.root_url }}/d/ceao6muzwos1sa/kraken-rds?orgId=1&from=now-1h&to=now&timezone=browser&var-query0=&var-db_name={{ "{{" }} $labels.datname }}'

Варто додати

Ну, тут прям дуже багато всього.

PostgreSQL Exporter custom metrics

Основне, десь вище вже згадував — в PostgreSQL Exporter ми можемо створювати кастомні метрики з результатами запитів до PostgreSQL, використовуючи config.queries.

Див. Create Prometheus integrated Postgres custom metrics.

Хоча ця фіча наче deprecated.

Але навіть якщо її вимкнуть — то можна заморочитись, і написати власний експортер. Див. Prometheus: створення Custom Prometheus Exporter на Python та Prometheus: GitHub Exporter — пишемо власний експортер для GitHub API.

CloudWatch Logs та Enhanced Monitoring

Теж вже згадував, було б дуже корисно мати власні метрики по тому ж Swap, або мати PID процесів і їхню resident memory.

How can I filter Enhanced Monitoring CloudWatch logs to generate automated custom metrics for Amazon RDS?

Моніторинг Transactions

В мене це зараз є на Grafana dashboard:

Але можливо додам окремими алертами — по кількості active transactions, або по idle in transaction.

Основні метрики з PostgreSQL Exporter:

• pg_stat_database_xact_commit та pg_stat_database_xact_rollback: як бачили в нашому випадку — якщо значення падає, то маємо проблеми — запити не завершуються
• pg_stat_activity: по лейблі state маємо два основні:
  • active: загальна кількість активних запитів
  • idle in transaction: теж бачили в нашому випадку, що багато запитів зависли в очікуванні завершення
• pg_locks: кількість блоків (див. pg_locks та Concurrency Control)

Моніторинг WAL

Теж згадував кілька метрик, які є в PotsgreSQL Exporter, можливо, додам по ним або алертів, або графіків до Grafana:

• pg_stat_archiver_archived_count: загальна кількість успішно заархівованих WAL-файлів (що скаже нам, що WAL працює коректно)
• pg_stat_archiver_failed_count: кількість невдалих спроб архівування WAL-файлів
• pg_stat_bgwriter_checkpoint_time: час, витрачений на виконання CHECKPOINT

В самому сервері можемо перевірити з view pg_stat_wal:

SELECT * FROM pg_stat_wal;

Основні тут:

• wal_records: кількість записаних WAL-записів (операцій INSERT, UPDATE, DELETE)
• wal_bytes: загальний обсяг даних (у байтах), записаних у WAL
• wal_buffers_full: скільки разів WAL-буфери були повністю заповнені, змушуючи бекенд-процеси писати напряму в WAL-файл
• wal_write: кількість разів, коли PostgreSQL записував WAL у файл
• wal_write_time: загальний час у мілісекундах, витрачений на записи WAL
• wal_sync_time: загальний час (у мілісекундах), витрачений на fsync() (гарантований запис на диск)

Моніторинг shared_buffers

Тут треба ще подумати, які б метрики можна було генерити, і які графіки або алерти придумати.

З того, що приходить в голову:

• моніторити shared hit та read: скільки даних було знайдено в кеші, а скільки довелось зчитувати з диску
• buffers_backend: скільки буферів записали безпосередньо бекенд-процеси
  • в нормальній ситуації всі дані з dirty pages мають записуватись bgwriter або checkpoint
  • якщо shared_buffers зайняті, а bgwriter, wal_writer або checkpointer не встигає переносити з них дані на диск — то backend-процеси клієнтів змушені переносити дані самі, що уповільнює виконання їх запитів

Перевіряємо з:

SELECT buffers_backend, buffers_checkpoint, buffers_alloc FROM pg_stat_bgwriter;

Тут:

• buffers_backend: скільки буферів записали безпосередньо бекенд-процеси
• buffers_checkpoint: скільки буферів записано під час CHECKPOINT
  • якщо маємо високе значення:
    • то чекпоінти відбуваються рідко, і одразу записують багато сторінок
    • або bgwriter не встигає виконувати записи, і CHECKPOINT записує все відразу
• buffers_alloc: скільки нових буферів виділено у shared_buffers
  • якщо маємо високе значення — то кеш постійно витісняється, і PostgreSQL змушений завантажувати сторінки з диска

Моніторинг Checkpointer

Також сенс приглядати за Checkpointer:

SELECT checkpoint_write_time, checkpoint_sync_time FROM pg_stat_bgwriter;

Тут:

• checkpoint_write_time: час, витрачений на запис змінених сторінок з shared_buffers у файлову систему; якщо значення велике — то:
  • занадто великий shared_buffers — при чекпоінті доводиться записувати забагато сторінок одразу
  • багато операцій (UPDATE, DELETE), що призводить до великої кількості «брудних» сторінок (dirty pages).
  • або checkpoint_timeout занадто великий, тому при чекпоінті записується багато змін одразу.
• checkpoint_sync_time: час, витрачений на примусовий запис (виконання fsync()) змінених сторінок на фізичний диск; якщо значення велике — то:
  • можливі проблеми з диском — повільно записуються дані

Моніторинг work_mem

Теж є сенс дивитись сюди.

Якщо work_mem недостатньо — то процеси починають писати temp_blks_written, що, по-перше, уповільнює виконання запитів, по-друге — створює додаткове навантаження на диск.

Перевіряємо з:

SELECT temp_files, temp_bytes FROM pg_stat_database WHERE datname = current_database();

Корисні посилання

• Common DBA tasks for Amazon RDS for PostgreSQL
• Monitor Amazon RDS for PostgreSQL and Amazon Aurora PostgreSQL performance using PGSnapper
• OS metrics in Enhanced Monitoring
• Tuning memory parameters
• Tuning memory parameters for Aurora PostgreSQL
• How can I log execution plans of queries for Amazon RDS PostgreSQL or Aurora PostgreSQL to tune query performance?
• RDS for PostgreSQL wait events
• SQL statistics for RDS PostgreSQL
• Viewing OS metrics in the RDS console
• Monitoring Transaction Logs in PostgreSQL
• Top metrics in PostgreSQL monitoring with Prometheus
• RDS for PostgreSQL memory
• pg_buffercache — inspect PostgreSQL buffer cache state
• Determining the optimal value for shared_buffers using the pg_buffercache extension in PostgreSQL
• How Linux uses RAM and swap
• pgPedia — An encyclopedia of things PostgreSQL-related
• PostgreSQL: використання EXPLAIN та налаштування «auto_explain» в AWS RDS