template1 database is facing high datfrozenxid

On 02/12/2016 02:56 PM, AI Rumman wrote:

Hi,

I am running Postgresql 9.1 and I can see the datfrozenxid is going high
and vacuum process is not bringing it down. And this has been happening
on template1 database.

2016-02-12 16:51:50.400 CST [19445][@] : [13-1] WARNING: oldest
xmin is far in the past
2016-02-12 16:51:50.400 CST [19445][@] : [14-1] HINT: Close open
transactions soon to avoid wraparound problems.

The above seems to be the contributing factor.

Does:

select * from pg_stat_activity

show long running queries.

2016-02-12 16:51:50.400 CST [19445][@] : [15-1] LOG: automatic
vacuum of table "template1.pg_catalog.pg_database": index scans: 0
pages: 0 removed, 1 remain
tuples: 0 removed, 9 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
2016-02-12 16:51:50.411 CST [19435][@] : [82-1] WARNING: oldest
xmin is far in the past
2016-02-12 16:51:50.411 CST [19435][@] : [83-1] HINT: Close open
transactions soon to avoid wraparound problems.
2016-02-12 16:51:50.411 CST [19435][@] : [84-1] LOG: automatic
vacuum of table "template1.pg_catalog.pg_largeobject": index scans: 0
pages: 0 removed, 0 remain
tuples: 0 removed, 0 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec

I vacuum database manually but nothing is working out.
Please help,

Thanks.

--
Adrian Klaver
adrian.klaver@aklaver.com

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

I checked it and I did not find any log running sql or any open
transaction. Not even in pg_prepared_xacts.
And it looks like pg_catalog database is making the alarm.

Any other idea please, where I need to look into.

Thanks.

On Fri, Feb 12, 2016 at 3:05 PM, Adrian Klaver <adrian.klaver@aklaver.com>
wrote:

On 02/12/2016 03:10 PM, AI Rumman wrote:

I checked it and I did not find any log running sql or any open
transaction. Not even in pg_prepared_xacts.
And it looks like pg_catalog database is making the alarm.

Any other idea please, where I need to look into.

select * from pg_locks

http://www.postgresql.org/docs/9.1/static/view-pg-locks.html

Thanks.

On Fri, Feb 12, 2016 at 3:05 PM, Adrian Klaver
<adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>> wrote:

On 02/12/2016 02:56 PM, AI Rumman wrote:

Hi,

I am running Postgresql 9.1 and I can see the datfrozenxid is
going high
and vacuum process is not bringing it down. And this has been
happening
on template1 database.

2016-02-12 16:51:50.400 CST [19445][@] : [13-1] WARNING:
oldest
xmin is far in the past
2016-02-12 16:51:50.400 CST [19445][@] : [14-1] HINT:
Close open
transactions soon to avoid wraparound problems.

The above seems to be the contributing factor.

Does:

select * from pg_stat_activity

show long running queries.

2016-02-12 16:51:50.400 CST [19445][@] : [15-1] LOG: automatic
vacuum of table "template1.pg_catalog.pg_database": index
scans: 0
pages: 0 removed, 1 remain
tuples: 0 removed, 9 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
2016-02-12 16:51:50.411 CST [19435][@] : [82-1] WARNING:
oldest
xmin is far in the past
2016-02-12 16:51:50.411 CST [19435][@] : [83-1] HINT:
Close open
transactions soon to avoid wraparound problems.
2016-02-12 16:51:50.411 CST [19435][@] : [84-1] LOG: automatic
vacuum of table "template1.pg_catalog.pg_largeobject":
index scans: 0
pages: 0 removed, 0 remain
tuples: 0 removed, 0 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec

I vacuum database manually but nothing is working out.
Please help,

Thanks.

--
Adrian Klaver
adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>

--
Adrian Klaver
adrian.klaver@aklaver.com

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

On 02/12/2016 03:10 PM, AI Rumman wrote:

I checked it and I did not find any log running sql or any open
transaction. Not even in pg_prepared_xacts.
And it looks like pg_catalog database is making the alarm.

Any other idea please, where I need to look into.

Should have added:

select * from pg_database

Thanks.

On Fri, Feb 12, 2016 at 3:05 PM, Adrian Klaver
<adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>> wrote:

On 02/12/2016 02:56 PM, AI Rumman wrote:

Hi,

I am running Postgresql 9.1 and I can see the datfrozenxid is
going high
and vacuum process is not bringing it down. And this has been
happening
on template1 database.

2016-02-12 16:51:50.400 CST [19445][@] : [13-1] WARNING:
oldest
xmin is far in the past
2016-02-12 16:51:50.400 CST [19445][@] : [14-1] HINT:
Close open
transactions soon to avoid wraparound problems.

The above seems to be the contributing factor.

Does:

select * from pg_stat_activity

show long running queries.

2016-02-12 16:51:50.400 CST [19445][@] : [15-1] LOG: automatic
vacuum of table "template1.pg_catalog.pg_database": index
scans: 0
pages: 0 removed, 1 remain
tuples: 0 removed, 9 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
2016-02-12 16:51:50.411 CST [19435][@] : [82-1] WARNING:
oldest
xmin is far in the past
2016-02-12 16:51:50.411 CST [19435][@] : [83-1] HINT:
Close open
transactions soon to avoid wraparound problems.
2016-02-12 16:51:50.411 CST [19435][@] : [84-1] LOG: automatic
vacuum of table "template1.pg_catalog.pg_largeobject":
index scans: 0
pages: 0 removed, 0 remain
tuples: 0 removed, 0 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec

I vacuum database manually but nothing is working out.
Please help,

Thanks.

--
Adrian Klaver
adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>

--
Adrian Klaver
adrian.klaver@aklaver.com

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

Used this query in each of the database::

SELECT t.relname, l.database, l.locktype, l.pid , l.mode, l.granted,
p.current_query, p.query_start ,p.waiting
FROM pg_locks as l
INNER JOIN pg_stat_all_tables t
on l.relation = t.relid
INNER JOIN pg_stat_activity as p
on l.pid = p.procpid ;

No luck. At present, db is working, but t is going towards wraparound.

On Fri, Feb 12, 2016 at 3:28 PM, Adrian Klaver <adrian.klaver@aklaver.com>
wrote:

In pg_subtrans, I have files like:

$ ls -lrt | more
total 1269436
-rw------- 1 postgres postgres 262144 Jan 25 18:49 D907
-rw------- 1 postgres postgres 262144 Jan 25 18:54 D908
-rw------- 1 postgres postgres 262144 Jan 25 18:58 D909
-rw------- 1 postgres postgres 262144 Jan 25 18:59 D90A
-rw------- 1 postgres postgres 262144 Jan 25 19:04 D90B
-rw------- 1 postgres postgres 262144 Jan 25 19:09 D90C
-rw------- 1 postgres postgres 262144 Jan 25 19:14 D90D
-rw------- 1 postgres postgres 262144 Jan 25 19:18 D90E
-rw------- 1 postgres postgres 262144 Jan 25 19:19 D90F
-rw------- 1 postgres postgres 262144 Jan 25 19:24 D910
-rw------- 1 postgres postgres 262144 Jan 25 19:29 D911
-rw------- 1 postgres postgres 262144 Jan 25 19:33 D912
-rw------- 1 postgres postgres 262144 Jan 25 19:34 D913
-rw------- 1 postgres postgres 262144 Jan 25 19:39 D914
-rw------- 1 postgres postgres 262144 Jan 25 19:44 D915
-rw------- 1 postgres postgres 262144 Jan 25 19:49 D916
-rw------- 1 postgres postgres 262144 Jan 25 19:53 D917
-rw------- 1 postgres postgres 262144 Jan 25 19:54 D918
-rw------- 1 postgres postgres 262144 Jan 25 19:59 D919
-rw------- 1 postgres postgres 262144 Jan 25 20:04 D91A
-rw------- 1 postgres postgres 262144 Jan 25 20:09 D91B
-rw------- 1 postgres postgres 262144 Jan 25 20:14 D91C
-rw------- 1 postgres postgres 262144 Jan 25 20:19 D91D
-rw------- 1 postgres postgres 262144 Jan 25 20:23 D91E
-rw------- 1 postgres postgres 262144 Jan 25 20:24 D91F
-rw------- 1 postgres postgres 262144 Jan 25 20:29 D920
-rw------- 1 postgres postgres 262144 Jan 25 20:34 D921
-rw------- 1 postgres postgres 262144 Jan 25 20:39 D922
-rw------- 1 postgres postgres 262144 Jan 25 20:44 D923
-rw------- 1 postgres postgres 262144 Jan 25 20:49 D924
-rw------- 1 postgres postgres 262144 Jan 25 20:54 D925
-rw------- 1 postgres postgres 262144 Jan 25 20:59 D926
-rw------- 1 postgres postgres 262144 Jan 25 21:04 D927
.....

Does it mean that I have too many open transactions? If yes, it is not
showing in pg_stat_activity.

On Fri, Feb 12, 2016 at 3:38 PM, AI Rumman <rummandba@gmail.com> wrote:

On 02/12/2016 04:03 PM, AI Rumman wrote:

In pg_subtrans, I have files like:

Are you sure you are looking at the same database cluster in all the cases?

What does:

SELECT datname, age(datfrozenxid) FROM pg_database;

give you?

$ ls -lrt | more
total 1269436
-rw------- 1 postgres postgres 262144 Jan 25 18:49 D907
-rw------- 1 postgres postgres 262144 Jan 25 18:54 D908
-rw------- 1 postgres postgres 262144 Jan 25 18:58 D909
-rw------- 1 postgres postgres 262144 Jan 25 18:59 D90A
-rw------- 1 postgres postgres 262144 Jan 25 19:04 D90B
-rw------- 1 postgres postgres 262144 Jan 25 19:09 D90C
-rw------- 1 postgres postgres 262144 Jan 25 19:14 D90D
-rw------- 1 postgres postgres 262144 Jan 25 19:18 D90E
-rw------- 1 postgres postgres 262144 Jan 25 19:19 D90F
-rw------- 1 postgres postgres 262144 Jan 25 19:24 D910
-rw------- 1 postgres postgres 262144 Jan 25 19:29 D911
-rw------- 1 postgres postgres 262144 Jan 25 19:33 D912
-rw------- 1 postgres postgres 262144 Jan 25 19:34 D913
-rw------- 1 postgres postgres 262144 Jan 25 19:39 D914
-rw------- 1 postgres postgres 262144 Jan 25 19:44 D915
-rw------- 1 postgres postgres 262144 Jan 25 19:49 D916
-rw------- 1 postgres postgres 262144 Jan 25 19:53 D917
-rw------- 1 postgres postgres 262144 Jan 25 19:54 D918
-rw------- 1 postgres postgres 262144 Jan 25 19:59 D919
-rw------- 1 postgres postgres 262144 Jan 25 20:04 D91A
-rw------- 1 postgres postgres 262144 Jan 25 20:09 D91B
-rw------- 1 postgres postgres 262144 Jan 25 20:14 D91C
-rw------- 1 postgres postgres 262144 Jan 25 20:19 D91D
-rw------- 1 postgres postgres 262144 Jan 25 20:23 D91E
-rw------- 1 postgres postgres 262144 Jan 25 20:24 D91F
-rw------- 1 postgres postgres 262144 Jan 25 20:29 D920
-rw------- 1 postgres postgres 262144 Jan 25 20:34 D921
-rw------- 1 postgres postgres 262144 Jan 25 20:39 D922
-rw------- 1 postgres postgres 262144 Jan 25 20:44 D923
-rw------- 1 postgres postgres 262144 Jan 25 20:49 D924
-rw------- 1 postgres postgres 262144 Jan 25 20:54 D925
-rw------- 1 postgres postgres 262144 Jan 25 20:59 D926
-rw------- 1 postgres postgres 262144 Jan 25 21:04 D927
.....

Does it mean that I have too many open transactions? If yes, it is not
showing in pg_stat_activity.

On Fri, Feb 12, 2016 at 3:38 PM, AI Rumman <rummandba@gmail.com
<mailto:rummandba@gmail.com>> wrote:

Used this query in each of the database::

SELECT t.relname, l.database, l.locktype, l.pid , l.mode, l.granted,
p.current_query, p.query_start ,p.waiting
FROM pg_locks as l
INNER JOIN pg_stat_all_tables t
on l.relation = t.relid
INNER JOIN pg_stat_activity as p
on l.pid = p.procpid ;

No luck. At present, db is working, but t is going towards wraparound.

On Fri, Feb 12, 2016 at 3:28 PM, Adrian Klaver
<adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>> wrote:

On 02/12/2016 03:10 PM, AI Rumman wrote:

I checked it and I did not find any log running sql or any open
transaction. Not even in pg_prepared_xacts.
And it looks like pg_catalog database is making the alarm.

Any other idea please, where I need to look into.

Should have added:

select * from pg_database

Thanks.

On Fri, Feb 12, 2016 at 3:05 PM, Adrian Klaver
<adrian.klaver@aklaver.com
<mailto:adrian.klaver@aklaver.com>
<mailto:adrian.klaver@aklaver.com
<mailto:adrian.klaver@aklaver.com>>> wrote:

On 02/12/2016 02:56 PM, AI Rumman wrote:

Hi,

I am running Postgresql 9.1 and I can see the
datfrozenxid is
going high
and vacuum process is not bringing it down. And
this has been
happening
on template1 database.

2016-02-12 16:51:50.400 CST [19445][@] :
[13-1] WARNING:
oldest
xmin is far in the past
2016-02-12 16:51:50.400 CST [19445][@] :
[14-1] HINT:
Close open
transactions soon to avoid wraparound problems.

The above seems to be the contributing factor.

Does:

select * from pg_stat_activity

show long running queries.

2016-02-12 16:51:50.400 CST [19445][@] :
[15-1] LOG: automatic
vacuum of table
"template1.pg_catalog.pg_database": index
scans: 0
pages: 0 removed, 1 remain
tuples: 0 removed, 9 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
2016-02-12 16:51:50.411 CST [19435][@] :
[82-1] WARNING:
oldest
xmin is far in the past
2016-02-12 16:51:50.411 CST [19435][@] :
[83-1] HINT:
Close open
transactions soon to avoid wraparound problems.
2016-02-12 16:51:50.411 CST [19435][@] :
[84-1] LOG: automatic
vacuum of table
"template1.pg_catalog.pg_largeobject":
index scans: 0
pages: 0 removed, 0 remain
tuples: 0 removed, 0 remain
system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec

I vacuum database manually but nothing is working out.
Please help,

Thanks.

--
Adrian Klaver
adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>
<mailto:adrian.klaver@aklaver.com
<mailto:adrian.klaver@aklaver.com>>

--
Adrian Klaver
adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>

--
Adrian Klaver
adrian.klaver@aklaver.com

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

Yes. And we solved the problem.
We looked into the pg_subtrans and found that we had subrans pending from
January 25th. We investigated more and found that I large sql was executed
on Streaming standby around that date.
More digging we found the date of the below alert is also near:

WARNING: oldest xmin is far in the past

We stopped standby and the problem solved. :)

Thanks.

On Fri, Feb 12, 2016 at 4:11 PM, Adrian Klaver <adrian.klaver@aklaver.com>
wrote: