8000 Improve logging of autovacuum I/O activity · postgrespro/postgres_cluster@9d3b502 · GitHub
[go: up one dir, main page]
Skip to content

Commit 9d3b502

Browse files
alvherrealvherre
committed
Improve logging of autovacuum I/O activity
This adds some I/O stats to the logging of autovacuum (when the operation takes long enough that log_autovacuum_min_duration causes it to be logged), so that it is easier to tune. Notably, it adds buffer I/O counts (hits, misses, dirtied) and read and write rate. Authors: Greg Smith and Noah Misch
1 parent 877b67c commit 9d3b502

File tree

5 files changed

+54
-9
lines changed

5 files changed

+54
-9
lines changed

‎src/backend/commands/vacuum.c‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -214,6 +214,9 @@ vacuum(VacuumStmt *vacstmt, Oid relid, bool do_toast,
214214

215215
VacuumCostActive = (VacuumCostDelay > 0);
216216
VacuumCostBalance = 0;
217+
VacuumPageHit = 0;
218+
VacuumPageMiss = 0;
219+
VacuumPageDirty = 0;
217220

218221
/*
219222
* Loop to process each selected relation.

‎src/backend/commands/vacuumlazy.c‎

Lines changed: 28 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -155,6 +155,10 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
155155
BlockNumber possibly_freeable;
156156
PGRUsage ru0;
157157
TimestampTz starttime = 0;
158+
long secs;
159+
int usecs;
160+
double read_rate,
161+
write_rate;
158162
bool scan_all;
159163
TransactionId freezeTableLimit;
160164
BlockNumber new_rel_pages;
@@ -166,8 +170,7 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
166170
if (IsAutoVacuumWorkerProcess() && Log_autovacuum_min_duration >= 0)
167171
{
168172
pg_rusage_init(&ru0);
169-
if (Log_autovacuum_min_duration > 0)
170-
starttime = GetCurrentTimestamp();
173+
starttime = GetCurrentTimestamp();
171174
}
172175

173176
if (vacstmt->options & VACOPT_VERBOSE)
@@ -262,13 +265,29 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
262265
/* and log the action if appropriate */
263266
if (IsAutoVacuumWorkerProcess() && Log_autovacuum_min_duration >= 0)
264267
{
268+
TimestampTz endtime = GetCurrentTimestamp();
269+
265270
if (Log_autovacuum_min_duration == 0 ||
266-
TimestampDifferenceExceeds(starttime, GetCurrentTimestamp(),
271+
TimestampDifferenceExceeds(starttime, endtime,
267272
Log_autovacuum_min_duration))
273+
{
274+
TimestampDifference(starttime, endtime, &secs, &usecs);
275+
276+
read_rate = 0;
277+
write_rate = 0;
278+
if ((secs > 0) || (usecs > 0))
279+
{
280+
read_rate = (double) BLCKSZ * VacuumPageMiss / (1024 * 1024) /
281+
(secs + usecs / 1000000.0);
282+
write_rate = (double) BLCKSZ * VacuumPageDirty / (1024 * 1024) /
283+
(secs + usecs / 1000000.0);
284+
}
268285
ereport(LOG,
269286
(errmsg("automatic vacuum of table \"%s.%s.%s\": index scans: %d\n"
270287
"pages: %d removed, %d remain\n"
271288
"tuples: %.0f removed, %.0f remain\n"
289+
"buffer usage: %d hits, %d misses, %d dirtied\n"
290+
"avg read rate: %.3f MiB/s, avg write rate: %.3f MiB/s\n"
272291
"system usage: %s",
273292
get_database_name(MyDatabaseId),
274293
get_namespace_name(RelationGetNamespace(onerel)),
@@ -277,8 +296,13 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
277296
vacrelstats->pages_removed,
278297
vacrelstats->rel_pages,
279298
vacrelstats->tuples_deleted,
280-
new_rel_tuples,
299+
vacrelstats->new_rel_tuples,
300+
VacuumPageHit,
301+
VacuumPageMiss,
302+
VacuumPageDirty,
303+
read_rate,write_rate,
281304
pg_rusage_show(&ru0))));
305+
}
282306
}
283307
}
284308

‎src/backend/storage/buffer/bufmgr.c‎

Lines changed: 15 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -340,6 +340,7 @@ ReadBuffer_common(SMgrRelation smgr, char relpersistence, ForkNumber forkNum,
340340
{
341341
/* Just need to update stats before we exit */
342342
*hit = true;
343+
VacuumPageHit++;
343344

344345
if (VacuumCostActive)
345346
VacuumCostBalance += VacuumCostPageHit;
@@ -471,6 +472,7 @@ ReadBuffer_common(SMgrRelation smgr, char relpersistence, ForkNumber forkNum,
471472
TerminateBufferIO(bufHdr, false, BM_VALID);
472473
}
473474

475+
VacuumPageMiss++;
474476
if (VacuumCostActive)
475477
VacuumCostBalance += VacuumCostPageMiss;
476478

@@ -972,10 +974,14 @@ MarkBufferDirty(Buffer buffer)
972974
Assert(bufHdr->refcount > 0);
973975

974976
/*
975-
* If the buffer was not dirty already, do vacuum cost accounting.
977+
* If the buffer was not dirty already, do vacuum accounting.
976978
*/
977-
if (!(bufHdr->flags & BM_DIRTY) && VacuumCostActive)
978-
VacuumCostBalance += VacuumCostPageDirty;
979+
if (!(bufHdr->flags & BM_DIRTY))
980+
{
981+
VacuumPageDirty++;
982+
if (VacuumCostActive)
983+
VacuumCostBalance += VacuumCostPageDirty;
984+
}
979985

980986
bufHdr->flags |= (BM_DIRTY | BM_JUST_DIRTIED);
981987

@@ -2337,8 +2343,12 @@ SetBufferCommitInfoNeedsSave(Buffer buffer)
23372343
{
23382344
LockBufHdr(bufHdr);
23392345
Assert(bufHdr->refcount > 0);
2340-
if (!(bufHdr->flags & BM_DIRTY) && VacuumCostActive)
2341-
VacuumCostBalance += VacuumCostPageDirty;
2346+
if (!(bufHdr->flags & BM_DIRTY))
2347+
{
2348+
VacuumPageDirty++;
2349+
if (VacuumCostActive)
2350+
VacuumCostBalance += VacuumCostPageDirty;
2351+
}
23422352
bufHdr->flags |= (BM_DIRTY | BM_JUST_DIRTIED);
23432353
UnlockBufHdr(bufHdr);
23442354
}

‎src/backend/utils/init/globals.c‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -115,6 +115,10 @@ int VacuumCostPageDirty = 20;
115115
int VacuumCostLimit = 200;
116116
int VacuumCostDelay = 0;
117117

118+
int VacuumPageHit = 0;
119+
int VacuumPageMiss = 0;
120+
int VacuumPageDirty = 0;
121+
118122
int VacuumCostBalance = 0; /* working state for vacuum */
119123
bool VacuumCostActive = false;
120124

‎src/include/miscadmin.h‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -230,6 +230,10 @@ extern int VacuumCostPageDirty;
230230
extern int VacuumCostLimit;
231231
extern int VacuumCostDelay;
232232

233+
extern int VacuumPageHit;
234+
extern int VacuumPageMiss;
235+
extern int VacuumPageDirty;
236+
233237
extern int VacuumCostBalance;
234238
extern bool VacuumCostActive;
235239

0 commit comments

Comments
 (0)
0