--00151758f42c2080ca04899e83b5
Content-Type: text/plain; charset=ISO-8859-1

Hi,

last ween i've seen a blocking "automatic vacuum".
as i understood, this is not supposed to happen. in the past i saw vacuum
processes disappear, in case of the need of a lock.


this is the relvant extract from the log and the database:
2010-06-18 18:33:36.011 CEST 172.19.5.34(57414) gc:29274
143897560 LOG: process 29274 still waiting for RowExclusiveLock on
relation 42964239 of database 19759903 after 1002.601 ms
....
2010-06-18 19:23:43.898 CEST :20892 0 LOG: automatic
vacuum of table "gd.pg_toast.pg_toast_42964236": index scans: 1
pages: 1469113 removed, 288899 remain
tuples: 369645 removed, 396719 remain
system usage: CPU 5.46s/0.85u sec elapsed 13785.76 sec
2010-06-18 19:23:43.899 CEST 172.19.5.22(45561) gc:315
143897590 LOG: process 315 acquired RowExclusiveLock on relation
42964239 of database 19759903 after 3007903.169 ms
2010-06-18 19:23:43.920 CEST 172.19.5.22(45561) gc:315
143897590 LOG: duration: 3007924.883 ms execute <unnamed>: insert
into SHARED_GAMESET .....

gd=# select oid,* from pg_class where reltoastrelid=42964239;
relname | relnamespace | reltype | relowner | relam | relfilenode |
reltablespace | relpages | reltuples | reltoastrelid | reltoastidxid |
relhasindex | relisshared | relistemp | relkind | relnatts | relchecks | rel
hasoids | relhaspkey | relhasrules | relhastriggers | relhassubclass |
relfrozenxid | relacl | reloptions
----------------+--------------+----------+----------+------ -+-------------+---------------+----------+-------------+--- ------------+---------------+-------------+-------------+--- --------+---------+----------+-----------+----
--------+------------+-------------+----------------+------- ---------+--------------+----------------------------------- -----+------------
shared_gameset | 19760303 | 42964238 | 16443 | 0 | 42964236
| 0 | 143715 | 1.96642e+06 | 42964239 | 0 |
t | f | f | r | 4 | 0 | f
| t | f | f | f |
101290258 | {gdadm=arwdDxt/gdadm,gc=arwdDxt/gdadm} |
(1 row)



So what's this?
from my point of view the vacuum blocked inserts on this table for about 50
minutes.
Is this a bug?
Or do yuo see here a configuration issue?

best regards,
Uwe

Uwe Bartels
Systemarchitect - Freelancer
mailto: uwe.bartels at gmail.com

--00151758f42c2080ca04899e83b5
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

Hi,<br><br>last ween i've seen a blocking "automatic vacuum".=
<br>as i understood, this is not supposed to happen. in the past i saw vacu=
um processes disappear, in case of the need of a lock.<br><br><br>this is t=
he relvant extract from the log and the database:<br>
2010-06-18 18:33:36.011 CEST=A0=A0=A0 172.19.5.34(57414)=A0=A0=A0=A0=A0 gc:=
29274=A0=A0=A0=A0=A0=A0=A0 143897560=A0=A0=A0=A0=A0=A0 LOG:=A0 process 2927=
4 still waiting for RowExclusiveLock on relation 42964239 of database 19759=
903 after 1002.601 ms<br>...<br>2010-06-18 19:23:43.898 CEST=A0=A0=A0=A0=A0=
=A0=A0=A0=A0=A0=A0 :20892=A0 0=A0=A0=A0=A0=A0=A0 LOG:=A0 automatic vacuum o=
f table "gd.pg_toast.pg_toast_42964236": index scans: 1<br>
=A0=A0=A0=A0=A0=A0=A0 pages: 1469113 removed, 288899 remain<br>=A0=A0=A0=A0=
=A0=A0=A0 tuples: 369645 removed, 396719 remain<br>=A0=A0=A0=A0=A0=A0=A0 sy=
stem usage: CPU 5.46s/0.85u sec elapsed 13785.76 sec<br>2010-06-18 19:23:43=
..899 CEST=A0=A0=A0 172.19.5.22(45561)=A0=A0=A0=A0=A0 gc:315=A0 143897590=A0=
=A0=A0=A0=A0=A0 LOG:=A0 process 315 acquired RowExclusiveLock on relation 4=
2964239 of database 19759903 after 3007903.169 ms<br>
2010-06-18 19:23:43.920 CEST=A0=A0=A0 172.19.5.22(45561)=A0=A0=A0=A0=A0 gc:=
315=A0 143897590=A0=A0=A0=A0=A0=A0 LOG:=A0 duration: 3007924.883 ms=A0 exec=
ute <unnamed>: insert into SHARED_GAMESET .....<br><br>gd=3D# select =
oid,* from pg_class where reltoastrelid=3D42964239;<br>
=A0=A0=A0 relname=A0=A0=A0=A0 | relnamespace | reltype=A0 | relowner | rela=
m | relfilenode | reltablespace | relpages |=A0 reltuples=A0 | reltoastreli=
d | reltoastidxid | relhasindex | relisshared | relistemp | relkind | relna=
tts | relchecks | rel<br>
hasoids | relhaspkey | relhasrules | relhastriggers | relhassubclass | relf=
rozenxid |=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 relacl=A0=A0=A0=
=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 | reloptions <br>----------------+-=
-------------+----------+----------+-------+-------------+-- -------------+-=
---------+-------------+---------------+---------------+---- ---------+-----=
--------+-----------+---------+----------+-----------+----<br>
--------+------------+-------------+----------------+------- ---------+-----=
---------+----------------------------------------+--------- ---<br>=A0share=
d_gameset |=A0=A0=A0=A0 19760303 | 42964238 |=A0=A0=A0 16443 |=A0=A0=A0=A0 =
0 |=A0=A0=A0 42964236 |=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 0 |=A0=A0 14371=
5 | 1.96642e+06 |=A0=A0=A0=A0=A0 42964239 |=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=
=A0=A0 0 | t=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 | f=A0=A0=A0=A0=A0=A0=A0=A0=A0=
=A0 | f=A0=A0=A0=A0=A0=A0=A0=A0 | r=A0=A0=A0=A0=A0=A0 |=A0=A0=A0=A0=A0=A0=
=A0 4 |=A0=A0=A0=A0=A0=A0=A0=A0 0 | f=A0 <br>
=A0=A0=A0=A0=A0=A0=A0 | t=A0=A0=A0=A0=A0=A0=A0=A0=A0 | f=A0=A0=A0=A0=A0=A0=
=A0=A0=A0=A0 | f=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 | f=A0=A0=A0=A0=A0=
=A0=A0=A0=A0=A0=A0=A0=A0 |=A0=A0=A0 101290258 | {gdadm=3DarwdDxt/gdadm,gc=
=3DarwdDxt/gdadm} | <br>(1 row)<br><br><br><br>So what's this?<br>from =
my point of view the vacuum blocked inserts on this table for about 50 minu=
tes.<br>
Is this a bug?<br>Or do yuo see here a configuration issue?<br><br>best reg=
ards,<br>Uwe<br><br clear=3D"all">Uwe Bartels<br>Systemarchitect - Freelanc=
er<br>mailto: uwe.bartels at <a href=3D"http://gmail.com">gmail.com</a><br>
<br>

--00151758f42c2080ca04899e83b5--

Uwe Bartels <uwe.bartels [at] gmail.com> wrote:

> last ween i've seen a blocking "automatic vacuum".

What does SELECT version(); show?

-Kevin

--
Sent via pgsql-admin mailing list (pgsql-admin [at] postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

--0016e6dcf18c4be8e904899f3e1a
Content-Type: text/plain; charset=ISO-8859-1

# select version();

version
------------------------------------------------------------ ------------------------------------------------------
PostgreSQL 8.4.3 on x86_64-redhat-linux-gnu, compiled by GCC gcc (GCC)
4.1.2 20071124 (Red Hat 4.1.2-42), 64-bit
(1 row)



On 22 June 2010 15:53, Kevin Grittner <Kevin.Grittner [at] wicourts.gov> wrote:

> Uwe Bartels <uwe.bartels [at] gmail.com> wrote:
>
> > last ween i've seen a blocking "automatic vacuum".
>
> What does SELECT version(); show?
>
> -Kevin
>

--0016e6dcf18c4be8e904899f3e1a
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

# select version();<br>=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=
=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 =A0=A0=A0=A0=A0=
=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 version=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=
=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 =A0=A0=A0=A0=A0=
=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 <br>----------------------=
------------------------------------------------------------ ---------------=
-----------------<br>
=A0PostgreSQL 8.4.3 on x86_64-redhat-linux-gnu, compiled by GCC gcc (GCC) 4=
..1.2 20071124 (Red Hat 4.1.2-42), 64-bit<br>(1 row)<br><br clear=3D"all"><b=
r><br><div class=3D"gmail_quote">On 22 June 2010 15:53, Kevin Grittner <spa=
n dir=3D"ltr"><<a href=3D"mailto:Kevin.Grittner [at] wicourts.gov">Kevin.Grit=
tner [at] wicourts.gov</a>></span> wrote:<br>
<blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0pt 0pt 0.8ex; borde=
r-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;"><div class=3D"im"=
>Uwe Bartels <<a href=3D"mailto:uwe.bartels [at] gmail.com">uwe.bartels [at] gmail=
..com</a>> wrote:<br>

<br>
> last ween i've seen a blocking "automatic vacuum".<br>
<br>
</div>What does SELECT version(); show?<br>
<font color=3D"#888888"><br>
-Kevin<br>
</font></blockquote></div><br>

--0016e6dcf18c4be8e904899f3e1a--

Uwe Bartels <uwe.bartels [at] gmail.com> writes:
> last ween i've seen a blocking "automatic vacuum".
> as i understood, this is not supposed to happen. in the past i saw vacuum
> processes disappear, in case of the need of a lock.

What that sounds like is it was an anti-wraparound vacuum. Autovacuum
won't cancel those to avoid delaying other processes.

Now, RowExclusiveLock doesn't conflict with an autovacuum, so there is
more going on here than you've showed us. The other obvious question is
how did you get to the point where an anti-wraparound vacuum became
necessary.

I speculate that you are doing something that does conflict with vacuum
(ie, SHARE UPDATE EXCLUSIVE lock or higher), and are doing it so often
that regular autovacuum runs on the table never manage to complete.
This is very bad, because you're going to have a serious bloat problem
if autovac keeps getting canceled. You need to look at what sort of DDL
you are repetitively executing on that table, and find a way to do it a
lot less often.

regards, tom lane

--
Sent via pgsql-admin mailing list (pgsql-admin [at] postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

--0016e6dcf18c5e06e20489a0819f
Content-Type: text/plain; charset=ISO-8859-1

Hi Tom,

hmm. thanks for your answer.
i'm pretty sure there is no repetitive ddl happen on this or any other
table. i checked this with the developers.

but if i had an anti-wraparound vacuum, then i should see warnings like
these in the log. am i right? I don't have any warnings that day.

WARNING: database "mydb" must be vacuumed within 177009986 transactions
HINT: To avoid a database shutdown, execute a database-wide VACUUM in "mydb".


the table shared_gameset belonging to the vacuumed table
pg_toast.pg_toast_42964236 is new and exists only for about one month.

the table was also vacuumed the day before.
2010-06-17 20:20:41.044 CEST :16787 0 LOG: automatic
vacuum of table "gd.pg_toast.pg_toast_42964236": index scans: 1
pages: 0 removed, 1758012 remain
tuples: 718132 removed, 703020 remain
system usage: CPU 0.02s/0.01u sec elapsed 12354.51 sec

other statements on that table are
- delete ... where timstamp < ....
- select * from ....
but, that's it.

If you wish i can send you the complete log for that day.

best regards,
Uwe


On 22 June 2010 16:48, Tom Lane <tgl [at] sss.pgh.pa.us> wrote:

> Uwe Bartels <uwe.bartels [at] gmail.com> writes:
> > last ween i've seen a blocking "automatic vacuum".
> > as i understood, this is not supposed to happen. in the past i saw vacuum
> > processes disappear, in case of the need of a lock.
>
> What that sounds like is it was an anti-wraparound vacuum. Autovacuum
> won't cancel those to avoid delaying other processes.
>
> Now, RowExclusiveLock doesn't conflict with an autovacuum, so there is
> more going on here than you've showed us. The other obvious question is
> how did you get to the point where an anti-wraparound vacuum became
> necessary.
>
> I speculate that you are doing something that does conflict with vacuum
> (ie, SHARE UPDATE EXCLUSIVE lock or higher), and are doing it so often
> that regular autovacuum runs on the table never manage to complete.
> This is very bad, because you're going to have a serious bloat problem
> if autovac keeps getting canceled. You need to look at what sort of DDL
> you are repetitively executing on that table, and find a way to do it a
> lot less often.
>
> regards, tom lane
>

--0016e6dcf18c5e06e20489a0819f
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

Hi Tom,<br><br>hmm. thanks for your answer.<br>i'm pretty sure there is=
no repetitive ddl happen on this or any other table. i checked this with t=
he developers.<br><br>but if i had an anti-wraparound vacuum, then i should=
see warnings like these in the log. am i right? I don't have any warni=
ngs that day.<br>
<pre class=3D"PROGRAMLISTING">WARNING: database "mydb" must be v=
acuumed within 177009986 transactions<br>HINT: To avoid a database shutdow=
n, execute a database-wide VACUUM in "mydb".</pre><br>the table s=
hared_gameset belonging to the vacuumed table pg_toast.pg_toast_42964236 is=
new and exists only for about one month.<br>
<br>the table was also vacuumed the day before.<br>2010-06-17 20:20:41.044 =
CEST=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 :16787=A0 0=A0=A0=A0=A0=A0=A0 LOG:=A0=
automatic vacuum of table "gd.pg_toast.pg_toast_42964236": index=
scans: 1<br>=A0=A0=A0=A0=A0=A0=A0 pages: 0 removed, 1758012 remain<br>
=A0=A0=A0=A0=A0=A0=A0 tuples: 718132 removed, 703020 remain<br>=A0=A0=A0=A0=
=A0=A0=A0 system usage: CPU 0.02s/0.01u sec elapsed 12354.51 sec<br><br>oth=
er statements on that table are <br>- delete ... where timstamp < ....<b=
r>- select * from ....<br>
but, that's it.<br><br>If you wish i can send you the complete log for =
that day.<br><br>best regards,<br>Uwe<br><br><br><div class=3D"gmail_quote"=
>On 22 June 2010 16:48, Tom Lane <span dir=3D"ltr"><<a href=3D"mailto:tg=
l [at] sss.pgh.pa.us">tgl [at] sss.pgh.pa.us</a>></span> wrote:<br>
<blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0pt 0pt 0.8ex; borde=
r-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;"><div class=3D"im"=
>Uwe Bartels <<a href=3D"mailto:uwe.bartels [at] gmail.com">uwe.bartels [at] gmail=
..com</a>> writes:<br>

> last ween i've seen a blocking "automatic vacuum".<br>
> as i understood, this is not supposed to happen. in the past i saw vac=
uum<br>
> processes disappear, in case of the need of a lock.<br>
<br>
</div>What that sounds like is it was an anti-wraparound vacuum. =A0Autovac=
uum<br>
won't cancel those to avoid delaying other processes.<br>
<br>
Now, RowExclusiveLock doesn't conflict with an autovacuum, so there is<=
br>
more going on here than you've showed us. =A0The other obvious question=
is<br>
how did you get to the point where an anti-wraparound vacuum became<br>
necessary.<br>
<br>
I speculate that you are doing something that does conflict with vacuum<br>
(ie, SHARE UPDATE EXCLUSIVE lock or higher), and are doing it so often<br>
that regular autovacuum runs on the table never manage to complete.<br>
This is very bad, because you're going to have a serious bloat problem<=
br>
if autovac keeps getting canceled. =A0You need to look at what sort of DDL<=
br>
you are repetitively executing on that table, and find a way to do it a<br>
lot less often.<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0regards, tom lane<br>
</blockquote></div><br>

--0016e6dcf18c5e06e20489a0819f--

Uwe Bartels <uwe.bartels [at] gmail.com> writes:
> i'm pretty sure there is no repetitive ddl happen on this or any other
> table. i checked this with the developers.

Well, *something* was blocking that RowExclusiveLock request, and for
sure it wasn't autovacuum. There has to be something else going on.

> but if i had an anti-wraparound vacuum, then i should see warnings like
> these in the log. am i right? I don't have any warnings that day.

> WARNING: database "mydb" must be vacuumed within 177009986 transactions
> HINT: To avoid a database shutdown, execute a database-wide VACUUM in "mydb".

Uh, no. Anti-wraparound vacuums are performed long before you would get
to the point of seeing any actual warnings.

regards, tom lane

--
Sent via pgsql-admin mailing list (pgsql-admin [at] postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin

--001517477f7c1fdacb048a4f7405
Content-Type: text/plain; charset=ISO-8859-1

Hi Tom,

till now i found more blocking vacuum processes in other databases as well.
we migrated postgres from 8.3 to 8.4 in april.

on most databases we have slony running - they have a good potential for
getting to that high number of transactions. only that they do their own
vacuum on the most frequented tables.
what exactly happens during anti-wraparond vacuum in terms of locking and
for how long?

best regards,
Uwe



On 22 June 2010 16:48, Tom Lane <tgl [at] sss.pgh.pa.us> wrote:

> Uwe Bartels <uwe.bartels [at] gmail.com> writes:
> > last ween i've seen a blocking "automatic vacuum".
> > as i understood, this is not supposed to happen. in the past i saw vacuum
> > processes disappear, in case of the need of a lock.
>
> What that sounds like is it was an anti-wraparound vacuum. Autovacuum
> won't cancel those to avoid delaying other processes.
>
> Now, RowExclusiveLock doesn't conflict with an autovacuum, so there is
> more going on here than you've showed us. The other obvious question is
> how did you get to the point where an anti-wraparound vacuum became
> necessary.
>
> I speculate that you are doing something that does conflict with vacuum
> (ie, SHARE UPDATE EXCLUSIVE lock or higher), and are doing it so often
> that regular autovacuum runs on the table never manage to complete.
> This is very bad, because you're going to have a serious bloat problem
> if autovac keeps getting canceled. You need to look at what sort of DDL
> you are repetitively executing on that table, and find a way to do it a
> lot less often.
>
> regards, tom lane
>

--001517477f7c1fdacb048a4f7405
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

Hi Tom,<br><br>till now i found more blocking vacuum processes in other dat=
abases as well.<br>we migrated postgres from 8.3 to 8.4 in april.<br><br>on=
most databases we have slony running - they have a good potential for gett=
ing to that high number of transactions. only that they do their own vacuum=
on the most frequented tables.<br>
what exactly happens during anti-wraparond vacuum in terms of locking and f=
or how long?<br><br>best regards,<br>Uwe<br clear=3D"all"><br><br><br><div =
class=3D"gmail_quote">On 22 June 2010 16:48, Tom Lane <span dir=3D"ltr"><=
;<a href=3D"mailto:tgl [at] sss.pgh.pa.us">tgl [at] sss.pgh.pa.us</a>></span> wrot=
e:<br>
<blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0pt 0pt 0.8ex; borde=
r-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;"><div class=3D"im"=
>Uwe Bartels <<a href=3D"mailto:uwe.bartels [at] gmail.com">uwe.bartels [at] gmail=
..com</a>> writes:<br>

> last ween i've seen a blocking "automatic vacuum".<br>
> as i understood, this is not supposed to happen. in the past i saw vac=
uum<br>
> processes disappear, in case of the need of a lock.<br>
<br>
</div>What that sounds like is it was an anti-wraparound vacuum. =A0Autovac=
uum<br>
won't cancel those to avoid delaying other processes.<br>
<br>
Now, RowExclusiveLock doesn't conflict with an autovacuum, so there is<=
br>
more going on here than you've showed us. =A0The other obvious question=
is<br>
how did you get to the point where an anti-wraparound vacuum became<br>
necessary.<br>
<br>
I speculate that you are doing something that does conflict with vacuum<br>
(ie, SHARE UPDATE EXCLUSIVE lock or higher), and are doing it so often<br>
that regular autovacuum runs on the table never manage to complete.<br>
This is very bad, because you're going to have a serious bloat problem<=
br>
if autovac keeps getting canceled. =A0You need to look at what sort of DDL<=
br>
you are repetitively executing on that table, and find a way to do it a<br>
lot less often.<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0regards, tom lane<br>
</blockquote></div><br>

--001517477f7c1fdacb048a4f7405--

Excerpts from Uwe Bartels's message of jue jul 01 04:42:42 -0400 2010:
> Hi Tom,
>
> till now i found more blocking vacuum processes in other databases as w=
ell.
> we migrated postgres from 8.3 to 8.4 in april.

Please examine pg_locks to see what's blocking autovacuum. The key is
WHERE granted=3Df.

--
Sent via pgsql-admin mailing list (pgsql-admin [at] postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-admin