database/postgres
database/postgres
1
0
Fork 0
mirror of https://github.com/postgres/postgres.git synced 2025-05-05 09:19:17 +03:00
Code

Reorder log_autovacuum_min_duration log output.

Browse Source 
This order seems more natural.  It starts with details that are
particular to heap and index data structures, and ends with system-level
costs incurred during the autovacuum worker's VACUUM/ANALYZE operation.

Author: Peter Geoghegan <pg@bowt.ie>
Discussion: https://postgr.es/m/CAH2-WzkzxK6ahA9xxsOftRtBX_R0swuHZsvo4QUbak1Bz7hb7Q@mail.gmail.com
Backpatch: 14-, which enhanced the log output in various ways.
This commit is contained in:
Peter Geoghegan 2021-08-27 13:08:41 -07:00
parent de5dcb0796
commit fdfbfa24fa
2 changed files with 22 additions and 23 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

33
src/backend/access/heap/vacuumlazy.c
View File

@ -739,6 +739,7 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
{ {
StringInfoData buf; StringInfoData buf;
char *msgfmt; char *msgfmt;
BlockNumber orig_rel_pages;
TimestampDifference(starttime, endtime, &secs, &usecs); TimestampDifference(starttime, endtime, &secs, &usecs);
@ -796,34 +797,27 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
(long long) vacrel->new_rel_tuples, (long long) vacrel->new_rel_tuples,
(long long) vacrel->new_dead_tuples, (long long) vacrel->new_dead_tuples,
OldestXmin); OldestXmin);
appendStringInfo(&buf, orig_rel_pages = vacrel->rel_pages + vacrel->pages_removed;
_("buffer usage: %lld hits, %lld misses, %lld dirtied\n"), if (orig_rel_pages > 0)
(long long) VacuumPageHit,
(long long) VacuumPageMiss,
(long long) VacuumPageDirty);
if (vacrel->rel_pages > 0)
{ {
BlockNumber orig_rel_pages;
if (vacrel->do_index_vacuuming) if (vacrel->do_index_vacuuming)
{ {
msgfmt = _("%u pages from table (%.2f%% of total) had %lld dead item identifiers removed\n");
if (vacrel->nindexes == 0 || vacrel->num_index_scans == 0) if (vacrel->nindexes == 0 || vacrel->num_index_scans == 0)
appendStringInfoString(&buf, _("index scan not needed: ")); appendStringInfoString(&buf, _("index scan not needed: "));
else else
appendStringInfoString(&buf, _("index scan needed: ")); appendStringInfoString(&buf, _("index scan needed: "));
msgfmt = _("%u pages from table (%.2f%% of total) had %lld dead item identifiers removed\n");
} }
else else
{ {
msgfmt = _("%u pages from table (%.2f%% of total) have %lld dead item identifiers\n");
if (!vacrel->failsafe_active) if (!vacrel->failsafe_active)
appendStringInfoString(&buf, _("index scan bypassed: ")); appendStringInfoString(&buf, _("index scan bypassed: "));
else else
appendStringInfoString(&buf, _("index scan bypassed by failsafe: ")); appendStringInfoString(&buf, _("index scan bypassed by failsafe: "));
msgfmt = _("%u pages from table (%.2f%% of total) have %lld dead item identifiers\n");
} }
orig_rel_pages = vacrel->rel_pages + vacrel->pages_removed;
appendStringInfo(&buf, msgfmt, appendStringInfo(&buf, msgfmt,
vacrel->lpdead_item_pages, vacrel->lpdead_item_pages,
100.0 * vacrel->lpdead_item_pages / orig_rel_pages, 100.0 * vacrel->lpdead_item_pages / orig_rel_pages,
@ -844,8 +838,6 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
istat->pages_deleted, istat->pages_deleted,
istat->pages_free); istat->pages_free);
} }
appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
read_rate, write_rate);
if (track_io_timing) if (track_io_timing)
{ {
appendStringInfoString(&buf, _("I/O timings:")); appendStringInfoString(&buf, _("I/O timings:"));
@ -859,12 +851,19 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
(double) (pgStatBlockWriteTime - startwritetime) / 1000); (double) (pgStatBlockWriteTime - startwritetime) / 1000);
appendStringInfoChar(&buf, '\n'); appendStringInfoChar(&buf, '\n');
} }
appendStringInfo(&buf, _("system usage: %s\n"), pg_rusage_show(&ru0)); appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
read_rate, write_rate);
appendStringInfo(&buf, appendStringInfo(&buf,
_("WAL usage: %lld records, %lld full page images, %llu bytes"), _("buffer usage: %lld hits, %lld misses, %lld dirtied\n"),
(long long) VacuumPageHit,
(long long) VacuumPageMiss,
(long long) VacuumPageDirty);
appendStringInfo(&buf,
_("WAL usage: %lld records, %lld full page images, %llu bytes\n"),
(long long) walusage.wal_records, (long long) walusage.wal_records,
(long long) walusage.wal_fpi, (long long) walusage.wal_fpi,
(unsigned long long) walusage.wal_bytes); (unsigned long long) walusage.wal_bytes);
appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
ereport(LOG, ereport(LOG,
(errmsg_internal("%s", buf.data))); (errmsg_internal("%s", buf.data)));

12
src/backend/commands/analyze.c
View File

@ -777,12 +777,6 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
get_database_name(MyDatabaseId), get_database_name(MyDatabaseId),
get_namespace_name(RelationGetNamespace(onerel)), get_namespace_name(RelationGetNamespace(onerel)),
RelationGetRelationName(onerel)); RelationGetRelationName(onerel));
appendStringInfo(&buf, _("buffer usage: %lld hits, %lld misses, %lld dirtied\n"),
(long long) AnalyzePageHit,
(long long) AnalyzePageMiss,
(long long) AnalyzePageDirty);
appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
read_rate, write_rate);
if (track_io_timing) if (track_io_timing)
{ {
appendStringInfoString(&buf, _("I/O timings:")); appendStringInfoString(&buf, _("I/O timings:"));
@ -796,6 +790,12 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
(double) (pgStatBlockWriteTime - startwritetime) / 1000); (double) (pgStatBlockWriteTime - startwritetime) / 1000);
appendStringInfoChar(&buf, '\n'); appendStringInfoChar(&buf, '\n');
} }
appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
read_rate, write_rate);
appendStringInfo(&buf, _("buffer usage: %lld hits, %lld misses, %lld dirtied\n"),
(long long) AnalyzePageHit,
(long long) AnalyzePageMiss,
(long long) AnalyzePageDirty);
appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0)); appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
ereport(LOG, ereport(LOG,