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

логи с пгбаунсера за тот период. Что это может быть? Внимание на wait

11 xacts/s, 11 queries/s, in 11570 B/s, out 10557 B/s, xact 1246 us, query 1246 us, wait 0 us
2021-12-13 12:52:45.246 EET [1186] LOG stats: 14 xacts/s, 14 queries/s, in 14160 B/s, out 13160 B/s, xact 2013 us, query 2013 us, wait 77 us
2021-12-13 12:53:45.249 EET [1186] LOG stats: 14 xacts/s, 14 queries/s, in 14556 B/s, out 13499 B/s, xact 1612 us, query 1610 us, wait 599 us
2021-12-13 12:54:45.247 EET [1186] LOG stats: 15 xacts/s, 15 queries/s, in 14112 B/s, out 18992 B/s, xact 1438 us, query 1438 us, wait 0 us
2021-12-13 12:55:45.249 EET [1186] LOG stats: 12 xacts/s, 12 queries/s, in 11885 B/s, out 37262 B/s, xact 2129 us, query 2129 us, wait 10 us
2021-12-13 12:56:45.249 EET [1186] LOG stats: 17 xacts/s, 17 queries/s, in 16720 B/s, out 26766 B/s, xact 1221 us, query 1221 us, wait 13 us
2021-12-13 12:57:45.245 EET [1186] LOG stats: 22 xacts/s, 22 queries/s, in 19144 B/s, out 77104 B/s, xact 122575 us, query 122575 us, wait 2706632 us
2021-12-13 12:58:45.245 EET [1186] LOG stats: 18 xacts/s, 18 queries/s, in 15133 B/s, out 16527 B/s, xact 1315 us, query 1315 us, wait 37 us
2021-12-13 12:59:45.247 EET [1186] LOG stats: 17 xacts/s, 17 queries/s, in 17597 B/s, out 19970 B/s, xact 1183 us, query 1183 us, wait 0 us

Да что угодно в принцыпе. Большой запрос, checkpoint, на сервер cron запустил что-то, диск накрывается... PS И да, с realtime в постгресе всё плохо. И 2 секунды -- это ещё очень коротко.

я же правильно понимаю xacts это транзакции, queries - запрос, wait - время ответа?

wait -- время когда у pgbouncer не было свободных соединений, хотя у клиентов были запросы.

хм. а еще интересно 22 xacts/s и xact 122575 us и это за минуту. как-то 22 xacts/s не сходится с итоговым значением? возможно есть где про это почитать, что б я не донимал Вас вопросами, в доке пгбаунсера ненашел именно разьяснений по данному поводу

Почему не сходится? Вот 122575 и 2706632 -- не сходится, да. Получается, что сервер 2 секунды просто не принимал соединение... Но не видно, что кто-нибудь закрывал старое. Вот это странно выглядит.

А почитать -- исходники pgbouncer. Документацыя у него так себе.

я просто хочу понять это облако шалит или приложение..

Хотя, читать надо -- можэт, он сюда реакцыю на свой ABORT или чем он там очищает состояние сэссии включает. Тогда можэт и не было никаких новых соединений, и сервер тормозил на чём-то стандартном.

Без тщательных дампов -- это будет не так просто.

можешь подсказать на что обратить внимание при наблюдении? это почти каждый день в обед неачинается

Если соединение без TLS -- то тупо снять tcpdumpом всё, что он там делает. Судя по pgbouncer, там небольшые объёмы. И можно будет после этого сопоставить -- кто всё-таки такой этот wait, и кто там тупит.

чувствую будет сложно) не такой опытный в анализе чистого трафика, но я попробую, спасибо!

Дампы открыть в wireshark, он знает протокол постгреса - там легко будет.

о, благодарю

Легко -- не будет. По опыту знаю.

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

tcpdump умеет писать дампы сразу с ротацией дампов по времени, например по часам. Может пригодиться )

Там облачный postgres, видимо -- так что "с двух сторон" ужэ не получится.

В зависимости от. Значит на своей стороне посмотреть. Может ретрансмиты будут - тогда можно сразу вопросы в ЦУС направить, они сами на своей стороне дамп сделают )

Но там где ЦУС - там возможно это не быстро. У меня был опыт убеждения провайдера в том, что они режут сины. Полгода заняло ) без моей лени можно было бы за 2-3 месяца убедить.

Так подожди. Если баунсер пишет что 2 секунды не выдавал соединение (принять он принял, раз начал отсчитывать время), то дампы тут не особо нужны. Я бы начал с конфига баунсера. Может оно не по транзакциям пулит, например?

В смысле -- не особо нужны? Ты вот можэшь сказать, что происходило? Не проходил SYN? Авторизацыя? ABORT/ROLLBACK/RESET?

Счётчик пошёл? - значит баунсер syn получил. Время транзакций там в логе тоже есть, так что запросы проходили. Либо я неправильно интерпретирую то что написано, не нулевая вероятность.

Баунсер понятно что SYN получил. Интересно-то -- что там между баунсером и postgres.

Баунсер держит коннекты. Ему какое дело? - если коннекты попадали, то кажется это в логи должно попасть. Баунсер дискард кинул и коннект уже чистый, готов к выдаче.

По идее -- должно, но зуб на это я бы не поставил... И да, вот если бы всё так и было -- то почему тогда wait большэ, чем xact? Ну, OK, он можэт быть на сколько-то большэ, если там оно складывается из нескольких запросов, но почему оно НАСТОЛЬКО большэ? Пришло сразу 500 запросов и ждали бОльшую часть от этого повисшэго xact? Возможно, да.

Но жэлательно всё-таки смотреть -- кого оно там реально ждало, и не ошыбся ли я в этих теоретизированиях.

Потому что балансировка по коннектам, а не транзакциям. Транзакции проскочили, а коннекты висят - баунсеру нечего отдать. Но это предположение, пока ещё рано исключать магию )

Только wait -- это наоборот, запрос есть а свободного коннэкта под него нет.

Так я же именно про это, может не ясно сформулировал. Открыли 20 коннектов к баунсеру. Он держит 20 коннектов к базе. На каждый коннект к баунсеру присвоился коннект к базе. Открыли 21 коннект к баунсеру, а коннектов к базе свободных нет - приложение не закрыло коннекты к баунсеру. Вроде пулинг коннектов так работает? - хотя я плохо понимаю зачем такой режим может быть нужен )

Нужен такой режим когда установка контекста дороже транзакции)))

И когда нужны адвайзори локи вне транзакций, когда нужны препаред статемент, когда ещё куча всего нужно. Пулинг транзакций режет функционал, это правда, но он же даёт максимальную производительность.

Справедливости ради, эту проблему будет видно в дампах )

В 14 стараниями CITUS (Аля Microsoft) многое решили. Но полностью согласен, да пока так

Не припомню такого в ченжлоге. По крайней мере по моим двум пунктам точно не было.

А у вас какие?)

У меня 13. Экстеншены пока сыроваты для 14. Впрочем стоит ещё раз пройтись, как раз от одного проблемного отказался - может пора )

Мне кажэтся, что тогда это был бы state ACTIVE и оно бы добавлялось к query time.

Добавлять к query time было бы некорректно. Мне кажется нет, я бы не стал так делать.

И да, по дефолту в pgbouncer одна транзакцыя на клиента. В смысле -- клиент отработал транзакцыю, всё, можно отрправлять его в wait и подбирать следующего. А здесь, видимо, вообще autocommit, так что получается, что соединение освобождается сразу после каждого statement.

https://github.com/pgbouncer/pgbouncer/blob/491625a23488b5a2a30e50c58ad439aed04771ce/etc/pgbouncer.ini#L143 Я неправильный термин использовал, видимо отсюда недопонимания. По-умолчанию конфиг предлагает пулинг сессий. И тут явно сказано - освобождается after client disconnects.

[databases] postgres = host=127.0.0.1 port=5432 dbname=postgres * = host=127.0.0.1 port=5432 [pgbouncer] logfile = /var/log/pgbouncer/pgbouncer.log pidfile = /var/run/pgbouncer/pgbouncer.pid listen_addr = 10.0.0.32 listen_port = 6432 unix_socket_dir = /var/run/postgresql auth_type = md5 auth_file = /etc/pgbouncer/userlist.txt admin_users = postgres ignore_startup_parameters = extra_float_digits,geqo pool_mode = session server_reset_query = DISCARD ALL max_client_conn = 10000 default_pool_size = 20 reserve_pool_size = 1 reserve_pool_timeout = 1 max_db_connections = 1000 pkt_buf = 8192 listen_backlog = 4096 log_connections = 0 log_disconnections = 0 мой конфиг если что:)

default_pool_size бы повысить

зачем?

У вас пул исчерпался. Вероятность 99.9%.

100% )

Аля больше 10000 конекшинов было?

Нет. Больше 20 )

у pgbouncer'a туговато с неймингом. Лучше открыть его доку по нему и через show pools постараться осмыслить его цифры. У вас лимит 20 коннектов

Оу.. я все не так понимал.. а сколько вы обычно ставите?

у нас по-разному. От 20 до 100 в пуле. Просто несколько юзеров под разные задачи/приложения. Каждый в своем пуле живет

Прям поворот.. что б изменить конфигурацию без разрыва соединения systemctl reload pgbouncer? И проект довольно не нагруженный, а что тогда на нагруженных проектах делают

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

Эх, поищу может статьи толковые есть, прочтение доки не дало сильных результатов(

Я даже от безысходности поставил pool_mode = transaction

мы кстати на нем живем. Но тут от задач надо отталкиваться

Ну сегодня в обед(пик нагрузки) буду смотреть на статы и думать, что делать дальше. Жаль, что нету динамического обновления инфы аля как htop

гляньте в show pools, там будет озарение скорее всего )

Ок) спасибо за все, теперь хоть понимаю суть проблемы

Ну, так вопрос -- почему он исчерпался, если суммарно там всё работало десятую секунды за минуту.

Потому что мы не знаем сколько оно работало. Мы знаем сколько запросы выполнялись, а сколько клиент держал коннект - не знаем, этого нет в логе. Тут действительно могут помочь дампы или логи приложения.