diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c index 8af12b5c6b..38d69d887e 100644 --- a/src/backend/commands/analyze.c +++ b/src/backend/commands/analyze.c @@ -312,6 +312,8 @@ do_analyze_rel(Relation onerel, VacuumParams *params, Oid save_userid; int save_sec_context; int save_nestlevel; + PgStat_Counter startreadtime = 0; + long startblksread = 0; if (inh) ereport(elevel, @@ -347,6 +349,8 @@ do_analyze_rel(Relation onerel, VacuumParams *params, if (IsAutoVacuumWorkerProcess() && params->log_min_duration >= 0) { pg_rusage_init(&ru0); + startreadtime = pgStatBlockReadTime; + startblksread = pgBufferUsage.shared_blks_read; if (params->log_min_duration > 0) starttime = GetCurrentTimestamp(); } @@ -685,12 +689,27 @@ do_analyze_rel(Relation onerel, VacuumParams *params, if (params->log_min_duration == 0 || TimestampDifferenceExceeds(starttime, GetCurrentTimestamp(), params->log_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)))); + { + double d_readtime = (double) (pgStatBlockReadTime - startreadtime)/1000000; + long d_readblks = pgBufferUsage.shared_blks_read - startblksread; + + /* We only log detailed autoanalyze statistics if we have sensible data (1MB) */ + if(track_io_timing && (double) ((BLCKSZ * d_readblks)/1000000) >= 1) + ereport(LOG, + (errmsg("automatic analyze of table \"%s.%s.%s\" avg read rate: %.3f MB/s (read time: %.2f s), system usage: %s", + get_database_name(MyDatabaseId), + get_namespace_name(RelationGetNamespace(onerel)), + RelationGetRelationName(onerel), + (double) (BLCKSZ * d_readblks / d_readtime)/1000000, + d_readtime, 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 */