Моніторинг Postgresql: запити

У 2008 році в списку розсилки pgsql-hackers почалося обсуждение розширення збору статистики за запитами. Починаючи з версії 8.4 розширення pg_stat_statements входить до складу постгреса і дозволяє отримувати різноманітну статистику про запити, які обробляє сервер.
Зазвичай це розширення використовується адміністраторами баз даних, як джерела даних для звітів (ці дані насправді є сумою показників з моменту скидання лічильників). Але на основі цієї статистики можна зробити моніторинг запитів — подивитися на статистику в часі. Це виявляється вкрай корисно для пошуку причин різних проблем і в цілому для розуміння, що відбувається на сервері БД.
Я розповім, які метрики за запитами збирає наш агент, як ми їх групуємо, пропонуємо, так само розповім про деяких граблях, з яким ми пройшли.
pg_stat_statements
Отже, що ж у нас є в view pg_stat_statements (мій приклад 9.4):
postgres=# \d pg_stat_statements;
View "public.pg_stat_statements"
Column | Type | Modifiers
---------------------+------------------+-----------
userid | oid |
dbid | oid |
queryid | bigint |
query | text |
calls | bigint |
total_time | double precision |
rows | bigint |
shared_blks_hit | bigint |
shared_blks_read | bigint |
shared_blks_dirtied | bigint |
shared_blks_written | bigint |
local_blks_hit | bigint |
local_blks_read | bigint |
local_blks_dirtied | bigint |
local_blks_written | bigint |
temp_blks_read | bigint |
temp_blks_written | bigint |
blk_read_time | double precision |
blk_write_time | double precision |

Тут всі запити згруповані, тобто статистику ми отримуємо не по кожному запиту, а по групі однакових з точки зору pg запитів (я розповім про це детальніше). Всі лічильники ростуть з моменту старту або з моменту скидання лічильників (pg_stat_statements_reset).
  • query — текст запиту
  • calls — кількість викликів запиту
  • total_time — сума часів виконання запиту в мілісекундах
  • rows — кількість рядків повернутих (select) або модифікованих у виконанні запиту (update)
  • shared_blks_hit — кількість блоків поділюваної пам'яті, отримане з кешу
  • shared_blks_read — кількість блоків поділюваної пам'яті, прочитане не з кешу
    В документації не очевидно, це сумарна кількість прочитаних блоків або тільки те, що не знайшлося в кеші, перевіряємо коду
    /*
    * lookup the buffer. IO_IN_PROGRESS is set if the requested block is
    * not currently in memory.
    */
    bufHdr = BufferAlloc(smgr, relpersistence, forkNum, blockNum,
    strategy, &found);
    if (found)
    pgBufferUsage.shared_blks_hit++;
    else
    pgBufferUsage.shared_blks_read++;

  • shared_blks_dirtied — кількість блоків поділюваної пам'яті, промаркованих як "брудні" у ході запиту запит змінив хоча б один кортеж в блоці і даний блок необхідно записати на диск, це робить або checkpointer або bgwriter)
  • shared_blks_written — кількість блоків поділюваної пам'яті записаного на диск синхронно в процесі обробки запиту. Постгрес намагається синхронно записати блок, якщо він вже повернувся "грязным".
  • local_blks — аналогічні лічильники для локальних з точки зору backend блоків, використовуються для тимчасових таблиць
  • temp_blks_read — кількість блоків тимчасових файлів лічених з диска.
    Тимчасові файли використовуються для обробки запиту коли не вистачає пам'яті, обмеженою налаштуванням work_mem
  • temp_blks_written — кількість блоків тимчасових файлів, записаних на диск
  • blk_read_time — сума часу очікування читання блоків мілісекундах
  • blk_write_time — сума часу очікування запису блоків на диск в мілісекундах (враховується тільки синхронний запис, час витрачений checkpointer/bgwriter тут не враховується)
blk_read_time і blk_write_time збираються тільки при включеній налаштування track_io_timing.
Окремо варто відзначити, що в pg_stat_statements потрапляють тільки завершені запити. Тобто, якщо у вас якийсь запит вже годину робить щось важке й досі не закінчився, його буде видно тільки в pg_stat_activity.
Як групуються запити
Я довгий час вважав, що запити групуються за реальним планом виконання. Бентежило лише те, що запити з різною кількістю аргументів IN відображаються окремо, план то в них повинен бути однаковий.
В коді видно, що насправді береться хеш від "значимих" частин запиту після синтаксичного розбору. Починаючи з 9.4 він виводиться в колонці queryid.
На практиці, нам доводиться додатково нормалізувалася і групувати запити вже в агенті. Наприклад, різне кількість аргументів в IN ми схлопываем в один плейсхолдер "(?)". Чи аргументи, які прилетіли в pg заинлайнеными запит ми самі замінюємо на плейсхолдеры. Завдання ускладнюється ще й тим, що текст запиту може бути не повним.
До 9.4 текст запиту обрізається до track_activity_query_size, c 9.4 текст запиту зберігається поза поділюваної пам'яті і обмеження прибрали, але ми в будь-якому випадку обрізаємо запит до 8Кб, так як якщо query лежать дуже важкі рядка, запити від агента відчутно навантажують постгрес.
З-за цього ми не можемо розібрати запит парсером SQL для додаткової нормалізації, замість цього довелося написати набір регулярних виразів для додаткової зачистки запитів. Це не дуже вдале рішення, тому що постійно доводиться додавати нові сценарії, але нічого кращого поки придумати не вдалося.
Ще одна проблема в тому, що в полі query постгрес записує перший прийшов запит в групі до нормалізації зі збереженням вихідного форматування, і якщо скинути лічильники, запит може бути іншим для тієї ж групи. Ще дуже часто розробники використовують коментарі в запитах, наприклад, для зазначення назви функції, яка смикає цей запит або ID користувальницького запиту), вони в query теж зберігаються.
Для того, щоб не плодити кожен раз нові метрики для одних і тих же потреб, ми вирізаємо коментарі зайві whitespace символи.
Постановка завдання
Моніторинг постгреса ми робили з допомогою наших друзів з postgresql consulting. Вони підказували, що саме корисне при пошуку проблем з базою, які метрики не особливо корисні і консультували по нутрощах postgresql.
У підсумку ми хочемо отримувати від моніторингу відповіді на наступні питання:
  • як зараз працює БД в цілому порівняно з іншим періодом
  • які запити навантажують сервер (cpu, диски)
  • яких запитів скільки
  • які часи виконання різних запитів
Збираємо метрики
насправді лити лічильники по всім запитам моніторинг досить дорого. Ми вирішили, що нас цікавить тільки TOP-50 запитів, але не можна просто взяти top по total_time, так як, якщо у нас з'явиться новий запит, його total_time ще довго буде наздоганяти старі запити.
Ми вирішили брати top по похідною (rate) total_time за хвилину. Для цього раз на хвилину агент вичитує pg_stat_statements цілком і зберігає предудущие значення лічильників. По кожному лічильнику кожного запиту обчислюється rate, потім ми намагаємося додатково об'єднати однакові запити, які pg порахував різними, їх статистики підсумовуються. Далі беремо top, за ним робимо окремі метрики, інші запити підсумовуємо в якийсь query="~other".
В результаті ми отримуємо 11 метрик для кожного запиту з топа. Кожна метрика має набір уточнюючих параметрів (міток):
{"database": "<db>", "user": "<user>", "query": "<query>"}

  • postgresql.query.time.cpu (ми просто відняли з total_time часи очікування диска для зручності)
  • postgresql.query.time.disk_read
  • postgresql.query.time.disk_write
  • postgresql.query.calls
  • postgresql.query.rows
  • postgresql.query.blocks.hit
  • postgresql.query.blocks.read
  • postgresql.query.blocks.written
  • postgresql.query.blocks.dirtied
  • postgresql.query.temp_blocks.read
  • postgresql.query.temp_blocks.written
Інтерпретуємо метрики
Дуже часто у користувачів з'являються питання про фізичному сенсі метрик "postgresql.query.time.*". Дійсно, не особливо зрозуміло, що показує сума часів відповідей, але такі метрики зазвичай добре показують співвідношення якихось процесів між собою.
Але якщо ми домовимося не брати до уваги блокування, можна дуже грубо припустити, що протягом всього часу обробки запиту постгрес утилізує якийсь ресурс (процесор або диск). Такі метрики мають розмірність: кількість витрачених ресурсних секунд в секунду. Можна ще привести це до відсотками утилізації запитом процесорного ядра, якщо помножити на 100%.
Дивимося, що вийшло
Перш ніж покладатися на метрики, потрібно перевірити, чи правду вони показують. Наприклад спробуємо розібратися, що викликає збільшення кількості операцій запису на сервері БД:




Дивимося, писав постгрес на диск в цей час:



Далі з'ясовуємо, які запити "бруднили" сторінки:



Бачимо, що є приблизний збіг, але графік по запитам в точності не повторює графік скидання буферів. Це викликано тим, що процес запису блоків відбувається у фоні і при цьому профіль навантаження на диск трохи змінюється.
Тепер подивимося, яка картина у нас вийшла з читанням:





Тут ми теж бачимо, що кореляція є, але точного збігу немає. Це можна пояснити тим, що постгрес читає блоки з диска не безпосередньо, а через кеш файлової системи. Таким чином ми не бачимо частину навантаження на диск, так як частина блоків читається з кешу.
Утилізацію процесора теж можна пояснити конкретними запитами, але абсолютної точності очікувати не доводиться, так як є очікування різних локов ітд:






Разом
  • pg_stat_statements дуже крута штука, яка дає докладну статистику, але при цьому не вбиває сервер
  • є ряд припущень і неточностей, їх потрібно розуміти для правильної інтерпретації метрик
На нашому демо стенді є приклад метрик за запитами, але навантаження там не дуже цікава і краще подивитися це на ваших метриках (у нас є безкоштовний, ні до чого не зобов'язує двотижневий тріал)
Джерело: Хабрахабр

0 коментарів

Тільки зареєстровані та авторизовані користувачі можуть залишати коментарі.