@@ -105,6 +105,7 @@ typedef struct LVRelStats
105105BlockNumber old_rel_pages ;/* previous value of pg_class.relpages */
106106BlockNumber rel_pages ;/* total number of pages */
107107BlockNumber scanned_pages ;/* number of pages we examined */
108+ BlockNumber pinned_pages ;/* # of pages we could not initially lock */
108109double scanned_tuples ;/* counts only tuples on scanned pages */
109110double old_rel_tuples ;/* previous value of pg_class.reltuples */
110111double new_rel_tuples ;/* new estimated total # of tuples */
@@ -332,6 +333,7 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
332333TimestampDifferenceExceeds (starttime ,endtime ,
333334Log_autovacuum_min_duration ))
334335{
336+ StringInfoData buf ;
335337TimestampDifference (starttime ,endtime ,& secs ,& usecs );
336338
337339read_rate = 0 ;
@@ -343,27 +345,47 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
343345write_rate = (double )BLCKSZ * VacuumPageDirty / (1024 * 1024 ) /
344346(secs + usecs /1000000.0 );
345347}
348+
349+ /*
350+ * This is pretty messy, but we split it up so that we can skip
351+ * emitting individual parts of the message when not applicable.
352+ */
353+ initStringInfo (& buf );
354+ appendStringInfo (& buf ,_ ("automatic vacuum of table \"%s.%s.%s\": index scans: %d\n" ),
355+ get_database_name (MyDatabaseId ),
356+ get_namespace_name (RelationGetNamespace (onerel )),
357+ RelationGetRelationName (onerel ),
358+ vacrelstats -> num_index_scans );
359+ appendStringInfo (& buf ,_ ("pages: %d removed, %d remain\n" ),
360+ vacrelstats -> pages_removed ,
361+ vacrelstats -> rel_pages );
362+ if (vacrelstats -> pinned_pages > 0 )
363+ {
364+ if (scan_all )
365+ appendStringInfo (& buf ,_ ("waited for %d buffer pins\n" ),
366+ vacrelstats -> pinned_pages );
367+ else
368+ appendStringInfo (& buf ,
369+ _ ("skipped %d pages due to buffer pins\n" ),
370+ vacrelstats -> pinned_pages );
371+ }
372+ appendStringInfo (& buf ,
373+ _ ("tuples: %.0f removed, %.0f remain, %.0f are dead but not yet removable\n" ),
374+ vacrelstats -> tuples_deleted ,
375+ vacrelstats -> new_rel_tuples ,
376+ vacrelstats -> new_dead_tuples );
377+ appendStringInfo (& buf ,
378+ _ ("buffer usage: %d hits, %d misses, %d dirtied\n" ),
379+ VacuumPageHit ,
380+ VacuumPageMiss ,
381+ VacuumPageDirty );
382+ appendStringInfo (& buf ,_ ("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n" ),
383+ read_rate ,write_rate );
384+ appendStringInfo (& buf ,_ ("system usage: %s" ),pg_rusage_show (& ru0 ));
385+
346386ereport (LOG ,
347- (errmsg ("automatic vacuum of table \"%s.%s.%s\": index scans: %d\n"
348- "pages: %d removed, %d remain\n"
349- "tuples: %.0f removed, %.0f remain, %.0f are dead but not yet removable\n"
350- "buffer usage: %d hits, %d misses, %d dirtied\n"
351- "avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"
352- "system usage: %s" ,
353- get_database_name (MyDatabaseId ),
354- get_namespace_name (RelationGetNamespace (onerel )),
355- RelationGetRelationName (onerel ),
356- vacrelstats -> num_index_scans ,
357- vacrelstats -> pages_removed ,
358- vacrelstats -> rel_pages ,
359- vacrelstats -> tuples_deleted ,
360- vacrelstats -> new_rel_tuples ,
361- vacrelstats -> new_dead_tuples ,
362- VacuumPageHit ,
363- VacuumPageMiss ,
364- VacuumPageDirty ,
365- read_rate ,write_rate ,
366- pg_rusage_show (& ru0 ))));
387+ (errmsg_internal ("%s" ,buf .data )));
388+ pfree (buf .data );
367389}
368390}
369391}
@@ -438,6 +460,7 @@ lazy_scan_heap(Relation onerel, LVRelStats *vacrelstats,
438460BlockNumber next_not_all_visible_block ;
439461bool skipping_all_visible_blocks ;
440462xl_heap_freeze_tuple * frozen ;
463+ StringInfoData buf ;
441464
442465pg_rusage_init (& ru0 );
443466
@@ -611,6 +634,8 @@ lazy_scan_heap(Relation onerel, LVRelStats *vacrelstats,
611634/* We need buffer cleanup lock so that we can prune HOT chains. */
612635if (!ConditionalLockBufferForCleanup (buf ))
613636{
637+ vacrelstats -> pinned_pages ++ ;
638+
614639/*
615640 * If we're not scanning the whole relation to guard against XID
616641 * wraparound, it's OK to skip vacuuming a page. The next vacuum
@@ -1094,19 +1119,37 @@ lazy_scan_heap(Relation onerel, LVRelStats *vacrelstats,
10941119RelationGetRelationName (onerel ),
10951120tups_vacuumed ,vacuumed_pages )));
10961121
1122+ /*
1123+ * This is pretty messy, but we split it up so that we can skip emitting
1124+ * individual parts of the message when not applicable.
1125+ */
1126+ initStringInfo (& buf );
1127+ appendStringInfo (& buf ,
1128+ _ ("%.0f dead row versions cannot be removed yet.\n" ),
1129+ nkeep );
1130+ appendStringInfo (& buf ,_ ("There were %.0f unused item pointers.\n" ),
1131+ nunused );
1132+ if (vacrelstats -> pinned_pages > 0 )
1133+ {
1134+ if (scan_all )
1135+ appendStringInfo (& buf ,_ ("Waited for %d buffer pins.\n" ),
1136+ vacrelstats -> pinned_pages );
1137+ else
1138+ appendStringInfo (& buf ,_ ("Skipped %u pages due to buffer pins.\n" ),
1139+ vacrelstats -> pinned_pages );
1140+ }
1141+ appendStringInfo (& buf ,_ ("%u pages are entirely empty.\n" ),
1142+ empty_pages );
1143+ appendStringInfo (& buf ,_ ("%s." ),
1144+ pg_rusage_show (& ru0 ));
1145+
10971146ereport (elevel ,
10981147(errmsg ("\"%s\": found %.0f removable, %.0f nonremovable row versions in %u out of %u pages" ,
10991148RelationGetRelationName (onerel ),
11001149tups_vacuumed ,num_tuples ,
11011150vacrelstats -> scanned_pages ,nblocks ),
1102- errdetail ("%.0f dead row versions cannot be removed yet.\n"
1103- "There were %.0f unused item pointers.\n"
1104- "%u pages are entirely empty.\n"
1105- "%s." ,
1106- nkeep ,
1107- nunused ,
1108- empty_pages ,
1109- pg_rusage_show (& ru0 ))));
1151+ errdetail_internal ("%s" ,buf .data )));
1152+ pfree (buf .data );
11101153}
11111154
11121155