88 *
99 *
1010 * IDENTIFICATION
11- * $PostgreSQL: pgsql/src/backend/storage/buffer/bufmgr.c,v 1.234 2008/07/13 20:45:47 tgl Exp $
11+ * $PostgreSQL: pgsql/src/backend/storage/buffer/bufmgr.c,v 1.235 2008/08/01 13:16:08 alvherre Exp $
1212 *
1313 *-------------------------------------------------------------------------
1414 */
3434#include <unistd.h>
3535
3636#include "miscadmin.h"
37+ #include "pg_trace.h"
38+ #include "pgstat.h"
3739#include "postmaster/bgwriter.h"
3840#include "storage/buf_internals.h"
3941#include "storage/bufmgr.h"
4244#include "storage/smgr.h"
4345#include "utils/rel.h"
4446#include "utils/resowner.h"
45- #include "pgstat.h"
4647
4748
4849/* Note: these two macros only work on shared buffers, not local ones! */
@@ -213,12 +214,22 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, BlockNumber blockNum,
213214if (isExtend )
214215blockNum = smgrnblocks (smgr );
215216
217+ TRACE_POSTGRESQL_BUFFER_READ_START (blockNum ,smgr -> smgr_rnode .spcNode ,
218+ smgr -> smgr_rnode .dbNode ,smgr -> smgr_rnode .relNode ,isLocalBuf );
219+
216220if (isLocalBuf )
217221{
218222ReadLocalBufferCount ++ ;
219223bufHdr = LocalBufferAlloc (smgr ,blockNum ,& found );
220224if (found )
225+ {
221226LocalBufferHitCount ++ ;
227+ TRACE_POSTGRESQL_BUFFER_HIT (true);/* true == local buffer */
228+ }
229+ else
230+ {
231+ TRACE_POSTGRESQL_BUFFER_MISS (true);/* ditto */
232+ }
222233}
223234else
224235{
@@ -230,7 +241,14 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, BlockNumber blockNum,
230241 */
231242bufHdr = BufferAlloc (smgr ,blockNum ,strategy ,& found );
232243if (found )
244+ {
233245BufferHitCount ++ ;
246+ TRACE_POSTGRESQL_BUFFER_HIT (false);/* false != local buffer */
247+ }
248+ else
249+ {
250+ TRACE_POSTGRESQL_BUFFER_MISS (false);/* ditto */
251+ }
234252}
235253
236254/* At this point we do NOT hold any locks. */
@@ -246,6 +264,11 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, BlockNumber blockNum,
246264if (VacuumCostActive )
247265VacuumCostBalance += VacuumCostPageHit ;
248266
267+ TRACE_POSTGRESQL_BUFFER_READ_DONE (blockNum ,
268+ smgr -> smgr_rnode .spcNode ,
269+ smgr -> smgr_rnode .dbNode ,
270+ smgr -> smgr_rnode .relNode ,isLocalBuf ,found );
271+
249272return BufferDescriptorGetBuffer (bufHdr );
250273}
251274
@@ -368,6 +391,10 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, BlockNumber blockNum,
368391if (VacuumCostActive )
369392VacuumCostBalance += VacuumCostPageMiss ;
370393
394+ TRACE_POSTGRESQL_BUFFER_READ_DONE (blockNum ,smgr -> smgr_rnode .spcNode ,
395+ smgr -> smgr_rnode .dbNode ,smgr -> smgr_rnode .relNode ,
396+ isLocalBuf ,found );
397+
371398return BufferDescriptorGetBuffer (bufHdr );
372399}
373400
@@ -1086,6 +1113,8 @@ BufferSync(int flags)
10861113if (num_to_write == 0 )
10871114return ;/* nothing to do */
10881115
1116+ TRACE_POSTGRESQL_BUFFER_SYNC_START (NBuffers ,num_to_write );
1117+
10891118/*
10901119 * Loop over all buffers again, and write the ones (still) marked with
10911120 * BM_CHECKPOINT_NEEDED. In this loop, we start at the clock sweep point
@@ -1117,6 +1146,7 @@ BufferSync(int flags)
11171146{
11181147if (SyncOneBuffer (buf_id , false)& BUF_WRITTEN )
11191148{
1149+ TRACE_POSTGRESQL_BUFFER_SYNC_WRITTEN (buf_id );
11201150BgWriterStats .m_buf_written_checkpoints ++ ;
11211151num_written ++ ;
11221152
@@ -1147,6 +1177,8 @@ BufferSync(int flags)
11471177buf_id = 0 ;
11481178}
11491179
1180+ TRACE_POSTGRESQL_BUFFER_SYNC_DONE (NBuffers ,num_written ,num_to_write );
1181+
11501182/*
11511183 * Update checkpoint statistics. As noted above, this doesn't include
11521184 * buffers written by other backends or bgwriter scan.
@@ -1653,11 +1685,13 @@ PrintBufferLeakWarning(Buffer buffer)
16531685void
16541686CheckPointBuffers (int flags )
16551687{
1688+ TRACE_POSTGRESQL_BUFFER_CHECKPOINT_START (flags );
16561689CheckpointStats .ckpt_write_t = GetCurrentTimestamp ();
16571690BufferSync (flags );
16581691CheckpointStats .ckpt_sync_t = GetCurrentTimestamp ();
16591692smgrsync ();
16601693CheckpointStats .ckpt_sync_end_t = GetCurrentTimestamp ();
1694+ TRACE_POSTGRESQL_BUFFER_CHECKPOINT_DONE ();
16611695}
16621696
16631697
@@ -1759,6 +1793,10 @@ FlushBuffer(volatile BufferDesc *buf, SMgrRelation reln)
17591793if (reln == NULL )
17601794reln = smgropen (buf -> tag .rnode );
17611795
1796+ TRACE_POSTGRESQL_BUFFER_FLUSH_START (reln -> smgr_rnode .spcNode ,
1797+ reln -> smgr_rnode .dbNode ,
1798+ reln -> smgr_rnode .relNode );
1799+
17621800/*
17631801 * Force XLOG flush up to buffer's LSN. This implements the basic WAL
17641802 * rule that log updates must hit disk before any of the data-file changes
@@ -1785,6 +1823,9 @@ FlushBuffer(volatile BufferDesc *buf, SMgrRelation reln)
17851823
17861824BufferFlushCount ++ ;
17871825
1826+ TRACE_POSTGRESQL_BUFFER_FLUSH_DONE (reln -> smgr_rnode .spcNode ,
1827+ reln -> smgr_rnode .dbNode ,reln -> smgr_rnode .relNode );
1828+
17881829/*
17891830 * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
17901831 * end the io_in_progress state.