Re: 8.2 Autovacuum BUG ?

[pavan95]

Hi all,

Regarding this archive log generation found one observation.  

A table named abc_table id found to be archived every 9'th and 39'th minute.
We are able to find number of tuples deleted from the pg_stat_user_tables
view. 

But to my wonder the number of tuple inserts are shown 0.  How can there be
any delete without any inserts.

It was found that the table is having 2060 rows, where in which all rows are
getting deleted in every 9'th and 39'th minute of an hour. It implies that
those deleted should be inserted before the delete operation.

Also performed vacuum freeze on that table before 9'th minute of an hour it
generated 36 archive logs, and when I tried to do the same operation after
9'th minute(say 11'th minute of the same hour), it is generating the same
number of archive logs.

This is possible only if  the entire table gets updated/recreated.  Now my
final doubt is why the tuple inserts in pg_stat_user_tables is showing 0,
when corresponding deletes are existing?

Please find the below outputs FYR.


--Steps performed on production server:--

--1. Found Count Of Rows in Production
--**
prod_erp=# select count(*) from abc_table;;
 count
---
  2060
(1 row)

--2. Issued 'Select pg_stat_reset();'

--3. Before Delete Statements (Before JAN 31'st 2018 14:09 Hrs)
--

Issued:

select * from pg_stat_user_tables where relname ='abc_table';
-[ RECORD 1 ]-+
relid | 550314
schemaname| public
relname   | abc_table
seq_scan  | 2
seq_tup_read  | 4120
idx_scan  | 0
idx_tup_fetch | 0
n_tup_ins | 0
n_tup_upd | 0
n_tup_del | 0
n_tup_hot_upd | 0
n_live_tup| 0
n_dead_tup| 0
last_vacuum   |
last_autovacuum   |
last_analyze  |
last_autoanalyze  |
vacuum_count  | 0
autovacuum_count  | 0
analyze_count | 0
autoanalyze_count | 0


--4. After Delete Statements (Before JAN 31'st 2018 14:09 Hrs)
--

select * from pg_stat_user_tables where relname ='abc_table';
-[ RECORD 1 ]-+
relid | 550314
schemaname| public
relname   | abc_table
seq_scan  | 3
seq_tup_read  | 6180
idx_scan  | 2060
idx_tup_fetch | 2060
n_tup_ins | 0
n_tup_upd | 0
n_tup_del | 2060
n_tup_hot_upd | 0
n_live_tup| 0
n_dead_tup| 0
last_vacuum   |
last_autovacuum   |
last_analyze  |
last_autoanalyze  |
vacuum_count  | 0
autovacuum_count  | 0
analyze_count | 0
autoanalyze_count | 0


--5. After Delete Statements (Before JAN 31'st 2018 14:39 Hrs)
--  

select * from pg_stat_user_tables where relname ='abc_table';
-[ RECORD 1 ]-+
relid | 550314
schemaname| public
relname   | abc_table
seq_scan  | 4
seq_tup_read  | 8240
idx_scan  | 4120
idx_tup_fetch | 4120
n_tup_ins | 0
n_tup_upd | 0
n_tup_del | 4120
n_tup_hot_upd | 0
n_live_tup| 0
n_dead_tup| 0
last_vacuum   |
last_autovacuum   |
last_analyze  |
last_autoanalyze  |
vacuum_count  | 0
autovacuum_count  | 0
analyze_count | 0
autoanalyze_count | 0


--6. After Delete Statements (Before JAN 31'st 2018 15:09 Hrs)
--  


select * from pg_stat_user_tables where relname ='abc_table';
-[ RECORD 1 ]-+
relid | 550314
schemaname| public
relname   | abc_table
seq_scan  | 5
seq_tup_read  | 10300
idx_scan  | 6180
idx_tup_fetch | 6180
n_tup_ins | 0
n_tup_upd | 0
n_tup_del | 6180
n_tup_hot_upd | 0
n_live_tup| 0
n_dead_tup| 0
last_vacuum   |
last_autovacuum   |
last_analyze  |
last_autoanalyze  |
vacuum_count  | 0
autovacuum_count  | 0
analyze_count | 0
autoanalyze_count | 0



As said above if we compare n_tup_del value in steps 4,5,6 it says us that
entire table is getting deleted(correct me if I'm wrong), but n_tup_ins is
0. 

Regards,
Pavan



--
Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html

Re: 8.2 Autovacuum BUG ?

[Claudio Freire]

On Tue, Jan 30, 2018 at 10:55 AM, pavan95  wrote:
> Hello all,
>
> Will a sudden restart(stop/start) of a postgres database will generate this
> huge WAL?

Shouldn't

Re: 8.2 Autovacuum BUG ?

[pavan95]

Hello all,

Will a sudden restart(stop/start) of a postgres database will generate this
huge WAL?

Regards,
Pavan








--
Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html

Re: 8.2 Autovacuum BUG ?

[Pavan Teja]

On Jan 26, 2018 6:02 AM, "Pavan Teja"  wrote:



On Jan 26, 2018 3:00 AM, "Alvaro Herrera"  wrote:

pavan95 wrote:
> Hi Álvaro Herrera,
>
> Please find the corresponding output:

OK, these settings look pretty normal, so they don't explain your
problem.

What is checkpoint_segments set to?  And checkpoint_timeout?

--
Álvaro Herrerahttps://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Hi,

  checkpoint_segments are set to '3' &
  checkpoint_timeout was set to '5min'.

 Regards,
 Pavan.

  Any clue???

 Regards,
  Pavan.

Re: 8.2 Autovacuum BUG ?

[pavan95]

Hi Álvaro Herrera,

Please find the corresponding output:

*1).select name, setting, source, sourcefile, sourceline from pg_settings
where name like '%vacuum%'; *
-[ RECORD 1 ]
name   | autovacuum
setting| on
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 437
-[ RECORD 2 ]
name   | autovacuum_analyze_scale_factor
setting| 0.1
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 451
-[ RECORD 3 ]
name   | autovacuum_analyze_threshold
setting| 50
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 448
-[ RECORD 4 ]
name   | autovacuum_freeze_max_age
setting| 2
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 452
-[ RECORD 5 ]
name   | autovacuum_max_workers
setting| 3
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 443
-[ RECORD 6 ]
name   | autovacuum_naptime
setting| 60
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 445
-[ RECORD 7 ]
name   | autovacuum_vacuum_cost_delay
setting| 20
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 454
-[ RECORD 8 ]
name   | autovacuum_vacuum_cost_limit
setting| -1
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 457
-[ RECORD 9 ]
name   | autovacuum_vacuum_scale_factor
setting| 0.2
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 450
-[ RECORD 10 ]---
name   | autovacuum_vacuum_threshold
setting| 50
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 446
-[ RECORD 11 ]---
name   | log_autovacuum_min_duration
setting| 100
source | configuration file
sourcefile | /etc/postgresql/9.1/main/postgresql.conf
sourceline | 439
-[ RECORD 12 ]---
name   | vacuum_cost_delay
setting| 0
source | default
sourcefile |
sourceline |
-[ RECORD 13 ]---
name   | vacuum_cost_limit
setting| 200
source | default
sourcefile |
sourceline |
-[ RECORD 14 ]---
name   | vacuum_cost_page_dirty
setting| 20
source | default
sourcefile |
sourceline |
-[ RECORD 15 ]---
name   | vacuum_cost_page_hit
setting| 1
source | default
sourcefile |
sourceline |
-[ RECORD 16 ]---
name   | vacuum_cost_page_miss
setting| 10
source | default
sourcefile |
sourceline |
-[ RECORD 17 ]---
name   | vacuum_defer_cleanup_age
setting| 0
source | default
sourcefile |
sourceline |
-[ RECORD 18 ]---
name   | vacuum_freeze_min_age
setting| 5000
source | default
sourcefile |
sourceline |
-[ RECORD 19 ]---
name   | vacuum_freeze_table_age
setting| 15000
source | default
sourcefile |
sourceline |


*2).select oid::regclass, reloptions from pg_class where reloptions is not
null; *

(No rows)



Thanks in Advance.


Regards,
Pavan




--
Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html

Re: 8.2 Autovacuum BUG ?

[Alvaro Herrera]

Please show the output of these queries in the relevant databases:

select name, setting, source, sourcefile, sourceline from pg_settings where 
name like '%vacuum%';
select oid::regclass, reloptions from pg_class where reloptions is not null;

-- 
Álvaro Herrerahttps://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: 8.2 Autovacuum BUG ?

[David G. Johnston]

On Wed, Jan 24, 2018 at 7:48 AM, Pavan Teja 
wrote:

>
>
>  Yes, but why doing vacuum freeze of a table is causing a rapid
> ​archiving??
> Any idea??
>
>
IIUC ​Freezing involves physically altering those pages that are not frozen
to make them frozen.  Those changes are logged just like any (most?) other
physical changes to pages.  The rapid-ness is because freezing is not that
difficult so lots of pages can be changed in a relatively short period of
time.

David J.
​

Re: 8.2 Autovacuum BUG ?

[Pavan Teja]

On Jan 24, 2018 7:57 PM, "Claudio Freire"  wrote:



On Wed, Jan 24, 2018 at 8:50 AM, pavan95 
wrote:

> Hello all,
>
> One more interesting observation made by me.
>
> I have ran the below query(s) on production:
>
> SELECT
> relname,
> age(relfrozenxid) as xid_age,
> pg_size_pretty(pg_table_size(oid)) as table_size
> FROM pg_class
> WHERE relkind = 'r' and pg_table_size(oid) > 1073741824
> ORDER BY age(relfrozenxid) DESC ;
> relname  |
> xid_age | table_size
> 
> +-+
>  *hxx*  |
> 7798262 | 3245 MB
>  hrx |
> 7797554 | 4917 MB
>  irxx|
> 7796771 | 2841 MB
>  hr_   | 7744262 |
> 4778 MB
>  reimbxxx | 6767712 | 1110 MB
>
> show autovacuum_freeze_max_age;
>  autovacuum_freeze_max_age
> ---
>  2
> (1 row)
>

You seem to be rather far from the freeze_max_age. Unless you're consuming
txids at a very high rate, I don't think that's your problem.


   Hi ,


 Yes, but why doing vacuum freeze of a table is causing a rapid
​archiving??
Any idea??

Regards,
Pavan

Re: 8.2 Autovacuum BUG ?

[Claudio Freire]

On Wed, Jan 24, 2018 at 8:50 AM, pavan95 
wrote:

> Hello all,
>
> One more interesting observation made by me.
>
> I have ran the below query(s) on production:
>
> SELECT
> relname,
> age(relfrozenxid) as xid_age,
> pg_size_pretty(pg_table_size(oid)) as table_size
> FROM pg_class
> WHERE relkind = 'r' and pg_table_size(oid) > 1073741824
> ORDER BY age(relfrozenxid) DESC ;
> relname  |
> xid_age | table_size
> 
> +-+
>  *hxx*  |
> 7798262 | 3245 MB
>  hrx |
> 7797554 | 4917 MB
>  irxx|
> 7796771 | 2841 MB
>  hr_   | 7744262 |
> 4778 MB
>  reimbxxx | 6767712 | 1110 MB
>
> show autovacuum_freeze_max_age;
>  autovacuum_freeze_max_age
> ---
>  2
> (1 row)
>

You seem to be rather far from the freeze_max_age. Unless you're consuming
txids at a very high rate, I don't think that's your problem.

Re: 8.2 Autovacuum BUG ?

[Claudio Freire]

On Wed, Jan 24, 2018 at 3:54 AM, pavan95 
wrote:

> Hi Claudio,
>
> We didn't configure any replication to our production server. Which strace
> are you talking about?
>

This one: https://linux.die.net/man/1/strace

You can attach it to a process (assuming you have the necessary
permissions) and it will report all the syscalls the process does. That
does slow down the process though.

Then lsof ( https://linux.die.net/man/8/lsof ) can be used to map file
descriptor numbers to file paths. You have to do it as soon as you read the
output, because files get closed and file descriptors reused. So it's
better to have a script that directly reads from /proc/pid/fd or fdinfo,
but that takes some programming.

It is nontrivial, but sometimes it's the only tool in your belt. You may
want to try something else first though.


> We did a keen observation that only at the time 9'th minute of the hour and
> 39'th minute of the hour the so called archive logs are generated even
> when

nobody is connecting from application(off the business hours).


Well, if you don't know what happens at those times (and only at those
times), it's not that useful.

Since you don't know what is causing this for certain, first thing you have
to do is ascertain that. Try increasing logging as much as you can,
especially around those times, and see what turns on then and not at other
times. You can monitor autovacuum processes as well in pg_stat_activity, so
make sure you check that as well, as autovacuum will only log once it's
done.

You do know autovacuum is running at those times, you have to check whether
it isn't when WAL isn't being generated, and whether autovacuum is
vacuuming the same tables over and over or what. Your earlier mails show
autoanalyze runs, not vacuum. Those shouldn't cause so much WAL, but if
it's running very often and you have lots of stats, then maybe.

You can also try pg_stat_statements:
https://www.postgresql.org/docs/9.1/static/pgstatstatements.html

Again, concentrate on the differential - what happens at those times, that
doesn't at other times.

Another idea would be to check for freeze runs in autovacuum. Ie, what's
described here: https://wiki.postgresql.org/wiki/VacuumHeadaches#FREEZE

There's a nice blog post with some queries to help you with that here:
http://www.databasesoup.com/2012/09/freezing-your-tuples-off-part-1.html
(and it's continuation here:
http://www.databasesoup.com/2012/10/freezing-your-tuples-off-part-2.html ).
I'm not saying you should tune those parameters, what you were showing was
autoanalyze activity, not vacuum freeze, but you should check whether you
need to anyway.

Re: 8.2 Autovacuum BUG ?

[pavan95]

Hi Claudio,

We didn't configure any replication to our production server. Which strace
are you talking about?

We did a keen observation that only at the time 9'th minute of the hour and
39'th minute of the hour the so called archive logs are generated even when
nobody is connecting from application(off the business hours). Minimum of 76
files are being produced in these two intervals of a hour. Tried to monitor
the DML's but those are the same DML's which were in the past. Any idea??

Thanks in advance.



--
Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html

Re: 8.2 Autovacuum BUG ?

[pavan95]

Hello,

Is there any way to check, how many transactions happened till date from the
point the database created and started accepting transactions ?

The reason for this doubt is to find whether my database has crossed 2
million transactions or not. 

Strangely had an interesting observation, when I tried to a vacuum full, it
is generating 1GB of archive logs per sec, and yes it's true.


So I had a doubt like whether this is related to vacuum

Please help me cope up with this.

Regards,
Pavan



--
Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html

Re: 8.2 Autovacuum BUG ?

[Andreas Kretschmer]

Am 23.01.2018 um 16:20 schrieb Pavan Teja:

Hi David,

If it's yes what needs to be done in order to stabilize this issue??



Don't top-post ;-)


You can't prevent the generation of wal's (apart from using unlogged 
tables, but i'm sure, that will be not your solution.)


Regards, Andreas

--
2ndQuadrant - The PostgreSQL Support Company.
www.2ndQuadrant.com

Re: 8.2 Autovacuum BUG ?

[Pavan Teja]

Hi David,

If it's yes what needs to be done in order to stabilize this issue??

Thanks in advance.

Regards,
Pavan

On Jan 23, 2018 8:15 PM, "David G. Johnston" 
wrote:

> On Tue, Jan 23, 2018 at 7:39 AM, Pavan Teja 
> wrote:
>
>> " checkpoints are frequently occurring (1second apart). Consider
>> increasing checkpoint_segements parameter".
>>
>
> The custom on these lists is to bottom or inline post.​
>
> ​This tends to appear when someone decide to write a load script of the
> form:
>
> INSERT INTO tbl (cols) VALUES (...);
> INSERT INTO ​tbl (cols) VALUES (...);
> [repeat many, many, times]
>
> (note the lack of BEGIN/END, single transaction help mitigate it somewhat)
>
> David J.
>
>

Re: 8.2 Autovacuum BUG ?

[Pavan Teja]

Yes so many wals are continuing to be produced.

Deleting the wals after a backup of the database.

Yes archiving mode is on. And the warning message in log file is

" checkpoints are frequently occurring (1second apart). Consider increasing
checkpoint_segements parameter".

My doubt is previously the same are the parameters which are reflected as
of now. Then what is the point in considering altering those values.
Correct me if I am wrong.

Regards,
Pavan

On Jan 23, 2018 7:47 PM, "Andreas Kretschmer" 
wrote:



Am 23.01.2018 um 12:51 schrieb pavan95:

> Hi Andreas,
>
> Yes I'm facing problem because of this huge WAL(archive log) generation. As
> it is seriously consuming a lot of disk space almost close to 50GB per day
> even if the DML's don't have that impact in this WAL generation.
>
> Previously the archive_log size is nearly 2 to 3 GB a day. Now with the
> same
> set of DML's how is it being generated to 50GB is my burning doubt.
>

Will so many wals continue to be produced?




> I just wanted to know how to stabilize this issue, as checking and deleting
> the archive logs on hourly basis is not a good idea.
>
Don't delete wal's!



Finally, I'm looking how to reduce this back to normal. Thanks in Advance.
>

have you set archive_mode to on and defined an archive_command? Wal-files
will be reused after 2 checkpoints.
Is there something in the logs?


Regards, Andreas
-- 
2ndQuadrant - The PostgreSQL Support Company.
www.2ndQuadrant.com

Re: 8.2 Autovacuum BUG ?

[pavan95]

Hi Andreas,

Yes I'm facing problem because of this huge WAL(archive log) generation. As
it is seriously consuming a lot of disk space almost close to 50GB per day
even if the DML's don't have that impact in this WAL generation.

Previously the archive_log size is nearly 2 to 3 GB a day. Now with the same
set of DML's how is it being generated to 50GB is my burning doubt.

I just wanted to know how to stabilize this issue, as checking and deleting
the archive logs on hourly basis is not a good idea.

Finally, I'm looking how to reduce this back to normal. Thanks in Advance.

Regards,
Pavan  



--
Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html