Обсуждение: Autovacuum not keeping up. (PG 9.2.9)
Hi. I have a large database with a message queue table, that has high activity. The database supports 1-300 client connection concurrently, having transactions open in up to 30 minutes each. Recently I am seeing autuvacuum being issued, but it takes ages to get through the message queue table, with strace showing waiting for semop's for 10's to 100's of seconds. There is no sign in pg_locks about this lock activity, so it is really hard to digest down to the offending processes. Currently autovacuum has been activly running for about 3 days on this table, not finishing a single run. I have seen this before and one option is to pull down everything, vacuum full or cluster the tables and start up again. But I would really like to get to a permanent solution here. Autovacuum for other tables are going fine, so it seems to be related to the high-activity of this table. PG 9.2.9 Thanks.
jesper@krogh.cc wrote: > Hi. > > I have a large database with a message queue table, that has high > activity. The database supports 1-300 client connection concurrently, > having transactions open in up to 30 minutes each. > > Recently I am seeing autuvacuum being issued, but it takes > ages to get through the message queue table, with strace showing waiting > for semop's for 10's to 100's of seconds. Do you have data on how relfrozenxid advances for that table? Vacuuming needs to grab a "cleanup lock" on each page it's going to vacuum, which is a special kind of lock that requires that no other process is even looking at the page at that moment (we call this "to have the page pinned"), which is even weaker than having a shared lock on the page. If traffic to some pages is high, it might be difficult for vacuum to acquire this. Normally, vacuum doesn't break much sweat about this: if it cannot acquire the cleanup lock, it ignores the page, keeps calm and carries on. But if it's a for-wraparound vacuuming, it will need to wait until it is able to acquire cleanup lock. I think one idea might be to try to manually vacuum the table once in a while with a reduced value of min_freeze_table_age. This will cause a full table scan (i.e. cleanup lock for all pages is waited for), which decreases the "frozen xid age", which moves the need to do this again further in the future; so the autovacuum-invoked vacuums will be able to skip the pages on which it cannot get cleanup lock. Another idea is to increase min_freeze_table_age for the queue table through ALTER TABLE, the idea being that you can delay forced vacuuming of hot pages for long enough that they can wait until they have cooled off. Default value is 150 million transactions, which you can raise tenfold and even higher. See http://www.postgresql.org/docs/9.2/static/runtime-config-client.html#GUC-VACUUM-FREEZE-TABLE-AGE The other idea is that heap truncation is what's causing the problem, but AFAICS that uses conditional lock acquisition so you shouldn't be seeing stalls in semop(). -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Training & Services
Sent from my iPad > On Jul 31, 2014, at 9:40 AM, Alvaro Herrera <alvherre@2ndquadrant.com> wrote: > > jesper@krogh.cc wrote: >> Hi. >> >> I have a large database with a message queue table, that has high >> activity. The database supports 1-300 client connection concurrently, >> having transactions open in up to 30 minutes each. >> >> Recently I am seeing autuvacuum being issued, but it takes >> ages to get through the message queue table, with strace showing waiting >> for semop's for 10's to 100's of seconds. > > Do you have data on how relfrozenxid advances for that table? > > Vacuuming needs to grab a "cleanup lock" on each page it's going to > vacuum, which is a special kind of lock that requires that no other > process is even looking at the page at that moment (we call this "to > have the page pinned"), which is even weaker than having a shared lock > on the page. If traffic to some pages is high, it might be difficult > for vacuum to acquire this. > > Normally, vacuum doesn't break much sweat about this: if it cannot > acquire the cleanup lock, it ignores the page, keeps calm and carries > on. But if it's a for-wraparound vacuuming, it will need to wait until > it is able to acquire cleanup lock. > > I think one idea might be to try to manually vacuum the table once in a > while with a reduced value of min_freeze_table_age. This will cause a > full table scan (i.e. cleanup lock for all pages is waited for), which > decreases the "frozen xid age", which moves the need to do this again > further in the future; so the autovacuum-invoked vacuums will be able to > skip the pages on which it cannot get cleanup lock. > > Another idea is to increase min_freeze_table_age for the queue table > through ALTER TABLE, the idea being that you can delay forced vacuuming > of hot pages for long enough that they can wait until they have cooled > off. Default value is 150 million transactions, which you can raise > tenfold and even higher. > > See > http://www.postgresql.org/docs/9.2/static/runtime-config-client.html#GUC-VACUUM-FREEZE-TABLE-AGE > > > The other idea is that heap truncation is what's causing the problem, > but AFAICS that uses conditional lock acquisition so you shouldn't be > seeing stalls in semop(). > > -- > Álvaro Herrera http://www.2ndQuadrant.com/ > PostgreSQL Development, 24x7 Support, Training & Services > > > -- > Sent via pgsql-admin mailing list (pgsql-admin@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-admin You should probably consider, if you haven't done already, to partition this table. Without knowing what's adding new transactions,it sounds like you could break up the table with a timestamp rule. That would permit autovacuum to do partsof the table much quicker, and only once. -/ Jay
> jesper@krogh.cc wrote: >> Hi. >> >> I have a large database with a message queue table, that has high >> activity. The database supports 1-300 client connection concurrently, >> having transactions open in up to 30 minutes each. >> >> Recently I am seeing autuvacuum being issued, but it takes >> ages to get through the message queue table, with strace showing waiting >> for semop's for 10's to 100's of seconds. > > Do you have data on how relfrozenxid advances for that table? Not really, how would you normally pick that out? 2014-08-01 10:49:39.171 db=# select relname, age(relfrozenxid), relfrozenxid FROM pg_class WHERE relkind = 'r' and relname = 'job'; relname | age | relfrozenxid ---------+-----------+-------------- job | 111893622 | 796259097 (1 row) Time: 1.913 ms This shouldn't qualify for a freeze vacuum, should it? > Vacuuming needs to grab a "cleanup lock" on each page it's going to > vacuum, which is a special kind of lock that requires that no other > process is even looking at the page at that moment (we call this "to > have the page pinned"), which is even weaker than having a shared lock > on the page. If traffic to some pages is high, it might be difficult > for vacuum to acquire this. Based on strace output this looks excactly like whats going on, there are some activity, then it pauses for some time then continues. > Normally, vacuum doesn't break much sweat about this: if it cannot > acquire the cleanup lock, it ignores the page, keeps calm and carries > on. But if it's a for-wraparound vacuuming, it will need to wait until > it is able to acquire cleanup lock. Can I force it to tell me if it does the for-wraparound cleanup or normal? > I think one idea might be to try to manually vacuum the table once in a > while with a reduced value of min_freeze_table_age. This will cause a > full table scan (i.e. cleanup lock for all pages is waited for), which > decreases the "frozen xid age", which moves the need to do this again > further in the future; so the autovacuum-invoked vacuums will be able to > skip the pages on which it cannot get cleanup lock. > > Another idea is to increase min_freeze_table_age for the queue table > through ALTER TABLE, the idea being that you can delay forced vacuuming > of hot pages for long enough that they can wait until they have cooled > off. Default value is 150 million transactions, which you can raise > tenfold and even higher. > > See > http://www.postgresql.org/docs/9.2/static/runtime-config-client.html#GUC-VACUUM-FREEZE-TABLE-AGE I tried to read through that, but that is a GUC not a storage level parameter. So I (hopefully correct) figured out that the storage level parameter that need to be set were autovacuum_freeze_min_age and set that one to 1.000.000.000 for the table. But apparently it didnt cause any changes. It is still waiting for the lock. Is a database restart required after setting storage parameters, or will autovacuum pick up the new one when it starts over with the table. > The other idea is that heap truncation is what's causing the problem, > but AFAICS that uses conditional lock acquisition so you shouldn't be > seeing stalls in semop(). That should only be once per vacuuming .. right? That doesn't fit the pattern either. -- Jesper
>> jesper@krogh.cc wrote:
>>> Hi.
>>>
>>> I have a large database with a message queue table, that has high
>>> activity. The database supports 1-300 client connection concurrently,
>>> having transactions open in up to 30 minutes each.
>>>
>>> Recently I am seeing autuvacuum being issued, but it takes
>>> ages to get through the message queue table, with strace showing
>>> waiting
>>> for semop's for 10's to 100's of seconds.
>>
>> Do you have data on how relfrozenxid advances for that table?
>
> Not really, how would you normally pick that out?
> 2014-08-01 10:49:39.171 db=# select relname, age(relfrozenxid),
> relfrozenxid FROM pg_class WHERE relkind = 'r' and relname = 'job';
> relname | age | relfrozenxid
> ---------+-----------+--------------
> job | 111893622 | 796259097
> (1 row)
>
> Time: 1.913 ms
>
> This shouldn't qualify for a freeze vacuum, should it?
>
>> Vacuuming needs to grab a "cleanup lock" on each page it's going to
>> vacuum, which is a special kind of lock that requires that no other
>> process is even looking at the page at that moment (we call this "to
>> have the page pinned"), which is even weaker than having a shared lock
>> on the page. If traffic to some pages is high, it might be difficult
>> for vacuum to acquire this.
>
> Based on strace output this looks excactly like whats going on, there are
> some activity, then it pauses for some time then continues.
Very "scientifically" i have captured this strace output of the autovacuum
pid. This is a 10 minute trace (600s), total waiting time for
semop(2850903 in those minutes are not less than 485s, (last semop not
counted in).
jk@srv01:~$ sudo timelimit -t 600 -T 10 strace -T -p 36839 2>&1 | grep -v
0.000
Process 36839 attached - interrupt to quit
semop(2850903, {{11, -1, 0}}, 1) = 0 <14.403021>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001100>
write(367, "\\D\1\0\30p\325\37\1\0\0\0t\6\200\6\360\37\4 \0\0\0\0\340\237
\0\200\206 \0"..., 8192) = 8192 <0.002371>
semop(2850903, {{11, -1, 0}}, 1) = 0 <38.871837>
semop(2850903, {{11, -1, 0}}, 1) = 0 <17.111822>
semop(2850903, {{11, -1, 0}}, 1) = 0 <22.438373>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001095>
semop(2850903, {{11, -1, 0}}, 1) = 0 <32.521132>
semop(2261061, {{8, 1, 0}}, 1) = 0 <0.001601>
semop(2850903, {{11, -1, 0}}, 1) = 0 <10.740716>
semop(1179684, {{9, 1, 0}}, 1) = 0 <0.001900>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001106>
semop(2850903, {{11, -1, 0}}, 1) = 0 <26.610242>
semop(2850903, {{11, -1, 0}}, 1) = 0 <21.911487>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001060>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.001694>
semop(2850903, {{11, -1, 0}}, 1) = 0 <128.996370>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001390>
semop(2850903, {{11, -1, 0}}, 1) = 0 <20.553280>
read(367, "\\D\1\0H\2107\357\1\0\0\0|\3`\22\360\37\4 \0\0\0\0\340\237
\0\320\237 \0"..., 8192) = 8192 <0.001670>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001357>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.001046>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.001352>
semop(2850903, {{11, -1, 0}}, 1) = 0 <44.311165>
semop(2850903, {{11, -1, 0}}, 1) = 0 <79.246222>
read(367, "]D\1\0\10\"\3-\1\0\0\0|\3`\22\360\37\4 \0\0\0\0\340\237
\0\320\237 \0"..., 8192) = 8192 <0.001124>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001093>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001098>
semop(2850903, {{11, -1, 0}}, 1) = 0 <8.440753>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.001390>
semop(2850903, {{11, -1, 0}}, 1) = 0 <27.041010>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.001679>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.004053>
semop(2850903, {{11, -1, 0}}, 1) = 0 <9.158556>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.001015>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001113>
write(367, "]D\1\0\360#\177x\1\0\0\0\344\4\300\f\360\37\4 \0\0\0\0\340\237
\0\300\214 \0"..., 8192) = 8192 <0.001474>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.002450>
semop(655380, {{7, 1, 0}}, 1) = 0 <0.002245>
read(367, "]D\1\0\270\311\247\221\1\0\0\0D\5@\v\360\37\4 \0\0\0\0\340\237
\0@\213 \0"..., 8192) = 8192 <0.001339>
semop(2850903, {{11, -1, 0}}, 1) = 0 <0.002029>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001078>
select(0, NULL, NULL, NULL, {0, 1000}) = 0 (Timeout) <0.001079>
semop(2850903, {{11, -1, 0}}, 1timelimit: sending warning signal 15
<unfinished ...>
Process 36839 detached
jk@srv01:~$
Is there any clue in that the semaphorenumber it waits on is excactly the
same all the time? (the <> to the right are timings in seconds.
--
Jesper
jesper@krogh.cc wrote: > > jesper@krogh.cc wrote: > >> Hi. > >> > >> I have a large database with a message queue table, that has high > >> activity. The database supports 1-300 client connection concurrently, > >> having transactions open in up to 30 minutes each. > >> > >> Recently I am seeing autuvacuum being issued, but it takes > >> ages to get through the message queue table, with strace showing waiting > >> for semop's for 10's to 100's of seconds. > > > > Do you have data on how relfrozenxid advances for that table? > > Not really, how would you normally pick that out? > 2014-08-01 10:49:39.171 db=# select relname, age(relfrozenxid), > relfrozenxid FROM pg_class WHERE relkind = 'r' and relname = 'job'; > relname | age | relfrozenxid > ---------+-----------+-------------- > job | 111893622 | 796259097 > (1 row) > > Time: 1.913 ms > > This shouldn't qualify for a freeze vacuum, should it? I misspoke -- I was referring to a full-table scan, not a for-wraparound vacuum. A full table scan is triggered when the table reaches the freeze_table_age. > > Normally, vacuum doesn't break much sweat about this: if it cannot > > acquire the cleanup lock, it ignores the page, keeps calm and carries > > on. But if it's a for-wraparound vacuuming, it will need to wait until > > it is able to acquire cleanup lock. > > Can I force it to tell me if it does the for-wraparound cleanup or normal? Don't think so, unless you're open to patching the source. > > See > > http://www.postgresql.org/docs/9.2/static/runtime-config-client.html#GUC-VACUUM-FREEZE-TABLE-AGE > > I tried to read through that, but that is a GUC not a storage level > parameter. So I (hopefully correct) figured out that the storage level > parameter that need to be set were autovacuum_freeze_min_age and set that > one to 1.000.000.000 for the table. But apparently it didnt cause any > changes. It is still waiting for the lock. Is a database restart required > after setting storage parameters, or will autovacuum pick up the new one > when it starts over with the table. It is autovacuum_freeze_table_age. You don't need to restart; autovacuum picks up new values from storage parameters immediately. (Workers that are already running will ignore changes for the table they are vacuuming at that moment.) > > The other idea is that heap truncation is what's causing the problem, > > but AFAICS that uses conditional lock acquisition so you shouldn't be > > seeing stalls in semop(). > > That should only be once per vacuuming .. right? That doesn't fit the > pattern either. There's a retry loop in there (see src/backend/commands/vacuumlazy.c): /* * Timing parameters for truncate locking heuristics. * * These were not exposed as user tunable GUC values because it didn't seem * that the potential for improvement was great enough to merit the cost of * supporting them. */ #define VACUUM_TRUNCATE_LOCK_CHECK_INTERVAL 20 /* ms */ #define VACUUM_TRUNCATE_LOCK_WAIT_INTERVAL 50 /* ms */ #define VACUUM_TRUNCATE_LOCK_TIMEOUT 5000 /* ms */ ... while (true) { if (ConditionalLockAcquire( ... )) break; if (++lock_retry > (VACUUM_TRUNCATE_LOCK_TIMEOUT / VACUUM_TRUNCATE_LOCK_WAIT_INTERVAL)) { /* give up */ return; } pg_usleep(VACUUM_TRUNCATE_LOCK_WAIT_INTERVAL); } Note the sleeps are always of the same duration. -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Training & Services