Patch LWlocks instrumentation

From: Pierre Frédéric Caillaud <lists(at)peufeu(dot)com>
To: "Jeff Janes" <jeff(dot)janes(at)gmail(dot)com>, "Tom Lane" <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: pgsql-hackers(at)postgresql(dot)org
Subject: Patch LWlocks instrumentation
Date: 2009-09-14 10:22:22
Message-ID: op.uz8sfkxycke6l8@soyouz
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers


A little bit of a reply to Jeff's email about WALInsertLock.

This patch instruments LWLocks, it is controlled with the following
#define's in lwlock.c :

LWLOCK_STATS
LWLOCK_TIMING_STATS

It is an upgrade of current lwlocks stats.

When active, at backend exit, it will display stats as shown below (here,
we have a parallel COPY with 4 concurrent processes into the same table,
on a 4 core machine).
If the (rather wide) sample output is mangled in your mail client, I've
attached it as a separate text file.

-------- Lock stats for PID 22403
PID Lock ShAcq ShWait ShWaitT ShHeldT
ExAcq ExWait ExWaitT ExHeldT Name
22403 7 0 0 0.00 0.00
2500002 730338 24.02 ( 53.49 %) 7.25 ( 16.14 %) WALInsert
22403 8 0 0 0.00 0.00
19501 73 3.48 ( 7.75 %) 0.40 ( 0.88 %) WALWrite

-------- Lock stats for PID 22404
PID Lock ShAcq ShWait ShWaitT ShHeldT
ExAcq ExWait ExWaitT ExHeldT Name
22404 7 0 0 0.00 0.00
2500002 724683 23.34 ( 51.59 %) 8.24 ( 18.20 %) WALInsert
22404 8 0 0 0.00 0.00
19418 90 4.37 ( 9.67 %) 0.44 ( 0.97 %) WALWrite

-------- Lock stats for PID 22402
PID Lock ShAcq ShWait ShWaitT ShHeldT
ExAcq ExWait ExWaitT ExHeldT Name
22402 7 0 0 0.00 0.00
2500002 735958 24.06 ( 52.73 %) 8.05 ( 17.63 %) WALInsert
22402 8 0 0 0.00 0.00
19154 97 4.21 ( 9.22 %) 0.39 ( 0.85 %) WALWrite

-------- Lock stats for PID 22400
PID Lock ShAcq ShWait ShWaitT ShHeldT
ExAcq ExWait ExWaitT ExHeldT Name
22400 7 0 0 0.00 0.00
2500002 736265 25.50 ( 55.59 %) 6.74 ( 14.70 %) WALInsert
22400 8 0 0 0.00 0.00
19391 66 2.95 ( 6.42 %) 0.39 ( 0.85 %) WALWrite

Here we see that PID 22400 spent :

25.50 s waiting to get exclusive on WALInsert
6.74 s while holding exclusive on WALInsert

The percentages represent the fraction of time relative to the backend
process' lifetime.
Here, I've exited the processes right after committing the transactions,
but if you use psql and want accurate %, you'll need to exit quickly after
the query to benchmark.

Here, for example, backends spend more than 50% of their time waiting on
WALInsert...

Attachment Content-Type Size
lwlock_instrumentation.patch application/octet-stream 10.8 KB
lwlock_instrumentation.sample application/octet-stream 1.8 KB

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Heikki Linnakangas 2009-09-14 11:08:14 Re: Encoding issues in console and eventlog on win32
Previous Message Pavel Stehule 2009-09-14 10:09:48 Re: Issues for named/mixed function notation patch