diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index 1f70fd4..c1bb9fd 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -1472,6 +1472,66 @@ SELECT pg_stat_get_backend_pid(s.backendid) AS procpid, Probe that fires when a deadlock is found by the deadlock detector. + + slru-readpage-start + (unsigned long, int, bool, TransactionId) + Probe that fires when a page is looked up in the SLRU buffer. arg0 is a pointer to + the current SLRU control structure, arg1 the page number, arg2 indicates when a dirty + read is in progress and arg3 is the transaction id (XID). + + + slru-readpage-done + (int) + Probe that fires when looking up the buffer page is done. + arg0 is the slot number finally returned. + + + slru-readpage-readonly + (unsigned long, int, TransactionId) + Probe that fires when a readonly lookup to find a page in the shared buffer is attempted. + arg0 is the pointer to the local SLRU control structure, arg1 defines the pagenumber, arg2 holds the + current transaction id. + + + slru-writepage-start + (unsigned long, int, TransactionId) + Probe that fires when an attempt to write to a page in the buffer is attempted. + arg0 is a pointer to the local SLRU control structure, arg1 the slot number and arg2 the pointer + to the data. + + + slru-writepage-done + () + Probe that fires when an attempt to write to a SLRU page is finished. + + + slru-readpage-physical-start + (unsigned long, char *, int, int) + Probe that fires when a page is phyiscally read into a buffer slot. + arg0 is a pointer to the local SLRU control structure, arg1 the path of the file + to read the page from, arg2 the page number and arg3 the slot number + of the target slot. + + + slru-readpage-physical-done + (int, int, int) + Probe that fires when a page is phyiscally read into a buffer slot. + arg0 indicates success or failure of the read attempt, arg1 holds the SLRU error cause and + arg2 finally the errno returned by the system call. + + + slru-writepage-physical-start + (unsigned long, int, int) + Probe that fires when a page is physically written out. arg0 is a pointer to the + local SLRU control structure, arg1 the page number and arg2 defines the slot number. + + + slru-writepage-physical-done + (int, int, int) + Probe that fires when physically writing a page out of the SLRU buffer is finished. arg0 indicates + wether the write action was successful, arg1 contains the error flag and arg2 the errno returned + by the system call. + @@ -1494,6 +1554,10 @@ SELECT pg_stat_get_backend_pid(s.backendid) AS procpid, unsigned int + TransactionId + unsigned int + + LWLockId int diff --git a/src/backend/access/transam/slru.c b/src/backend/access/transam/slru.c index 68e3869..235ca40 100644 --- a/src/backend/access/transam/slru.c +++ b/src/backend/access/transam/slru.c @@ -57,6 +57,7 @@ #include "storage/fd.h" #include "storage/shmem.h" #include "miscadmin.h" +#include "pg_trace.h" /* @@ -372,6 +373,7 @@ SimpleLruReadPage(SlruCtl ctl, int pageno, bool write_ok, { SlruShared shared = ctl->shared; + TRACE_POSTGRESQL_SLRU_READPAGE_START((uintptr_t)ctl, pageno, write_ok, xid); /* Outer loop handles restart if we must wait for someone else's I/O */ for (;;) { @@ -399,6 +401,7 @@ SimpleLruReadPage(SlruCtl ctl, int pageno, bool write_ok, } /* Otherwise, it's ready to use */ SlruRecentlyUsed(shared, slotno); + TRACE_POSTGRESQL_SLRU_READPAGE_DONE(slotno); return slotno; } @@ -446,6 +449,7 @@ SimpleLruReadPage(SlruCtl ctl, int pageno, bool write_ok, SlruReportIOError(ctl, pageno, xid); SlruRecentlyUsed(shared, slotno); + TRACE_POSTGRESQL_SLRU_READPAGE_DONE(slotno); return slotno; } } @@ -470,6 +474,8 @@ SimpleLruReadPage_ReadOnly(SlruCtl ctl, int pageno, TransactionId xid) SlruShared shared = ctl->shared; int slotno; + TRACE_POSTGRESQL_SLRU_READPAGE_READONLY((uintptr_t)ctl, pageno, xid); + /* Try to find the page while holding only shared lock */ LWLockAcquire(shared->ControlLock, LW_SHARED); @@ -511,6 +517,8 @@ SimpleLruWritePage(SlruCtl ctl, int slotno, SlruFlush fdata) int pageno = shared->page_number[slotno]; bool ok; + TRACE_POSTGRESQL_SLRU_WRITEPAGE_START((uintptr_t)ctl, pageno, slotno); + /* If a write is in progress, wait for it to finish */ while (shared->page_status[slotno] == SLRU_PAGE_WRITE_IN_PROGRESS && shared->page_number[slotno] == pageno) @@ -525,7 +533,10 @@ SimpleLruWritePage(SlruCtl ctl, int slotno, SlruFlush fdata) if (!shared->page_dirty[slotno] || shared->page_status[slotno] != SLRU_PAGE_VALID || shared->page_number[slotno] != pageno) + { + TRACE_POSTGRESQL_SLRU_WRITEPAGE_DONE(); return; + } /* * Mark the slot write-busy, and clear the dirtybit. After this point, a @@ -569,6 +580,8 @@ SimpleLruWritePage(SlruCtl ctl, int slotno, SlruFlush fdata) /* Now it's okay to ereport if we failed */ if (!ok) SlruReportIOError(ctl, pageno, InvalidTransactionId); + + TRACE_POSTGRESQL_SLRU_WRITEPAGE_DONE(); } /* @@ -593,6 +606,8 @@ SlruPhysicalReadPage(SlruCtl ctl, int pageno, int slotno) SlruFileName(ctl, path, segno); + TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_START((uintptr_t)ctl, path, pageno, slotno); + /* * In a crash-and-restart situation, it's possible for us to receive * commands to set the commit status of transactions whose bits are in @@ -607,6 +622,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pageno, int slotno) { slru_errcause = SLRU_OPEN_FAILED; slru_errno = errno; + TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } @@ -614,6 +630,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pageno, int slotno) (errmsg("file \"%s\" doesn't exist, reading as zeroes", path))); MemSet(shared->page_buffer[slotno], 0, BLCKSZ); + TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(true, -1, -1); return true; } @@ -622,6 +639,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pageno, int slotno) slru_errcause = SLRU_SEEK_FAILED; slru_errno = errno; close(fd); + TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } @@ -631,6 +649,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pageno, int slotno) slru_errcause = SLRU_READ_FAILED; slru_errno = errno; close(fd); + TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } @@ -638,9 +657,12 @@ SlruPhysicalReadPage(SlruCtl ctl, int pageno, int slotno) { slru_errcause = SLRU_CLOSE_FAILED; slru_errno = errno; + TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } + TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(true, -1, -1); + return true; } @@ -668,6 +690,8 @@ SlruPhysicalWritePage(SlruCtl ctl, int pageno, int slotno, SlruFlush fdata) char path[MAXPGPATH]; int fd = -1; + TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_START((uintptr_t)ctl, pageno, slotno); + /* * Honor the write-WAL-before-data rule, if appropriate, so that we do not * write out data before associated WAL records. This is the same action @@ -753,6 +777,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int pageno, int slotno, SlruFlush fdata) { slru_errcause = SLRU_OPEN_FAILED; slru_errno = errno; + TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } @@ -781,6 +806,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int pageno, int slotno, SlruFlush fdata) slru_errno = errno; if (!fdata) close(fd); + TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } @@ -794,6 +820,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int pageno, int slotno, SlruFlush fdata) slru_errno = errno; if (!fdata) close(fd); + TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } @@ -808,6 +835,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int pageno, int slotno, SlruFlush fdata) slru_errcause = SLRU_FSYNC_FAILED; slru_errno = errno; close(fd); + TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } @@ -815,10 +843,12 @@ SlruPhysicalWritePage(SlruCtl ctl, int pageno, int slotno, SlruFlush fdata) { slru_errcause = SLRU_CLOSE_FAILED; slru_errno = errno; + TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno); return false; } } + TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(true, -1, -1); return true; } diff --git a/src/backend/utils/probes.d b/src/backend/utils/probes.d index c703c2f..9f80270 100644 --- a/src/backend/utils/probes.d +++ b/src/backend/utils/probes.d @@ -15,6 +15,7 @@ * in probe definitions, as they cause compilation errors on Mac OS X 10.5. */ #define LocalTransactionId unsigned int +#define TransactionId unsigned int #define LWLockId int #define LWLockMode int #define LOCKMODE int @@ -90,4 +91,14 @@ provider postgresql { probe xlog__switch(); probe wal__buffer__write__dirty__start(); probe wal__buffer__write__dirty__done(); + + probe slru__readpage__start(unsigned long, int, bool, TransactionId); + probe slru__readpage__done(int); + probe slru__readpage__readonly(unsigned long, int, TransactionId); + probe slru__writepage__start(unsigned long, int, int); + probe slru__writepage__done(); + probe slru__readpage__physical__start(unsigned long, char *, int, int); + probe slru__readpage__physical__done(int, int, int); + probe slru__writepage__physical__start(unsigned long, int, int); + probe slru__writepage__physical__done(int, int, int); };