Improve automatic analyze messages for inheritance trees

Started by Etsuro Fujitaover 11 years ago7 messages
#1Etsuro Fujita
fujita.etsuro@lab.ntt.co.jp
1 attachment(s)

I noticed that analyze messages shown by autovacuum don't discriminate
between non-inherited cases and inherited cases, as shown in the below
example:

LOG: automatic analyze of table "postgres.public.pt" system usage: CPU
0.00s/0.01u sec elapsed 0.06 sec
LOG: automatic analyze of table "postgres.public.pt" system usage: CPU
0.00s/0.02u sec elapsed 0.11 sec

(The first one is for table "postgres.public.pt" and the second one is
for table inheritance tree "postgres.public.pt".)

So, I'd like to propose improving the messages for inherited cases, in
order to easily distinguish such cases from non-inherited cases. Please
find attached a patch. I'll add this to the upcoming CF.

Thanks,

Best regards,
Etsuro Fujita

Attachments:

autoanalyze-message.patchtext/x-diff; name=autoanalyze-message.patchDownload
*** a/src/backend/commands/analyze.c
--- b/src/backend/commands/analyze.c
***************
*** 648,659 **** do_analyze_rel(Relation onerel, VacuumStmt *vacstmt,
  		if (Log_autovacuum_min_duration == 0 ||
  			TimestampDifferenceExceeds(starttime, GetCurrentTimestamp(),
  									   Log_autovacuum_min_duration))
! 			ereport(LOG,
! 					(errmsg("automatic analyze of table \"%s.%s.%s\" system usage: %s",
! 							get_database_name(MyDatabaseId),
! 							get_namespace_name(RelationGetNamespace(onerel)),
! 							RelationGetRelationName(onerel),
! 							pg_rusage_show(&ru0))));
  	}
  
  	/* Roll back any GUC changes executed by index functions */
--- 648,669 ----
  		if (Log_autovacuum_min_duration == 0 ||
  			TimestampDifferenceExceeds(starttime, GetCurrentTimestamp(),
  									   Log_autovacuum_min_duration))
! 		{
! 			if (inh)
! 				ereport(LOG,
! 						(errmsg("automatic analyze of table inheritance tree \"%s.%s.%s\" system usage: %s",
! 								get_database_name(MyDatabaseId),
! 								get_namespace_name(RelationGetNamespace(onerel)),
! 								RelationGetRelationName(onerel),
! 								pg_rusage_show(&ru0))));
! 			else
! 				ereport(LOG,
! 						(errmsg("automatic analyze of table \"%s.%s.%s\" system usage: %s",
! 								get_database_name(MyDatabaseId),
! 								get_namespace_name(RelationGetNamespace(onerel)),
! 								RelationGetRelationName(onerel),
! 								pg_rusage_show(&ru0))));
! 		}
  	}
  
  	/* Roll back any GUC changes executed by index functions */
#2Simon Riggs
simon@2ndQuadrant.com
In reply to: Etsuro Fujita (#1)
Re: Improve automatic analyze messages for inheritance trees

On 6 October 2014 11:07, Etsuro Fujita <fujita.etsuro@lab.ntt.co.jp> wrote:

I noticed that analyze messages shown by autovacuum don't discriminate
between non-inherited cases and inherited cases, as shown in the below
example:

LOG: automatic analyze of table "postgres.public.pt" system usage: CPU
0.00s/0.01u sec elapsed 0.06 sec
LOG: automatic analyze of table "postgres.public.pt" system usage: CPU
0.00s/0.02u sec elapsed 0.11 sec

(The first one is for table "postgres.public.pt" and the second one is
for table inheritance tree "postgres.public.pt".)

So, I'd like to propose improving the messages for inherited cases, in
order to easily distinguish such cases from non-inherited cases. Please
find attached a patch. I'll add this to the upcoming CF.

Thanks for the suggestion. It seems like a useful addition.

Existing log analysis may wish to see the "automatic analyze of table"
on each row.
So it would be good to keep
automatic analyze of table \"%s.%s.%s\"

Can we add some words after this to indicate inheritance? (I have no
suggestions at present)
e.g.
automatic analyze of table \"%s.%s.%s\" (new words go here)

--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

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

#3Etsuro Fujita
fujita.etsuro@lab.ntt.co.jp
In reply to: Simon Riggs (#2)
Re: Improve automatic analyze messages for inheritance trees

(2014/10/16 11:45), Simon Riggs wrote:

On 6 October 2014 11:07, Etsuro Fujita <fujita.etsuro@lab.ntt.co.jp> wrote:

I noticed that analyze messages shown by autovacuum don't discriminate
between non-inherited cases and inherited cases, as shown in the below
example:

LOG: automatic analyze of table "postgres.public.pt" system usage: CPU
0.00s/0.01u sec elapsed 0.06 sec
LOG: automatic analyze of table "postgres.public.pt" system usage: CPU
0.00s/0.02u sec elapsed 0.11 sec

(The first one is for table "postgres.public.pt" and the second one is
for table inheritance tree "postgres.public.pt".)

So, I'd like to propose improving the messages for inherited cases, in
order to easily distinguish such cases from non-inherited cases. Please
find attached a patch. I'll add this to the upcoming CF.

Thanks for the suggestion. It seems like a useful addition.

Existing log analysis may wish to see the "automatic analyze of table"
on each row.
So it would be good to keep
automatic analyze of table \"%s.%s.%s\"

Agreed.

Can we add some words after this to indicate inheritance? (I have no
suggestions at present)
e.g.
automatic analyze of table \"%s.%s.%s\" (new words go here)

How about this?

automatic analyze of table \"%s.%s.%s\" as inheritance tree

Thank you for the comment.

Best regards,
Etsuro Fujita

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

#4Simon Riggs
simon@2ndQuadrant.com
In reply to: Etsuro Fujita (#3)
Re: Improve automatic analyze messages for inheritance trees

On 16 October 2014 06:49, Etsuro Fujita <fujita.etsuro@lab.ntt.co.jp> wrote:

How about this?

automatic analyze of table \"%s.%s.%s\" as inheritance tree

Thank you for the comment.

Would it be useful to keep track of how many tables just got analyzed?

i.e. analyze of foo (including N inheritance children)

--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

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

#5Etsuro Fujita
fujita.etsuro@lab.ntt.co.jp
In reply to: Simon Riggs (#4)
Re: Improve automatic analyze messages for inheritance trees

(2014/10/16 17:17), Simon Riggs wrote:

On 16 October 2014 06:49, Etsuro Fujita <fujita.etsuro@lab.ntt.co.jp> wrote:

How about this?

automatic analyze of table \"%s.%s.%s\" as inheritance tree

Thank you for the comment.

Would it be useful to keep track of how many tables just got analyzed?

i.e. analyze of foo (including N inheritance children)

I think that's a good idea. So, I'll update the patch.

Thanks,

Best regards,
Etsuro Fujita

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

#6Etsuro Fujita
fujita.etsuro@lab.ntt.co.jp
In reply to: Etsuro Fujita (#5)
1 attachment(s)
Re: Improve automatic analyze messages for inheritance trees

(2014/10/17 18:35), Etsuro Fujita wrote:

(2014/10/16 17:17), Simon Riggs wrote:

Would it be useful to keep track of how many tables just got analyzed?

i.e. analyze of foo (including N inheritance children)

I think that's a good idea. So, I'll update the patch.

Done. Attached is an updated version of the patch.

Thanks for the comment!

Best regards,
Etsuro Fujita

Attachments:

autoanalyze-message-2.patchtext/x-patch; name=autoanalyze-message-2.patchDownload
*** a/src/backend/commands/analyze.c
--- b/src/backend/commands/analyze.c
***************
*** 648,659 **** do_analyze_rel(Relation onerel, VacuumStmt *vacstmt,
  		if (Log_autovacuum_min_duration == 0 ||
  			TimestampDifferenceExceeds(starttime, GetCurrentTimestamp(),
  									   Log_autovacuum_min_duration))
! 			ereport(LOG,
! 					(errmsg("automatic analyze of table \"%s.%s.%s\" system usage: %s",
! 							get_database_name(MyDatabaseId),
! 							get_namespace_name(RelationGetNamespace(onerel)),
! 							RelationGetRelationName(onerel),
! 							pg_rusage_show(&ru0))));
  	}
  
  	/* Roll back any GUC changes executed by index functions */
--- 648,699 ----
  		if (Log_autovacuum_min_duration == 0 ||
  			TimestampDifferenceExceeds(starttime, GetCurrentTimestamp(),
  									   Log_autovacuum_min_duration))
! 		{
! 			if (inh)
! 			{
! 				List	   *tableOIDs;
! 				int			nchildren;
! 
! 				/*
! 				 * Find all members of inheritance set.
! 				 *
! 				 * Note: we already got the lock on children except for
! 				 * temp tables of other backends.  See
! 				 * acquire_inherited_sample_rows.
! 				 */
! 				tableOIDs =
! 					find_all_inheritors(RelationGetRelid(onerel), NoLock, NULL);
! 
! 				/*
! 				 * Compute the number of children.
! 				 *
! 				 * Note: this might contain temp tables of other backends,
! 				 * which we didn't analyze, unless those tables have been
! 				 * dropped concurrently.  We could get the number of children
! 				 * that we did analyze, if we were willing to change the API
! 				 * of acquire_inherited_sample_rows to output it, or check
! 				 * whether each child in tableOIDs is a temp table of another
! 				 * backend or not using RELATION_IS_OTHER_TEMP(), but it
! 				 * doesn't seem worth the code complexity or the overhead.
! 				 */
! 				nchildren = list_length(tableOIDs) - 1;
! 
! 				ereport(LOG,
! 						(errmsg("automatic analyze of table \"%s.%s.%s\" (including %d inheritance children) system usage: %s",
! 								get_database_name(MyDatabaseId),
! 								get_namespace_name(RelationGetNamespace(onerel)),
! 								RelationGetRelationName(onerel),
! 								nchildren,
! 								pg_rusage_show(&ru0))));
! 			}
! 			else
! 				ereport(LOG,
! 						(errmsg("automatic analyze of table \"%s.%s.%s\" system usage: %s",
! 								get_database_name(MyDatabaseId),
! 								get_namespace_name(RelationGetNamespace(onerel)),
! 								RelationGetRelationName(onerel),
! 								pg_rusage_show(&ru0))));
! 		}
  	}
  
  	/* Roll back any GUC changes executed by index functions */
#7Simon Riggs
simon@2ndQuadrant.com
In reply to: Etsuro Fujita (#6)
Re: Improve automatic analyze messages for inheritance trees

On 30 October 2014 03:30, Etsuro Fujita <fujita.etsuro@lab.ntt.co.jp> wrote:

(2014/10/17 18:35), Etsuro Fujita wrote:

(2014/10/16 17:17), Simon Riggs wrote:

Would it be useful to keep track of how many tables just got analyzed?

i.e. analyze of foo (including N inheritance children)

I think that's a good idea. So, I'll update the patch.

Done. Attached is an updated version of the patch.

Thanks for the comment!

The patch was kinda ok, but we have deeper problems.

If we have a 3 level hierarchy like foo->(p1, p2->(p4), p3)
then we still report this pretty strangely
LOG: automatic analyze of table "postgres.public.p1" system usage:
CPU 0.00s/0.00u sec elapsed 0.05 sec
LOG: automatic analyze of table "postgres.public.foo" system usage:
CPU 0.00s/0.00u sec elapsed 0.04 sec
LOG: automatic analyze of table "postgres.public.foo" (including 3
inheritance children) system usage: CPU 0.00s/0.01u sec elapsed 0.12
sec
LOG: automatic analyze of table "postgres.public.p4" system usage:
CPU 0.00s/0.00u sec elapsed 0.00 sec

notice that p4 is not included as an inheritance child, even though it
most surely is. Why is p4 reported, when p1, p2 and p3 are not?

and I notice psql reports this incorrectly also

postgres=# \d+ foo

Table "public.foo"
Column | Type | Modifiers | Storage | Stats target | Description

----------+---------+-----------+---------+--------------+-------------

?column? | integer | | plain | |

Child tables: p1,
p2,
p3

No mention of grandchildren...

Not your fault, but this patch doesn't sufficiently improve the
situation to commit it, yet.

Sorry, patch returned with feedback, for now.

--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

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