ReSQL.ru
     
powered by simpleCommunicator - 2.0.53     © 2025 Programmizd 02
Мобильная версия    Контакт    Правила    FAQ    Помощь
Доб. в избранное | Игнор. тему | Прикреп. тему | Пометить прочит. / непрочит. | Фильтр
Форумы / PostgreSQL [игнор отключен] [закрыт для гостей] / вопрос за автовакуум
12 сообщений из 12, страница 1 из 1
вопрос за автовакуум
    #39635769
gav21
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
gav21
Участник
Привет
Есть таблица с высокой частотой апдейта ~2500 update/sec
autovacuum_vacuum_scale_factor = 0.05
autovacuum_analyze_threshold = 50
select count(*) from t
31488384

Каждые 10 мин автовакуум просыпается и вычищает мертвяков (вычищаться должно около 1 млн).
Однако я вижу нестыковки в логах АВ, и в во вьюхе pg_stat_user_tables
типичная запись лога АВ для этой таблицы:
Код: plsql
1.
2.
3.
4.
5.
6.
2018-04-25 07:05:00 MSK    32078  LOG:  automatic vacuum of table "t": index scans: 1
        pages: 0 removed, 549695 remain, 0 skipped due to pins, 51041 skipped frozen
        tuples: 27060 removed, 32632164 remain, 19326 are dead but not yet removable
        buffer usage: 662246 hits, 1301286 misses, 14424 dirtied
        avg read rate: 112.518 MB/s, avg write rate: 1.247 MB/s
        system usage: CPU 5.83s/12.96u sec elapsed 90.35 sec



Я подловил момент когда вакуум закончил работать по этой таблице и сразу запросил вьюху pg_stat_user_tables. Она показала, что все было вычищено (т.е более 1 млн строк), а лог АВ пишет про 27 тыс.
Кто врет?
p.s создается впечатление что миллион строк затерялся в "remain", но почему такая нестыковка?
PG 9.6.5
...
Рейтинг: 0 / 0
25.04.2018, 07:35
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39635790
gav21
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
gav21
Участник
Дождался когда накопится 1 млн мертвых и запустил ручной вакум
Код: plsql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
39.
40.
vacuum verbose t
INFO:  vacuuming "t"
INFO:  scanned index "t_pk" to remove 1029647 row versions
DETAIL:  CPU 1.16s/3.33u sec elapsed 4.50 sec
INFO:  scanned index "t_id_i" to remove 1029647 row versions
DETAIL:  CPU 2.60s/4.13u sec elapsed 6.73 sec
INFO:  scanned index "t_req_at_i" to remove 1029647 row versions
DETAIL:  CPU 0.96s/3.39u sec elapsed 4.35 sec
INFO:  "t": removed 1029647 row versions in 31913 pages
DETAIL:  CPU 0.04s/0.42u sec elapsed 0.68 sec
INFO:  index "t_pk" now contains 31532285 row versions in 352092 pages
DETAIL:  919855 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t_id_i" now contains 31547157 row versions in 789100 pages
DETAIL:  896607 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t_req_at_i" now contains 31557054 row versions in 262979 pages
DETAIL:  1029120 index row versions were removed.
75722 index pages have been deleted, 69837 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  "t": found 31195 removable, 3726281 nonremovable row versions in 59753 out of 549695 pages
DETAIL:  10755 dead row versions cannot be removed yet.
There were 12516177 unused item pointers.
Skipped 1 page due to buffer pins.
0 pages are entirely empty.
CPU 5.02s/11.88u sec elapsed 17.13 sec.
INFO:  vacuuming "pg_toast.pg_toast_32170"
INFO:  index "pg_toast_32170_index" now contains 0 row versions in 1 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  "pg_toast_32170": found 0 removable, 0 nonremovable row versions in 0 out of 0 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
Skipped 0 pages due to buffer pins.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
VACUUM



Тут все сходится.
...
Рейтинг: 0 / 0
25.04.2018, 08:06
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636142
Синий Слон
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Синий Слон
Участник
Вакуум не может все вычистить, мож данные еще какой-то сессии нужны.
...
Рейтинг: 0 / 0
25.04.2018, 16:00
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636494
gav21
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
gav21
Участник
Синий Слон,

проблема не в том, что АВ не очистил.
А в том, что он очистил > 1млн, а залогировал 27к
...
Рейтинг: 0 / 0
26.04.2018, 07:18
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636693
Alexius
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Alexius
Участник
gav21,

а не может быть, что между замерами автовакуум на самом деле запускался несколько раз? но прерывался в процессе (если например кто-то запрашивает access exclusive lock на таблицу, обычные автовакуумы прерываются). в логах при этом должны быть строки вида 'canceling autovacuum task'.
...
Рейтинг: 0 / 0
26.04.2018, 12:28
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636702
gav21
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
gav21
Участник
Alexius,

отменных АВ в логе нет.
а не autoanalyze ли чистит попутно и не сообщает подробностей?
Код: plsql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
2018-04-26 12:08:40 MSK    5964  LOG:  automatic analyze of table "t" system usage: CPU 0.54s/0.68u sec elapsed 12.82 sec
2018-04-26 12:11:36 MSK    7192  LOG:  automatic analyze of table "t" system usage: CPU 0.49s/0.79u sec elapsed 8.50 sec
2018-04-26 12:14:37 MSK    7793  LOG:  automatic analyze of table "t" system usage: CPU 0.45s/0.69u sec elapsed 8.74 sec
2018-04-26 12:17:48 MSK    8966  LOG:  automatic analyze of table "t" system usage: CPU 0.60s/0.81u sec elapsed 11.36 sec
2018-04-26 12:22:10 MSK    10084  LOG:  automatic vacuum of table "t": index scans: 1
        pages: 0 removed, 549695 remain, 0 skipped due to pins, 45320 skipped frozen
        tuples: 43582 removed, 33820042 remain, 12562 are dead but not yet removable
        buffer usage: 712577 hits, 1278491 misses, 15484 dirtied
        avg read rate: 98.269 MB/s, avg write rate: 1.190 MB/s
        system usage: CPU 8.37s/15.48u sec elapsed 101.64 sec
...
Рейтинг: 0 / 0
26.04.2018, 12:44
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636715
gav21
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
gav21
Участник
gav21,
хотя нет
на момент 12:17:48, кол-во мертвых строк росло а не уменьшалось...
...
Рейтинг: 0 / 0
26.04.2018, 12:54
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636732
Alexius
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Alexius
Участник
gav21,

а можно показать 2 вывода с pg_stat_user_tables до и после автовакуума вместе с выводом логов автовакуума? интересно какая доля hot update и какой порядок числа апдейтов на строку (не обновляем ли мы одну и ту же строку очень много раз в секунду).
...
Рейтинг: 0 / 0
26.04.2018, 13:18
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636755
gav21
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
gav21
Участник
Таблица - очередь, делается инсерт, потом эти строки много-много раз меняют статус. Но в парадигме Postgres, каждый апдейт это ведь delete+insert, так ведь?
Даже если мы будем миллион раз в секунду обновлять одну и ту же строку.
Хот апдейтов там нет, от слова совсем.

Вот снимки перед запуском АВ, и сразу после

Код: plsql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
39.
40.
41.
42.
43.
44.
45.
46.
47.
48.
49.
50.
51.
52.
53.
54.
55.
56.
57.
58.
59.
60.
# select now(),* from pg_stat_user_tables where relname = 't';
-[ RECORD 1 ]-------+------------------------------
now                 | 2018-04-26 13:36:07.707784+03
relid               | 32170
schemaname          | public
relname             | t
seq_scan            | 151371
seq_tup_read        | 132672944
idx_scan            | 4525649653
idx_tup_fetch       | 9402703531
n_tup_ins           | 33785210
n_tup_upd           | 4502119094
n_tup_del           | 0
n_tup_hot_upd       | 0
n_live_tup          | 33815482
n_dead_tup          | 1926735
n_mod_since_analyze | 492583
last_vacuum         | 2018-04-25 07:51:33.307364+03
last_autovacuum     | 2018-04-26 13:21:53.931788+03
last_analyze        | 2018-04-01 19:40:08.063981+03
last_autoanalyze    | 2018-04-26 13:32:15.845189+03
vacuum_count        | 5
autovacuum_count    | 8628
analyze_count       | 2
autoanalyze_count   | 13407


# select now(),* from pg_stat_user_tables where relname = 't';
-[ RECORD 1 ]-------+------------------------------
now                 | 2018-04-26 13:38:07.320179+03
relid               | 32170
schemaname          | public
relname             | t
seq_scan            | 151371
seq_tup_read        | 132672944
idx_scan            | 4525898773
idx_tup_fetch       | 9403224417
n_tup_ins           | 33789071
n_tup_upd           | 4502366855
n_tup_del           | 0
n_tup_hot_upd       | 0
n_live_tup          | 33830290
n_dead_tup          | 296035
n_mod_since_analyze | 49793
last_vacuum         | 2018-04-25 07:51:33.307364+03
last_autovacuum     | 2018-04-26 13:37:28.072735+03
last_analyze        | 2018-04-01 19:40:08.063981+03
last_autoanalyze    | 2018-04-26 13:37:44.353704+03
vacuum_count        | 5
autovacuum_count    | 8629
analyze_count       | 2
autoanalyze_count   | 13408


2018-04-26 13:37:28 MSK    12076  LOG:  automatic vacuum of table "t": index scans: 1
        pages: 0 removed, 549695 remain, 0 skipped due to pins, 43363 skipped frozen
        tuples: 53866 removed, 33836682 remain, 13483 are dead but not yet removable
        buffer usage: 801664 hits, 1280506 misses, 7528 dirtied
        avg read rate: 96.220 MB/s, avg write rate: 0.566 MB/s
        system usage: CPU 10.54s/16.85u sec elapsed 103.96 sec
...
Рейтинг: 0 / 0
26.04.2018, 13:48
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636856
Alexius
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Alexius
Участник
gav21,

спасибо, я подозреваю что это какой-то баг в отображении в логах в числе tuples removed, надо смотреть vacuumlazy.c (lazy_scan_heap, lazy_vacuum_heap). я пока сходу до конца не разобрался.

каждый апдейт это ведь delete+insert, так ведь?
да
...
Рейтинг: 0 / 0
26.04.2018, 16:16
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636892
tip78
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
tip78
Участник
gav21Таблица - очередь, делается инсерт, потом эти строки много-много раз меняют статус. Но в парадигме Postgres, каждый апдейт это ведь delete+insert, так ведь?
Даже если мы будем миллион раз в секунду обновлять одну и ту же строку.
Хот апдейтов там нет, от слова совсем.
пардон, а почему не стали в редисе/мемкешеде очередь делать ?
...
Рейтинг: 0 / 0
26.04.2018, 16:59
| Ответить | Цитировать | Написать  
вопрос за автовакуум
    #39636968
gav21
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
gav21
Участник
tip78,
вопрос архитекурный - к сожалению (или к счастью) не ко мне :)
что дали, то и поддерживаю
...
Рейтинг: 0 / 0
26.04.2018, 18:48
| Ответить | Цитировать | Написать  
12 сообщений из 12, страница 1 из 1
Форумы / PostgreSQL [игнор отключен] [закрыт для гостей] / вопрос за автовакуум
Целевая тема:
Создать новую тему:
Автор:
Закрыть
Цитировать
Найденые пользователи ...
Разблокировать пользователей ...
Читали тему (0):
Читали форум (0):
Пользователи онлайн (0):
Польз. соглашение
NoSQL.ru       Новости, Чат       Фотоальбом: Участники, Встречи
Закрыть
start [/forum/topic.php?fid=53&msg=39636693&tid=1995805]:
 0ms
get settings:
 11ms
get forum list:
 13ms
check forum access:
 3ms
check topic access:
 3ms
track hit:
 25ms
get topic data:
 10ms
get forum data:
 2ms
get page messages:
 44ms
get tp. blocked users:
 1ms
others: 15ms
total:  127ms
созд. / загр.: 127ms
x
x
Закрыть


Просмотр
0 / 0
Close
Debug Console [Select Text]