Percona Server with XtraDB

Adaptive search scalability

Reported by Percona on 2009-02-19
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Percona Server
Medium
Unassigned
5.1
Medium
Unassigned
5.5
Medium
Unassigned
Percona-XtraDB
Invalid
Medium
Unassigned

Bug Description

During some workloads I see a lot of output
--Thread 1164450128 has waited at btr0sea.c line 1383 for 0.00 seconds the semaphore:
X-lock on RW-latch at 0x2aaaac50e0b8 created in file btr0sea.c line 139
a writer (thread id 1164450128) has reserved it in mode wait exclusive
 number of readers 1, waiters flag 1
 Last time read locked in file btr0sea.c line 746
 Last time write locked in file btr0sea.c line 1383
 though the waits are very small though -- 0.00

What we can do there ?

Changed in percona-xtradb:
importance: Undecided → Medium
Changed in percona-patches:
importance: Undecided → Medium

On Thu, Apr 9, 2009 at 11:55 AM, Evgeniy Stepchenko
<email address hidden> wrote:
> ** Changed in: percona-xtradb
>   Importance: Undecided => Medium
>
> ** Changed in: percona-patches
>   Importance: Undecided => Medium
>
> --
> Adaptive search scalability
> https://bugs.launchpad.net/bugs/331659
> You received this bug notification because you are a member of Percona
> developers, which is the registrant for Percona patches.
>
> Status in Patches for MySQL by Percona: New
> Status in Percona XtraDB Storage Engine for MySQL: New
>
> Bug description:
> During some workloads I see a lot of output
> --Thread 1164450128 has waited at btr0sea.c line 1383 for 0.00 seconds the semaphore:
> X-lock on RW-latch at 0x2aaaac50e0b8 created in file btr0sea.c line 139
> a writer (thread id 1164450128) has reserved it in mode  wait exclusive
>  number of readers 1, waiters flag 1
>  Last time read locked in file btr0sea.c line 746
>  Last time write locked in file btr0sea.c line 1383
>  though the waits are very small though -- 0.00
>
> What we can do there ?

Does SHOW MUTEX STATUS report a lot of contention for it?

>
> _______________________________________________
> Mailing list: https://launchpad.net/~percona-discussion
> Post to     : <email address hidden>
> Unsubscribe : https://launchpad.net/~percona-discussion
> More help   : https://help.launchpad.net/ListHelp
>

--
Mark Callaghan
<email address hidden>

MARK ,

This is rw_lock, so no output in SHOW MUTEX STATUS.

But in SHOW INNODB STATUS it fills several screens in output.

MARK CALLAGHAN wrote:
> On Thu, Apr 9, 2009 at 11:55 AM, Evgeniy Stepchenko
> <email address hidden> wrote:
>> ** Changed in: percona-xtradb
>> Importance: Undecided => Medium
>>
>> ** Changed in: percona-patches
>> Importance: Undecided => Medium
>>
>> --
>> Adaptive search scalability
>> https://bugs.launchpad.net/bugs/331659
>> You received this bug notification because you are a member of Percona
>> developers, which is the registrant for Percona patches.
>>
>> Status in Patches for MySQL by Percona: New
>> Status in Percona XtraDB Storage Engine for MySQL: New
>>
>> Bug description:
>> During some workloads I see a lot of output
>> --Thread 1164450128 has waited at btr0sea.c line 1383 for 0.00 seconds the semaphore:
>> X-lock on RW-latch at 0x2aaaac50e0b8 created in file btr0sea.c line 139
>> a writer (thread id 1164450128) has reserved it in mode wait exclusive
>> number of readers 1, waiters flag 1
>> Last time read locked in file btr0sea.c line 746
>> Last time write locked in file btr0sea.c line 1383
>> though the waits are very small though -- 0.00
>>
>> What we can do there ?
>
> Does SHOW MUTEX STATUS report a lot of contention for it?
>
>> _______________________________________________
>> Mailing list: https://launchpad.net/~percona-discussion
>> Post to : <email address hidden>
>> Unsubscribe : https://launchpad.net/~percona-discussion
>> More help : https://help.launchpad.net/ListHelp
>>
>
>
>

--
Vadim Tkachenko, CTO
Percona Inc.
ICQ: 369-510-335, Skype: vadimtk153, Phone +1-888-401-3403
MySQL Performance Blog - http://www.mysqlperformanceblog.com
MySQL Consulting http://www.percona.com/

  Attend the 2009 Percona Performance Conference
  April 22-23 - http://conferences.percona.com/

On Thu, Apr 9, 2009 at 12:26 PM, Vadim Tkachenko <email address hidden> wrote:
> MARK ,
>
>
> This is rw_lock, so no output in SHOW MUTEX STATUS.
>
> But in SHOW INNODB STATUS it fills several screens in output.

I forgot about that. We fixed innodb_mutex_show_status in our branch
to display contention for both. It is an easy change to make. Another
good change is to not return data for mutexes and rw-locks with no
contention.

>
>
>
> MARK CALLAGHAN wrote:
>> On Thu, Apr 9, 2009 at 11:55 AM, Evgeniy Stepchenko
>> <email address hidden> wrote:
>>> ** Changed in: percona-xtradb
>>>   Importance: Undecided => Medium
>>>
>>> ** Changed in: percona-patches
>>>   Importance: Undecided => Medium
>>>
>>> --
>>> Adaptive search scalability
>>> https://bugs.launchpad.net/bugs/331659
>>> You received this bug notification because you are a member of Percona
>>> developers, which is the registrant for Percona patches.
>>>
>>> Status in Patches for MySQL by Percona: New
>>> Status in Percona XtraDB Storage Engine for MySQL: New
>>>
>>> Bug description:
>>> During some workloads I see a lot of output
>>> --Thread 1164450128 has waited at btr0sea.c line 1383 for 0.00 seconds the semaphore:
>>> X-lock on RW-latch at 0x2aaaac50e0b8 created in file btr0sea.c line 139
>>> a writer (thread id 1164450128) has reserved it in mode  wait exclusive
>>>  number of readers 1, waiters flag 1
>>>  Last time read locked in file btr0sea.c line 746
>>>  Last time write locked in file btr0sea.c line 1383
>>>  though the waits are very small though -- 0.00
>>>
>>> What we can do there ?
>>
>> Does SHOW MUTEX STATUS report a lot of contention for it?
>>
>>> _______________________________________________
>>> Mailing list: https://launchpad.net/~percona-discussion
>>> Post to     : <email address hidden>
>>> Unsubscribe : https://launchpad.net/~percona-discussion
>>> More help   : https://help.launchpad.net/ListHelp
>>>
>>
>>
>>
>
>
> --
> Vadim Tkachenko, CTO
> Percona Inc.
> ICQ: 369-510-335, Skype: vadimtk153, Phone +1-888-401-3403
> MySQL Performance Blog - http://www.mysqlperformanceblog.com
> MySQL Consulting http://www.percona.com/
>
>  Attend the 2009 Percona Performance Conference
>  April 22-23 - http://conferences.percona.com/
>

--
Mark Callaghan
<email address hidden>

Changed in percona-xtradb:
status: New → Invalid
affects: percona-patches → percona-server
Changed in percona-server:
status: New → Triaged
Trey Raymond (wraymond) wrote :
Download full text (4.1 KiB)

Seeing something like this in a 5.5.21 install.

Example, a bunch of queries waiting for this to be released caused a long-semaphore-wait crash:

InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Error: semaphore wait has lasted > 600 seconds
InnoDB: We intentionally crash the server, because it appears to be hung.
120609 23:38:53 InnoDB: Assertion failure in thread 139683626649344 in file srv0srv.c line 2839

---TRANSACTION 42D176FD, ACTIVE 948 sec
mysql tables in use 5, locked 0
, holds adaptive hash latch
MySQL thread id 43, OS thread handle 0x7f0a9d51f700, query id 4619343 10.0.113.13 fppuser Copying to tmp table
SELECT
    SQL_NO_CACHE
    t1.ApplicationUserName,
...

This query returns <20 records, only uses primary keys. Seems to acquire the latch, get the rows immediately I'm sure, and then hang in "Copying to tmp table" for 15 mins as seen here without releasing it.

Full procedure call:

BEGIN
  SELECT
    SQL_NO_CACHE
    t1.ApplicationUserName,
    t1.ApplicationUserId,
    Font,
    FontColour,
    FontSize,
    IsScroll,
    IsSound,
    t2.ResetLockedOutDateTime,
    DateOfBirth,
    Sex,
    COALESCE(t3.MinSavedFileName,t3.MedSavedFileName, t3.MaxSavedFileName, ChatroomUserDefaultImage(t1.Sex)) AS Avatar,
    CAST(COALESCE(IsBlocked, 0) AS UNSIGNED) AS IsBlocked,
    CAST(COALESCE(t2.IsVisible, 1) AS UNSIGNED) AS IsVisible,
    CAST(IF(t4.RoleName = 'Administrator', 1, 0) AS UNSIGNED) AS IsAdministrator,
    t5.ChatroomId,
    t5.EnteredRoomDateTime,
    t5.LastPingedDateTime,
    t5.LastPostedDateTime,
    t5.LastTypedDateTime,
    IF(DATE_ADD(COALESCE(t5.LastTypedDateTime, '1900-01-01'), INTERVAL 2 SECOND) > NOW(), true, false) AS IsTyping,
    IF(DATE_ADD(COALESCE(t5.LastTypedDateTime, '1900-01-01'), INTERVAL 300 SECOND) < NOW(), true, false) AS IsOffline
  FROM
    ApplicationUser t1
  LEFT JOIN
    UserChatroomSettings t2
  ON
    t1.ApplicationUserId = t2.ApplicationUserId
  LEFT JOIN
    Photograph t3
  ON
    t1.DefaultPhotographId = t3.PhotographId
  INNER JOIN
    Role t4
  ON
    t1.DefaultRoleId = t4.RoleId
  INNER JOIN
    ChatroomOnlineUser t5
  ON
    t1.ApplicationUserId = t5.ApplicationUserId
  WHERE
    t5.ChatroomId = IPChatroomId
  ORDER BY
    EnteredRoomDateTime,
    t1.ApplicationUserName ASC;
END

explain:
+----+-------------+-------+--------+---------------+---------+---------+-------------------------------+------+---------------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+-------+--------+---------------+---------+---------+-------------------------------+------+---------------------------------+
| 1 | SIMPLE | t5 | ref | PRIMARY | PRIMARY | 4 | const | 19 | Using temporary; Using filesort |
| 1 | SIMPLE | t1 | eq_ref | PRIMARY | PRIMARY | 4 | dating.t5.ApplicationUserId | 1 | |
| 1 | SIMPLE | t4 | eq_ref | PRIMARY | PRIMARY | 4 | dating.t1.DefaultRoleId | 1 | Using where ...

Read more...

Jervin R (revin) wrote :

This has occurred with a customer on 5.5.16, if it crashes again, hopefully a core file is generated. Full error log on the tagged issue.

----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 153359, signal count 370811
--Thread 1264470336 has waited at btr0sea.c line 1203 for 942.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x2ab73bee6318 'btr_search_latch_part[i]'
a writer (thread id 1264470336) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
Last time read locked in file btr0sea.c line 1104
Last time write locked in file /home/buildbot/slaves/percona-server-51-12/CentOS-5-x86-RPM_CentOS_5_x86_64/work/BUILD/Percona-Server-5.5.16-rel22.0/Percona-Server-5.5.16-rel22.0/storage/innobase/btr/btr0sea.c line 664

tags: added: i27028
Jervin R (revin) wrote :

I think this is somewhat related and a workaround could be set innodb_adaptive_hash_index_partitions to 1. https://bugs.launchpad.net/percona-server/+bug/791030

I believe the issue here is more that this is a bug than anything with scalability. Specifically, the bug lp:791030 which may be regressing again and/or not fixed fully, (more details posted there) and the reason I believe both should be merged.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers