Re: slow queries on system tables

[PegoraroF10]

these values were collected before vacuum analyse:select (select reltuples
from pg_Class where relName = t.relName), * from pg_stat_sys_tables t where
schemaname = 'pg_catalog' and relname in
('pg_class','pg_attribute','pg_index');
reltuples   relid   schemaname  relname seq_scanseq_tup_read
idx_scan
idx_tup_fetch   n_tup_ins   n_tup_upd   n_tup_del   n_tup_hot_upd   
n_live_tup
n_dead_tup  n_mod_since_analyze last_vacuum last_autovacuum 
last_analyze
last_autoanalyzevacuum_countautovacuum_countanalyze_count
autoanalyze_count
930475  1249pg_catalog  pg_attribute22462   61582178
646833988   2785143399
25381   776 15287   566 10094   15497   41444   NULLNULLNULL
NULL0   0   0   0
169186  1259pg_catalog  pg_class5541140 39631813757 
638041068   2316793709
224375187   625 44008   169891  56457435NULL2019-08-22 
19:58:48.497317  NULL
2019-08-22 13:03:02.770579  0   415 0   1
87387   2610pg_catalog  pg_index5263825 33638625440 
246528384   590160274   1142
0   208 0   934 208 1350NULLNULLNULLNULL
0   0   0   0
Then ... vacuum analyze pg_catalog.pg_index;vacuum analyze
pg_catalog.pg_attribute;vacuum analyze pg_catalog.pg_class;
reltuples   relid   schemaname  relname seq_scanseq_tup_read
idx_scan
idx_tup_fetch   n_tup_ins   n_tup_upd   n_tup_del   n_tup_hot_upd   
n_live_tup
n_dead_tup  n_mod_since_analyze last_vacuum last_autovacuum 
last_analyze
last_autoanalyzevacuum_countautovacuum_countanalyze_count
autoanalyze_count
940569  1249pg_catalog  pg_attribute22550   61582570
646919000   2785430403
25381   776 15287   566 940569  0   0   2019-08-24 
09:01:26.334472  NULL2019-08-24
09:01:27.169883 NULL1   0   1   0
150903  1259pg_catalog  pg_class5542002 39640547448 
63819   2316941739
224375187   625 44008   150903  0   0   2019-08-24 
09:01:33.130845  2019-08-22
19:58:48.497317 2019-08-24 09:01:33.441355  2019-08-22 13:03:02.770579  
1   415
1   1
88321   2610pg_catalog  pg_index5263994 33639781274 
246576056   590229532   1142
0   208 0   88321   0   0   2019-08-24 09:01:18.080615  
NULL2019-08-24 09:01:18.275907
NULL1   0   1   0
and this is explain before
https://explain.depesz.com/s/fUNB
and after
https://explain.depesz.com/s/1FZR



--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[Adrian Klaver]

On 8/23/19 3:47 PM, PegoraroF10 wrote:

This week we added just 5 new customers. Every schema has 100 tables, 300
indices, 400 triggers.
I cannot imagine our script doing 75000 updates just for adding those
schemas.


Very rough calculation:

https://www.postgresql.org/docs/11/catalog-pg-class.html

The catalog pg_class catalogs tables and most everything else that has 
columns or is otherwise similar to a table. This includes indexes (but 
see also pg_index), sequences (but see also pg_sequence), views, 
materialized views, composite types, and TOAST tables; see relkind. ...



From above, not counting TOAST tables:

5 * (100 + 300) = 2,000 new entries.

From previous post you said you had 190 schemas at that time.

190 * 400 = 76,000 entries
+2,000
78,000

In pg_class rel* fields:

"It is updated by VACUUM, ANALYZE, and a few DDL commands such as CREATE 
INDEX."


Assuming tables/indexes have changed enough to trigger vacuum run:

78,000 * 1 vacuum = 78,000 updates








--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html






--
Adrian Klaver
adrian.kla...@aklaver.com

Re: slow queries on system tables

[Michael Lewis]

Can you manually execute vacuum analyze on all three involved tables and
again share the plan for the same query? If it is significantly improved,
it would seem like following the recommendation to tune autovacuum (and
analyze) to be more frequent would be prudent.

You haven't seemed to change from default vacuum/analyze settings despite
the default parameters being suggested only for bare minimum hardware and
very light use databases.

Re: slow queries on system tables

[PegoraroF10]

This week we added just 5 new customers. Every schema has 100 tables, 300
indices, 400 triggers. 
I cannot imagine our script doing 75000 updates just for adding those
schemas.




--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[PegoraroF10]

autovacuum_analyze_threshold   = 50;
autovacuum_analyze_scale_factor   = 0.1



--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[PegoraroF10]

https://explain.depesz.com/s/5Rrd

EXPLAIN (ANALYZE, COSTS, VERBOSE, BUFFERS) SELECT
current_database() AS TABLE_CATALOG, n.nspname AS TABLE_SCHEMA, t.relname AS
TABLE_NAME, t.oid AS TABLE_OID, current_database() AS INDEX_CATALOG,
n.nspname AS INDEX_SCHEMA, c.relname AS INDEX_NAME, c.oid AS INDEX_OID,
a.attname AS COLUMN_NAME, a.attnum AS COLUMN_POSITION,indoption[index] & 1
AS DESCENDING , indisunique::integer AS UNIQUE FROM   (SELECT
generate_series(0, indnatts - 1), indrelid, indexrelid, indkey,   indoption,
indisunique, indisprimary FROM pg_index i)   i(index, indrelid, indexrelid,
indkey, indoption, indisunique, indisprimary)  INNER JOIN pg_class c ON
c.oid = indexrelid   INNER JOIN pg_class t ON t.oid = indrelid   INNER JOIN
pg_namespace n ON n.oid = t.relnamespace   INNER JOIN pg_attribute a ON
a.attrelid = indrelid AND a.attnum = indkey[index] WHERE n.nspname LIKE
'f10_0275, public' AND t.relname LIKE 'sys_var' ORDER BY
indisprimary::integer DESC, n.nspname, t.relname, c.relname, a.attnum;



--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[Adrian Klaver]

On 8/23/19 2:47 PM, PegoraroF10 wrote:
Coming back to my problem, today happened again, that search comes slow. 
Explaining again, auto vacuum and auto analyse for pg_* tables are not 
configured one by one, so its using that defaults of scale_factor = 0.2 
and threshold = 50. Today, when that problem of speed came back, the 
view pg_stat_sys_tables for pg_class table shows that it ran 415 times 
autovacuum only this week and there are 75187 updates on this table. How 
can I have been updated 75000 times this table only in a week ? What 


If you are still doing this:

https://www.postgresql.org/message-id/1563909633976-0.post%40n3.nabble.com

then it is not surprising.

kind of statement does an update on this table ? And why did it run 415 
times autovacuum and only 1 autoanalyse ?


Can you show the actual settings in postgresql.conf for:

autovacuum_analyze_threshold

autovacuum_analyze_scale_factor

Also do you have an include in postgresql.conf pointing to another file?

I know you said they are using the defaults but the scale_factor you 
show above is the default for autovacuum_vacuum_scale_factor. For 
autovacuum_analyze_scale_factor the default is 0.1, which makes wonder.


relname	seq_scan	seq_tup_read	idx_scan	idx_tup_fetch	n_tup_ins 
n_tup_upd	n_tup_del	n_tup_hot_upd	n_live_tup	n_dead_tup 
n_mod_since_analyze	last_vacuum	last_autovacuum	last_analyze 
last_autoanalyze	vacuum_count	autovacuum_count	analyze_count 
autoanalyze_count
pg_class	5395512	38598962913	616674711	2219978581	2243	75187	625	44008 
169891	5645	7435	NULL	2019-08-22 19:58:48.497317	NULL	2019-08-22 
13:03:02.770579	0	415	0	1




Sent from the PostgreSQL - general mailing list archive 
 at 
Nabble.com.



--
Adrian Klaver
adrian.kla...@aklaver.com

Re: slow queries on system tables

[Michael Lewis]

Might the issue be with pg_index or pg_attribute rather than pg_class? Is
the query still slow? Do you have the output of explain analyze for use on
https://explain.depesz.com/ or the output of EXPLAIN (ANALYZE, COSTS,
VERBOSE, BUFFERS, FORMAT JSON) for use on
http://tatiyants.com/pev/#/plans/new website?

Re: slow queries on system tables

[PegoraroF10]

Coming back to my problem, today happened again, that search comes slow.
Explaining again, auto vacuum and auto analyse for pg_* tables are not
configured one by one, so its using that defaults of scale_factor = 0.2 and
threshold = 50. Today, when that problem of speed came back, the view
pg_stat_sys_tables for pg_class table shows that it ran 415 times autovacuum
only this week and there are 75187 updates on this table. How can I have
been updated 75000 times this table only in a week ? What kind of statement
does an update on this table ? And why did it run 415 times autovacuum and
only 1 autoanalyse ?
relname seq_scanseq_tup_readidx_scanidx_tup_fetch   
n_tup_ins   n_tup_upd
n_tup_del   n_tup_hot_upd   n_live_tup  n_dead_tup  
n_mod_since_analyze
last_vacuum last_autovacuum last_analyzelast_autoanalyze
vacuum_count
autovacuum_countanalyze_count   autoanalyze_count
pg_class5395512 38598962913 616674711   2219978581  2243
75187   625 44008
169891  56457435NULL2019-08-22 19:58:48.497317  NULL
2019-08-22
13:03:02.770579 0   415 0   1




--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[PegoraroF10]

As I told you before, these queries cannot be changed because the driver
creates them. 
As I cannot change them how can I help Postgres to run it faster, just that.

My log_min_duration_statement = 500ms, so I find SQL some dozens of this sql
inside it daily, but I´m sure this sql is used thousands and thousands a
day.
 
duration: 566.415 ms  execute PRSTMTST1590201604/PORTALST1590201604: SELECT
current_database() AS TABLE_CATALOG, n.nspname AS TABLE_SCHEMA, t.relname AS
TABLE_NAME, t.oid AS TABLE_OID, current_database() AS INDEX_CATALOG,
n.nspname AS INDEX_SCHEMA, c.relname AS INDEX_NAME, c.oid AS INDEX_OID,
a.attname AS COLUMN_NAME, a.attnum AS COLUMN_POSITION,indoption[index] & 1
AS DESCENDING , indisunique::integer AS UNIQUE FROM   (SELECT
generate_series(0, indnatts - 1), indrelid, indexrelid, indkey,   indoption,
indisunique, indisprimary FROM pg_index i)   i(index, indrelid, indexrelid,
indkey, indoption, indisunique, indisprimary)  INNER JOIN pg_class c ON
c.oid = indexrelid   INNER JOIN pg_class t ON t.oid = indrelid   INNER JOIN
pg_namespace n ON n.oid = t.relnamespace   INNER JOIN pg_attribute a ON
a.attrelid = indrelid AND a.attnum = indkey[index] WHERE n.nspname LIKE
'f10_0275, public' AND t.relname LIKE 'sys_var' ORDER BY
indisprimary::integer DESC, n.nspname, t.relname, c.relname, a.attnum

QUERY PLAN
Sort  (cost=260362.69..260362.69 rows=1 width=470) (actual
time=59.526..59.527 rows=0 loops=1)
  Sort Key: ((i.indisprimary)::integer) DESC, n.nspname, t.relname,
c.relname, a.attnum
  Sort Method: quicksort  Memory: 25kB
  ->  Nested Loop  (cost=1003.58..260362.68 rows=1 width=470) (actual
time=59.519..59.519 rows=0 loops=1)
->  Nested Loop  (cost=1003.44..260360.98 rows=1 width=238) (actual
time=5.251..58.872 rows=424 loops=1)
  ->  Gather  (cost=1003.02..260360.42 rows=1 width=174) (actual
time=5.232..72.894 rows=424 loops=1)
Workers Planned: 1
Workers Launched: 1
->  Nested Loop  (cost=3.02..259360.32 rows=1 width=174)
(actual time=8.357..48.200 rows=212 loops=2)
  Join Filter: (t.oid = a.attrelid)
  ->  Hash Join  (cost=2.59..259357.51 rows=4
width=138) (actual time=8.322..46.124 rows=212 loops=2)
Hash Cond: (i.indrelid = t.oid)
->  ProjectSet  (cost=0.00..258260.16
rows=51008000 width=66) (actual time=0.011..33.557 rows=53694 loops=2)
  ->  Parallel Seq Scan on pg_index i 
(cost=0.00..2710.08 rows=51008 width=64) (actual time=0.007..6.804
rows=43564 loops=2)
->  Hash  (cost=2.44..2.44 rows=12 width=72)
(actual time=7.614..7.615 rows=210 loops=2)
  Buckets: 1024  Batches: 1  Memory
Usage: 30kB
  ->  Index Scan using
pg_class_relname_nsp_index on pg_class t  (cost=0.42..2.44 rows=12 width=72)
(actual time=0.029..7.556 rows=210 loops=2)
Index Cond: ((relname >=
'sys'::name) AND (relname < 'syt'::name))
Filter: (relname ~~
'sys_account'::text)
Rows Removed by Filter: 1696
  ->  Index Scan using
pg_attribute_relid_attnum_index on pg_attribute a  (cost=0.42..0.69 rows=1
width=70) (actual time=0.009..0.009 rows=1 loops=424)
Index Cond: ((attrelid = i.indrelid) AND
(attnum = (i.indkey)[(generate_series(0, (i.indnatts - 1)))]))
  ->  Index Scan using pg_class_oid_index on pg_class c 
(cost=0.42..0.56 rows=1 width=68) (actual time=0.005..0.005 rows=1
loops=424)
Index Cond: (oid = i.indexrelid)
->  Index Scan using pg_namespace_oid_index on pg_namespace n 
(cost=0.14..0.92 rows=1 width=68) (actual time=0.001..0.001 rows=0
loops=424)
  Index Cond: (oid = t.relnamespace)
  Filter: (nspname ~~ 'f10_0511, public'::text)
  Rows Removed by Filter: 1
Planning Time: 1.176 ms
Execution Time: 76.031 ms




--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[Tom Lane]

PegoraroF10  writes:
> Values for autovacuum and autoanalyse are Null because I did not configured
> them for system tables yet, but I´m doing vacuum manually once a week. My
> question now is why those selects varies that way. 

Well, one point is that the execution time would probably vary hugely
depending on what's supplied for the parameters in

WHERE n.nspname LIKE $4 AND t.relname LIKE $5

which you haven't told us.  I'm also wondering about just how many rows
get emitted by "generate_series($2, indnatts - $3)", and why that
particular part of the query makes any sense at all.

regards, tom lane

Re: slow queries on system tables

[PegoraroF10]

Well, not exactly.

Values for autovacuum and autoanalyse are Null because I did not configured
them for system tables yet, but I´m doing vacuum manually once a week. My
question now is why those selects varies that way. 

Almost all times it spend 20ms but 2 o 3% of the times it spend 500ms, why ? 
System tables are not cached ? What is Postgres doing on that time to get
that response times ?
Can I help Postgres on any way ?



--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[Adrian Klaver]

On 8/15/19 12:09 PM, PegoraroF10 wrote:

last values for autovacuum and autoanalyse are Null.

Thanks, I´ll change and see if that solve our problem


I thought we had been down this trail before:

https://www.postgresql.org/message-id/1564168884421-0.post%40n3.nabble.com





--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html






--
Adrian Klaver
adrian.kla...@aklaver.com

Re: slow queries on system tables

[PegoraroF10]

last values for autovacuum and autoanalyse are Null.

Thanks, I´ll change and see if that solve our problem



--
Sent from: https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html

Re: slow queries on system tables

[Michael Lewis]

Are you autovacuuming and analyzing aggressively enough? Is there bloat or
other concern for these system tables? I expect it may be a concern based
on what I remember about your environment having thousands of tables and
perhaps autovacuum not keeping up (re: Too slow to create new schema and
their tables, functions, triggers).

Can you check results for last (auto)vacuum and analyze?
select * from pg_stat_all_tables where relname IN( 'pg_class',
'pg_attribute', 'pg_index' );