MySQL Bugs: #42649: THR_LOCK_charset global mutex abused by InnoDB

Bug #42649	THR_LOCK_charset global mutex abused by InnoDB
Submitted:	6 Feb 2009 14:18	Modified:	15 Aug 2009 1:37
Reporter:	Domas Mituzas	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Charsets	Severity:	S5 (Performance)
Version:	5.0,5.1	OS:	Any
Assigned to:	Alexander Barkov	CPU Architecture:	Any

Description:
if table data is not in default server character set or latin1, InnoDB calls get_charset() for each varchar compare - what may end up contended on THR_LOCK_charset.

In my simple tests this mutex was acquired 8 times per inserted row. 

How to repeat:
INSERT INTO innodbtable;

Suggested fix:
either cache returned charsets, or use more static charset declarations, or initialize them all at server start, or ..

Hit count of get_charset and THR_LOCK_charset

Attachment: hit_count_on_vista_64x.png (image/png, text), 204.58 KiB.

I just to illustrate what Domas is reporting I did:

- Run on VS2005 a 5.1.32 X64 server on Vista.
- Create an InnoDB table  (see below) and inserted some rows
- 2 breakpoint at:

} else if (charset_number == my_charset_latin1.number) {
			charset = &my_charset_latin1;
		} else {
	>>>>>>>		charset = get_charset(charset_number, MYF(MY_WME));

and 

static CHARSET_INFO *get_internal_charset(uint cs_number, myf flags)
{
  char  buf[FN_REFLEN];
  CHARSET_INFO *cs;
  /*
    To make things thread safe we are not allowing other threads to interfere
    while we may changing the cs_info_table
  */
  pthread_mutex_lock(&THR_LOCK_charset); <<<<<<<<<<

sets the above breakpoint to be skipped when the hit count is < 1000.

- Done exactly the number of inserts below:

c:\dbs>c:\dbs\5.1\bin\mysql -uroot --port=3510 --prompt="mysql 5.1 >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.1.32-Win x64 bzr revno 2768-debug-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql 5.1 >use test
Database changed
mysql 5.1 >show create table tb;
+-------+--------------------------------------------------------------------------------------------------------------------+
| Table | Create Table                                                                                                       |
+-------+--------------------------------------------------------------------------------------------------------------------+
| tb    | CREATE TABLE `tb` (
  `col1` varchar(200) DEFAULT NULL,
  KEY `col1` (`col1`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |
+-------+--------------------------------------------------------------------------------------------------------------------+
1 row in set (0.03 sec)

mysql 5.1 >select count(*) from tb;
+----------+
| count(*) |
+----------+
|       19 |
+----------+
1 row in set (0.00 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.10 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.10 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.09 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.08 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.08 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.08 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.08 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.08 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.07 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.08 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.21 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.14 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.14 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.10 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.09 sec)

mysql 5.1 >insert into tb values (repeat('a',200));
Query OK, 1 row affected (0.08 sec)

mysql 5.1 >insert into tb values (repeat('b',200));
Query OK, 1 row affected (0.09 sec)

mysql 5.1 >insert into tb values (repeat('b',200));
Query OK, 1 row affected (0.09 sec)

mysql 5.1 >insert into tb values (repeat('b',200));
Query OK, 1 row affected (0.09 sec)

mysql 5.1 >insert into tb values (repeat('b',200));
Query OK, 1 row affected (2 min 20.95 sec)

mysql 5.1 >insert into tb values (repeat('b',200));
Query OK, 1 row affected (0.09 sec)

mysql 5.1 >

See picture attached for the count hit: 324 and 307

Thanks for noticing this, Domas.
I'm inclined to wait on the triage values before assigning it.
Is there a test case for this to see how much we could gain by fixing this,
something like inserting into a table from multiple connections, once for a latin1 table, another one into a table where we like to call get_charset(),
or could you build one and get some numbers as part of the triage.
Also, would you consider this as a serverside bug with a serverside solution?
Caching that charset in the code for each engine just doesn't seem right.
It's also not our fault that get_charset() acquires the mutex. I'd say
if get_charset() has a reason to do this it's quite possible we have a reason
to call it all the time. On the other hand if we can cache it, so could get_charset() or mysqld otherwise. Why can't we have this value in one of the data structures that come with the query?

Analysis using the performance schema

Attachment: Analysis-with-performance-schema.txt (text/plain), 16.33 KiB.

Please see the attachments, for an analysis prepared by Peter,
using the performance schema.

Thanks Peter.

Michael, this isn't major lock holder in write operations - in my test, lock was held around 16% of time, whereas log_sys mutex was held way more - so, it is secondary performance problem, but still a problem. 

It has been missed mostly because performance testing is done without character sets in mind :)

Domas, is it intentional that you keep the bug assigned to yourself?
If it's not, I could assign it to someone in InnoDB, just set status to Verified
and/or assign the bug to me.
I still see this more of a server issue even though something could be 
done on innodb side as well.

by setting to open you probably reassigned it back to me automatically, it definitely wasn't me setting assigner to me, why would I ever make such a mistake myself :)

I think it was the * - Need Feedback - * process that did the assignment,
anyway let's assign it to Marko to have a look.

Sorry Domas, I believe that this is a design problem in MySQL. It should really load the collations during initialization, before starting any storage engine. Then get_charset() could be a macro that simply dereferences all_charsets[].

InnoDB stores data and indexes in B-trees. The B-trees are ordered by the key of the relevant index (the columns of the primary key or those of a secondary key). If a key column is a string type, InnoDB has to ask MySQL to compare it. As far as I understand and remember, the situation has been like this since MySQL 4.1. 

Note that InnoDB implements latin1_swedish_ci as a special case. ha_innodb.cc also dereferences all_charsets[] in innobase_get_cset_width(), to cache mbminlen and mbmaxlen. I'm not sure if that is safe. (1) Can the collation be reloaded? I hope not, because a change in a collation usually leads to corruption of all affected InnoDB indexes. (2) Can the all_charsets array be relocated (e.g., reallocated to dynamically load more charsets)? If yes, the address of all_charsets could change, and it shouldn't be accessed without appropriate mutex protection.

Again, I think that the problem should be fixed in get_charset() in MySQL code, not in InnoDB. InnoDB code doesn't access THR_LOCK_charset directly; get_charset() does. (Why) can't you observe the THR_LOCK_charset contention with other storage engines?

I've spent some time looking at the following code:

static CHARSET_INFO *get_internal_charset(uint cs_number, myf flags)
{
  char  buf[FN_REFLEN];
  CHARSET_INFO *cs;
  /*
    To make things thread safe we are not allowing other threads to interfere
    while we may changing the cs_info_table
  */
  pthread_mutex_lock(&THR_LOCK_charset);
  if ((cs= all_charsets[cs_number]))
  {
    if (!(cs->state & MY_CS_COMPILED) && !(cs->state & MY_CS_LOADED))
    {
      strxmov(get_charsets_dir(buf), cs->csname, ".xml", NullS);
      my_read_charset_file(buf,flags);
    }
    cs= (cs->state & MY_CS_AVAILABLE) ? cs : NULL;
  }
  if (cs && !(cs->state & MY_CS_READY))
  {
    if ((cs->cset->init && cs->cset->init(cs, cs_alloc)) ||
        (cs->coll->init && cs->coll->init(cs, cs_alloc)))
      cs= NULL;
    else
      cs->state|= MY_CS_READY;
  }
  pthread_mutex_unlock(&THR_LOCK_charset);
  return cs;
}

discussed it with Marko, too. If the mutex absolutely has to be acquired
in such form that we can't cache anything since the code above codesets being able to be reloaded, get uncompiled somehow, and whatever we cache could get sour. On the other hand if what gets compiled,stays compiled,
the code above could be rewritten from its current style of

get mutex 
check and do something if necessary

to 

check
  get mutex if you don't like what you see
  check again, maybe something has done the work already
    do compile now
  release

even recompiling can be supported with the above scheme by wrapping
it in another level of similar code, if the thread that wants to do reload
is willing to wait a second or so.

No need to be sorry :) The only engine affected by this seems to be InnoDB - others don't go via this interface, it seems (though I didn't test too much), so I have to get everyone a proper understanding, that this is design problem at one of sides, or both - and of course, resolved in the end. 

I'm hereby putting Bar as Lead, removing myself from assignee, and setting back to verified, until next round :)

I guess reassigning it to InnoDB is a mistake.
Please see the arguments above why this is not InnoDB issue.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/71497

2858 Alexander Barkov	2009-04-07
      Bug#42649 THR_LOCK_charset global mutex abused by InnoDB
      The patch was originally proposed by Mikael and reviewed by Bar.

Pushed into 5.1.35 (revid:davi.arnaut@sun.com-20090505190206-9xmh7dlc6kom8exp) (version source revid:davi.arnaut@sun.com-20090505190206-9xmh7dlc6kom8exp) (merge vers: 5.1.35) (pib:6)

Pushed into 6.0.12-alpha (revid:svoj@sun.com-20090506125450-yokcmvqf2g7jhujq) (version source revid:bar@mysql.com-20090407070353-dljrdyt0cyn4cqak) (merge vers: 6.0.11-alpha) (pib:6)

Noted in 5.1.35, 6.0.12 changelogs.

InnoDB had excessive contention for a character set mutex.

Pushed into 5.1.35-ndb-6.3.26 (revid:jonas@mysql.com-20090615074202-0r5r2jmi83tww6sf) (version source revid:jonas@mysql.com-20090615070837-9pccutgc7repvb4d) (merge vers: 5.1.35-ndb-6.3.26) (pib:6)

Pushed into 5.1.35-ndb-7.0.7 (revid:jonas@mysql.com-20090615074335-9hcltksp5cu5fucn) (version source revid:jonas@mysql.com-20090615072714-rmfkvrbbipd9r32c) (merge vers: 5.1.35-ndb-7.0.7) (pib:6)

Pushed into 5.1.35-ndb-6.2.19 (revid:jonas@mysql.com-20090615061520-sq7ds4yw299ggugm) (version source revid:jonas@mysql.com-20090615054654-ebgpz7elwu1xj36j) (merge vers: 5.1.35-ndb-6.2.19) (pib:6)

Docs, please update description from

"InnoDB had excessive contention for a character set mutex."

to:

"If the character set for a column being compared was neither the default server character set nor latin1 InnoDB was slower than necessary due to excessive contention for a character set mutex."

Please also add the performance tag for this fix.

The purpose of the changed description is to give some idea of when this may help performance.

As a workaround for earlier versions, set the default server character set to the character set other than latin1 that is most often used in indexed columns.

Changelog entry revised as requested.