Re: spinlocks on HP-UX

On Tue, Aug 30, 2011 at 7:21 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
> Robert Haas <robertmhaas(at)gmail(dot)com> writes:
>> On Tue, Aug 30, 2011 at 6:33 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
>>> I ran it up to "pgbench -c 200 -j 200 -S -T 300 bench" and still see
>>> vmstat numbers around 50% user time, 12% system time, 38% idle.
>>> So no lseek problem here, boss. Kernel calls itself 2.6.32-192.el6.x86_64.
>
>> Eh, wait a minute.  38% idle time?  Did you use a scale factor that
>> doesn't fit in shared_buffers?
>
> Nope: -s 100, 8GB shared_buffers, same as all the other tests.
>
> Typical strace of one backend looks like
>
> recvfrom(9, "Q\0\0\0?SELECT abalance FROM pgbenc"..., 8192, 0, NULL, NULL) = 64
> lseek(10, 0, SEEK_END)                  = 269213696
> lseek(11, 0, SEEK_END)                  = 224641024
> sendto(9, "T\0\0\0!\0\1abalance\0\0\0\241\267\0\3\0\0\0\27\0\4\377\377\377\377"..., 66, 0, NULL, 0) = 66
> recvfrom(9, "Q\0\0\0?SELECT abalance FROM pgbenc"..., 8192, 0, NULL, NULL) = 64
> lseek(10, 0, SEEK_END)                  = 269213696
> lseek(11, 0, SEEK_END)                  = 224641024
> sendto(9, "T\0\0\0!\0\1abalance\0\0\0\241\267\0\3\0\0\0\27\0\4\377\377\377\377"..., 66, 0, NULL, 0) = 66
> recvfrom(9, "Q\0\0\0?SELECT abalance FROM pgbenc"..., 8192, 0, NULL, NULL) = 64
> select(0, NULL, NULL, NULL, {0, 1000})  = 0 (Timeout)
> lseek(10, 0, SEEK_END)                  = 269213696
> lseek(11, 0, SEEK_END)                  = 224641024
> select(0, NULL, NULL, NULL, {0, 1000})  = 0 (Timeout)
> select(0, NULL, NULL, NULL, {0, 1000})  = 0 (Timeout)
> sendto(9, "T\0\0\0!\0\1abalance\0\0\0\241\267\0\3\0\0\0\27\0\4\377\377\377\377"..., 66, 0, NULL, 0) = 66
> recvfrom(9, "Q\0\0\0?SELECT abalance FROM pgbenc"..., 8192, 0, NULL, NULL) = 64
> lseek(10, 0, SEEK_END)                  = 269213696
> lseek(11, 0, SEEK_END)                  = 224641024
> select(0, NULL, NULL, NULL, {0, 1000})  = 0 (Timeout)
> sendto(9, "T\0\0\0!\0\1abalance\0\0\0\241\267\0\3\0\0\0\27\0\4\377\377\377\377"..., 66, 0, NULL, 0) = 66
>
> No I/O anywhere.  I'm thinking the reported idle time must correspond to
> spinlock delays that are long enough to reach the select() calls in
> s_lock.  If so, 38% is depressingly high, but it's not out of line with
> what we've seen in the past in tests designed to provoke spinlock
> contention.
>
> (BTW, this is with the unlocked test added to TAS_SPIN.)

Well, that is mighty interesting. That strace looks familiar, but I
have never seen a case where the idle time was more than a few
percentage points on this test (well, assuming you're using 9.2
sources, anyway).

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