measuring spinning

From: Robert Haas <robertmhaas(at)gmail(dot)com>
To: pgsql-hackers(at)postgresql(dot)org
Subject: measuring spinning
Date: 2012-01-12 01:48:03
Message-ID: CA+TgmobK=fVj2TWci7+YdTbnwvGtLiHAoemBJjDJ1qnp8TDTww@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

I've had cause, a few times this development cycle, to want to measure
the amount of spinning on each lwlock in the system. To that end,
I've found the attached patch useful. Note that if you don't define
LWLOCK_STATS, this changes nothing except that the return value from
s_lock becomes int rather than void. If you do define LWLOCK_STATS,
then LWLockAcquire() counts the number of pg_usleep() calls that are
required to acquire each LWLock, in addition to the other statistics.
Since this has come up for me a few times now, I'd like to proposing
including it in core.

Just to whet your appetite, here are the top spinners on a 32-client
SELECT-only test on a 32-core Itanium server. All the locks not shown
below have two orders of magnitude less of a problem than these do.

lwlock 48: shacq 6042357 exacq 34590 blk 53 spin 1288
lwlock 42: shacq 5014729 exacq 34942 blk 58 spin 1321
lwlock 43: shacq 5448771 exacq 34725 blk 44 spin 1608
lwlock 44: shacq 6420992 exacq 34980 blk 67 spin 1713
lwlock 35: shacq 6353111 exacq 34256 blk 59 spin 1784
lwlock 38: shacq 6052801 exacq 34913 blk 70 spin 1801
lwlock 46: shacq 6401413 exacq 34698 blk 58 spin 1879
lwlock 36: shacq 6051887 exacq 35309 blk 73 spin 1915
lwlock 45: shacq 6812817 exacq 35170 blk 59 spin 1924
lwlock 33: shacq 6793666 exacq 35009 blk 59 spin 1955
lwlock 34: shacq 6395994 exacq 34941 blk 58 spin 2019
lwlock 40: shacq 6388136 exacq 34579 blk 51 spin 2054
lwlock 37: shacq 7250574 exacq 35242 blk 73 spin 2409
lwlock 39: shacq 7109729 exacq 34892 blk 65 spin 2632
lwlock 47: shacq 8243963 exacq 35256 blk 88 spin 3018
lwlock 328936: shacq 33992167 exacq 0 blk 0 spin 59816
lwlock 4: shacq 33994583 exacq 168 blk 40 spin 74018
lwlock 41: shacq 40098590 exacq 35001 blk 440 spin 81324
grant total: shacq 361775238 exacq 172965995 blk 2315 spin 245342

This is a 5-minute test run. If I had to take a shot in the dark, the
buffer mapping lock in the #1 spot is the one protecting the root page
of pgbench_acocunts_pkey, and the high numbered lock in position #3 is
the content lock on the buffer itself.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Thom Brown 2012-01-12 01:54:44 Re: measuring spinning
Previous Message Aidan Van Dyk 2012-01-12 01:38:48 Re: [WIP] Double-write with Fast Checksums