|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
Доброго времени суток) Столкнулся с непонятными тормозами запроса, большая база, сложный поисковый запрос, на старом сервере все работает хорошо, на новом вылезла проблема. Версия и конфигурация постгреса одинаковые - постгрес 12.2 старый на Debian 8, новый на Debian 10. База грубо одна и та же (на старом менее обслуженная). Эксплейн запроса на старом: Result (cost=8096.36..8101.46 rows=5 width=581) (actual time=105.865..115.639 rows=9 loops=1) Buffers: shared hit=29129 -> Sort (cost=8096.36..8096.37 rows=5 width=453) (actual time=95.699..95.702 rows=9 loops=1) ... Он же на новом: Result (cost=8884.74..8890.86 rows=6 width=581) (actual time=525.709..4020.367 rows=8 loops=1) Buffers: shared hit=10490 -> Sort (cost=8884.74..8884.76 rows=6 width=453) (actual time=18.989..18.995 rows=8 loops=1) ... Т.е. планы одинаковые, почти везде используются индексы, все норм, отличие только в последней операции Result, ее реальное время на новом сервере непомерно большое, хотя все предыдущие шаги (Sort и т.д.) нормальные. В результате запрос на новом сервере отрабатывает вместо 0.2 сек целых 4 сек. Непонятно откуда берутся такие тормоза в конце (Result). Есть какие нибудь идеи? в какую сторону хотябы смотреть? ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 00:27 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
tmc, Для начала включить track_io_timing и далее всегда делать explain (analyze, costs, buffers, timing) а не просто explain analyze тогда и понятнее станет ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 09:27 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
tmc, Добавьте verbose в explain, может какие-то подробности про ноду Result расскажет. ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 09:28 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
Добавил: При первом запросе: Result (cost=8004.65..8009.75 rows=5 width=581) (actual time=636.941..4670.860 rows=9 loops=1) Output: vtb3.is_nom_limit, vtb3.sort_quantity, vtb3.prod_id, vtb3.mult_sale, vtb3.quantity... Buffers: shared hit=12420 read=2370 I/O Timings: read=9.907 -> Sort (cost=8004.65..8004.66 rows=5 width=453) (actual time=50.695..50.700 rows=9 loops=1) I/O Timings: read=8.972 ... При последующих: Result (cost=8004.65..8009.75 rows=5 width=581) (actual time=517.473..4473.986 rows=9 loops=1) Output: vtb3.is_nom_limit, vtb3.sort_quantity, vtb3.prod_id, vtb3.mult_sale, vtb3.quantity... Buffers: shared hit=11285 -> Sort (cost=8004.65..8004.66 rows=5 width=453) (actual time=18.212..18.217 rows=9 loops=1) ... Видно что пока в оперативе данных нет, идет чтение диска, потом его уже нет, ну и поля выводить начал, но вопрос откуда появляются тормоза в Result так и остается ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 16:01 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
tmc, Тогда показывайте полный план и полный запрос а не огрызки. ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 16:06 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
Да тут та еще портянка, вот: https://vk.com/doc86723927_552123991 https://vk.com/doc86723927_552123961 ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 17:01 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
Насколько я понимаю все остальное вложено в верхнюю ноду Sort, и уже не принципиально, т.к. стоимость Sort нормальная, а Result из нее непонятно как такой получается ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 17:06 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
tmc Насколько я понимаю все остальное вложено в верхнюю ноду Sort, и уже не принципиально, т.к. стоимость Sort нормальная, а Result из нее непонятно как такой получается скорее всего result у вас это вычисление Код: plsql 1. 2. 3. 4.
я бы сделал begin; ваш запрос без explain analyze; SELECT * FROM pg_stat_xact_user_functions ORDER BY total_time DESC; abort; и сравнил бы выводы pg_stat_xact_user_functions в двух случаях если где то есть большая разница по total_time - начал бы копать туда. ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 17:52 |
|
Неожиданные тормоза запроса
|
|||
---|---|---|---|
#18+
Maxim Boguk, вы красавчик, до меня бы не дошло что раз эти функции не используются в сортировке, то постгрес откладывает их вычисление наверх) Далее методом последовательного закоменчивания было установлено что тормозит bs.get_news_act(), ее план: ... -> Seq Scan on t_news_act_excepts nae (cost=0.00..30.40 rows=2040 width=8) (never executed) Planning Time: 24.225 ms JIT: Functions: 48 Options: Inlining true, Optimization true, Expressions true, Deforming true Timing: Generation 3.855 ms, Inlining 44.581 ms, Optimization 285.519 ms, Emission 195.997 ms, Total 529.952 ms Execution Time: 584.460 ms Вот это думаю наоптимизировали.. пошел выключил JIT в конфиге и все залетало, а на старом сервере JIT хоть и включен, но т.к. он использует системный LLVM, которого в той ОС нет, то и проблемы небыло. ... |
|||
:
Нравится:
Не нравится:
|
|||
27.05.2020, 19:57 |
|
|
start [/forum/topic.php?fid=53&msg=39962972&tid=1994668]: |
0ms |
get settings: |
9ms |
get forum list: |
14ms |
check forum access: |
4ms |
check topic access: |
4ms |
track hit: |
38ms |
get topic data: |
11ms |
get forum data: |
3ms |
get page messages: |
49ms |
get tp. blocked users: |
1ms |
others: | 260ms |
total: | 393ms |
0 / 0 |