Adaptive search scalability

[Percona]

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 ?

[Mark Callaghan (mdcallag)]

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>

[Vadim Tkachenko (vadim-tk)]

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 [phone]
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 (mdcallag)]

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 [phone]
> 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>

[Trey Raymond (wraymond)]

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 ...

[Jervin R (revin)]

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

[Jervin R (revin)]

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

[Raghavendra D Prabhu (raghavendra-prabhu)]

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.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1135