My Thoughts on MySQL

Category Archives: MySQL 5.6

This post was originally published on the MySQL Support Team Blog at https://blogs.oracle.com/mysqlsupport/entry/innodb_locks_analysis_why_is on 14 April 2017.

Consider the scenario that you execute a query. You expect it to be fast – typically subsecond – but now it take not return until after 50 seconds (innodb_lock_wait_timeout seconds) and then it returns with an error:

Lock wait timeout error

1

2

mysql>UPDATEworld.CitySETPopulation=Population+999WHEREID=130;

ERROR1205(HY000):Lockwaittimeoutexceeded;tryrestartingtransaction

You continue to investigate the issue using the sys.innodb_lock_waits view or the underlying Information Schema tables (INNODB_TRX, INNODB_LOCKS and INNODB_LOCK_WAITS).

Note: The above Information Schema tables with lock and lock waits information have been moved to the Performance Schema in 8.0 as the data_locks and data_lock_waits tables. The sys schema view however works the same.

However, when you query the locks information, the blocking query is returned as NULL. What does that mean and how to proceed from that to get information about the blocking transaction?

Setting Up an Example

Before proceeding, lets set up an example which will be investigated later in the blog. The example can be set up as (do not disconnect Connection 1 when the queries have been executed):

Connection 1:

Test case - Connection 1

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

Connection1>START TRANSACTION;

QueryOK,0rowsaffected(0.00sec)

Connection1>UPDATEworld.CitySETPopulation=Population+1WHEREID=130;

QueryOK,1rowaffected(0.00sec)

Rowsmatched:1Changed:1Warnings:0

Connection1>UPDATEworld.CitySETPopulation=Population+1WHEREID=131;

QueryOK,1rowaffected(0.00sec)

Rowsmatched:1Changed:1Warnings:0

Connection1>UPDATEworld.CitySETPopulation=Population+1WHEREID=132;

QueryOK,1rowaffected(0.00sec)

Rowsmatched:1Changed:1Warnings:0

Connection1>UPDATEworld.CitySETPopulation=Population+1WHEREID=133;

QueryOK,1rowaffected(0.00sec)

Rowsmatched:1Changed:1Warnings:0

Connection 2 (blocks for innodb_lock_wait_timeout seconds):

Test case - Connection 2

1

Connection2>UPDATEworld.CitySETPopulation=Population+999WHEREID=130;

The following output while Connection 2 is still blocking from sys.innodb_lock_waits shows that the blocking query is NULL (slightly reformatted):

sys.innodb_lock_waits

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29

30

31

32

33

34

35

36

37

38

39

40

41

42

43

44

45

46

47

48

Connection3>SELECT*FROMsys.innodb_lock_waits\G

***************************1.row***************************

wait_started:2017-04-1509:54:53

wait_age:00:00:03

wait_age_secs:3

locked_table:`world`.`City`

locked_index:PRIMARY

locked_type:RECORD

waiting_trx_id:2827

waiting_trx_started:2017-04-1509:54:53

waiting_trx_age:00:00:03

waiting_trx_rows_locked:1

waiting_trx_rows_modified:0

waiting_pid:5

waiting_query:UPDATEworld.CitySETPopulati...opulation+999

WHEREID=130

waiting_lock_id:2827:24:6:41

waiting_lock_mode:X

blocking_trx_id:2826

blocking_pid:3

blocking_query:NULL

blocking_lock_id:2826:24:6:41

blocking_lock_mode:X

blocking_trx_started:2017-04-1509:54:46

blocking_trx_age:00:00:10

blocking_trx_rows_locked:4

blocking_trx_rows_modified:4

sql_kill_blocking_query:KILL QUERY3

sql_kill_blocking_connection:KILL3

1rowinset,3warnings(0.00sec)

Connection3>SHOWWARNINGS\G

***************************1.row***************************

Level:Warning

Code:1681

Message:'INFORMATION_SCHEMA.INNODB_LOCK_WAITS'isdeprecated

andwillberemovedinafuturerelease.

***************************2.row***************************

Level:Warning

Code:1681

Message:'INFORMATION_SCHEMA.INNODB_LOCKS'isdeprecatedand

willberemovedinafuturerelease.

***************************3.row***************************

Level:Warning

Code:1681

Message:'INFORMATION_SCHEMA.INNODB_LOCKS'isdeprecatedand

willberemovedinafuturerelease.

3rowsinset(0.00sec)

The warnings will only occur in the 5.7.14 and later as the InnoDB lock tables being moved to the Performance Schema in MySQL 8.0. It is recommended to use the sys.innodb_lock_waits view as that is updated accordingly in MySQL 8.0.

Investigating Idle Transactions

To investigate idle transactions, you need to use the Performance Schema to get this information. First determine the Performance Schema thread id for the blocking transaction. For this you need the blocking_pid, in the above example:

In this case this does not explain why the lock is held as the last query update a different row then where the lock issue occurs. However if the events_statements_history consumer is enabled (it is by default in MySQL 5.7 and later), the The events_statements_history Table table will include the last 10 statements (by default) executed for the connection:

So now the history of the blocking transaction can be seen and it is possible to determine why the locking issue occur.

Note: The history also includes some queries executed before the transaction started. These are not related to the locking issue.

If transaction monitoring is also enabled (only available in MySQL 5.7 and later), it is possible to get more information about the transaction and automatically limit the query of the history to the current transaction. Transaction monitoring is not enabled by default. To enable it, use:

Enabling transaction monitoring

1

2

3

4

5

6

7

8

9

10

11

mysql>UPDATEperformance_schema.setup_consumers

SETENABLED='YES'

WHERENAME='events_transactions_current';

QueryOK,1rowaffected(0.00sec)

Rowsmatched:1Changed:1Warnings:0

mysql>UPDATEperformance_schema.setup_instruments

SETENABLED='YES'

WHERENAME='transaction';

QueryOK,1rowaffected(0.00sec)

Rowsmatched:1Changed:1Warnings:0

Note: This must be done before either of the transactions is started. Only transaction started after the transaction monitoring is enabled will be instrumented.

If the above was enabled before the blocking transaction started, you can get more details about the blocking transaction as:

While I prepared for my Hands-On Lab about the Performance Schema at MySQL Connect last year, one of the things that occurred to me was how difficult it was quickly getting an overview of which consumers, instruments, actors, etc. are actually enabled. For the consumers things are made more complicated as the effective setting also depends on parents in the hierarchy. So my thought was: “How difficult can it be to write a stored procedure that outputs a tree of the hierarchies.” Well, simple enough in principle, but trying to be general ended up making it into a lengthy project and as it was a hobby project, it often ended up being put aside for more urgent tasks.

However here around eight months later, it is starting to shape up. While there definitely still is work to be done, e.g. creating the full tree and outputting it in text mode (more on modes later) takes around one minute on my test system – granted I am using a standard laptop and MySQL is running in a VM, so it is nothing sophisticated.

Note: This far the routines have only been tested in Linux on MySQL 5.6.11. Particularly line endings may give problems on Windows and Mac.

Description of the ps_tools Routines

The current status are two views, four stored procedure, and four functions – not including several functions and procedures that does all the hard work:

Views:

setup_consumers – Displays whether each consumer is enabled and whether the consumer actually will be collected based on the hierarchy rules described in Pre-Filtering by Consumer in the Reference Manual.

accounts_enabled – Displays whether each account defined in the mysql.user table has instrumentation enabled based on the rows in performance_schema.setup_actors.

Procedures:

setup_tree_consumers(format, color) – Create a tree based on setup_consumers displaying whether each consumer is effectively enabled. The arguments are:

format is the output format and can be either (see also below).:

Text: Left-Right

Text: Top-Bottom

Dot: Left-Right

Dot: Top-Bottom

color is whether to add bash color escapes sequences around the consumer names when used a Text format (ignored for Dot outputs).

setup_tree_instruments(format, color, only_enabled, regex_filter) – Create a tree based on setup_instruments displaying whether each instrument is enabled. The tree is creating by splitting the instrument names at each /. The arguments are:

format is the output format and can be either:

Text: Left-Right

Dot: Left-Right

Dot: Top-Bottom

color is whether to add bash color escapes sequences around the instrument names when used a Text format (ignored for Dot outputs).

type – whether to base the tree on the ENABLED or TIMED column of setup_instruments.

only_enabled – if TRUE only the enabled instruments are included.

regex_filter – if set to a non-empty string only instruments that match the regex will be included.

setup_tree_actors_by_host(format, color) – Create a tree of each account defined in mysql.user and whether they are enabled; grouped by host. The arguments are:

format is the output format and can be either:

Text: Left-Right

Dot: Left-Right

Dot: Top-Bottom

color is whether to add bash color escape sequences around the names when used a Text format (ignored for Dot outputs).

setup_tree_actors_by_user – Create a tree of each account defined in mysql.user and whether they are enabled; grouped by username. The arguments are:

format is the output format and can be either:

Text: Left-Right

Dot: Left-Right

Dot: Top-Bottom

color is whether to add bash color escape sequences around the names when used a Text format (ignored for Dot outputs).

Functions:

is_consumer_enabled(consumer_name) – Returns whether a given consumer is effectively enabled.

is_account_enabled(host, user) – Returns whether a given account (host, user) is enabled according to setup_actors.

substr_count(haystack, needle, offset, length) – The number of times a given substring occurs in a string. A port of the PHP function of the same name.

The two functions substr_count() and substr_by_delim() was also described in an earlier blog.

The formats for the four stored procedures consists of two parts: whether it is Text or Dot and the direction. Text is a tree that can be viewed directly either in the mysql command line client (coloured output not supported) or the shell (colours supported for bash). Dot will output a DOT graph file in the same way as dump_thread_stack() in ps_helper. The direction is as defined in the DOT language, so e.g. Left-Right will have the first level furthest to the left, then add each new level to the right of the parent level.

Examples

As the source code – including comments – is more than 1600 lines, I will not discuss it here, but rather go through some examples.

setup_tree_consumers

Using the coloured output:

or the same using a non-coloured output:

setup_tree_instruments

Here a small part of the tree is selected using a regex.

setup_tree_actors_%

With only root@localhost and root@127.0.0.1 enabled, the outputs of setup_tree_actors_by_host and setup_tree_actors_by_user gives respectively:

DOT Graph of setup_instruments

The full tree of setup_instruments can be created using the following sequence of steps (I am using graphviz to get support for dot files):

Conclusion

There is definitely more work to do on making the Performance Schema easier to access. ps_helper and ps_tools are a great start to what I am sure will be an extensive library of useful diagnostic queries and tools.

In MySQL 5.5 and earlier, the steps to resize the InnoDB log files were a bit involved and for example included manually moving the log files out of the way as InnoDB would only create new files, if none existed.

In MySQL 5.6 a not so much talked about feature is the support to resize the log files in a way much more similar to changing other settings in MySQL. Now you simply update your MySQL configuration file and restart MySQL.

Let us look at an example. In MySQL 5.5 and earlier the total size of the InnoDB log files has to be less than 4G in total, so one way of staying within this limit is to have two files each 2047M large:

1

2

3

innodb$ls-1sib_logfile*

2096132ib_logfile0

2096144ib_logfile1

Now update the configuration file to take advantage of the fact that MySQL 5.6 allows much larger InnoDB log files; the actual limit is a total size of 512G, but here I will use two files each 4G large:

1

2

3

[mysqld]

innodb_log_files_in_group = 2

innodb_log_file_size = 4G

Restarting MySQL will then automatically resize the log files, and the error log will show something like:

One of the other requirements when changing the log file size in MySQL 5.5 and earlier was that innodb_fast_shutdown must be set to 0 or 1 (the default value is 1). What happens in MySQL 5.6 if you have innodb_fast_shutdown = 2 and try to change the log size? Well now InnoDB handles that as well – InnoDB will do its “crash recovery” and then resize the log files:

1

2

mysql>SETGLOBALinnodb_fast_shutdown=2;

QueryOK,0rowsaffected(0.01sec)

And a look into the error log for the restart (setting the size back to 2 times 2047M):

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

2013-02-24 11:38:00 5997 [Note] InnoDB: MySQL has requested a very fast shutdown without flushing the InnoDB buffer pool to data files. At the next mysqld startup InnoDB will do a crash recovery!

With MySQL 5.6 just gone GA, I thought it would be good to take a look at the changes in options and variables that comes with the new release.

First of all, several of the existing options have get new default values. As James Day already have written a good post about that in his blog, I will refer to that instead of going through the changes. For a general overview of the new features and improvements, the recent blogs by Rob Young and Peter Saitsev are good starting points together with the What is New in MySQL 5.6 page in the Reference Manual are good places to start.

Instead I will focus a little on the new options that has been introduced. The first thing to note is that a in the current 5.5. release (5.5.30) there are 323 variables whereas 5.6 GA (5.6.10) returns 440 rows.

Note: this post is written using the Enterprise versions with the semi-synchronous replication plugins enabled in both versions plus the memcached and password validation plugins in 5.6.

Actually the number of new variables is not 117 but 129 as 12 variables have been removed in 5.6.

So what are all of these 129 new variables good for? Actually there is a good chance that you will never need to touch many of them as the default value is good enough, they simply have been added to provide the value of options already present in 5.5 but not exposed through SHOW GLOBAL VARIABLES, or that they are for features you are not using. If we try to group the new variables the distribution comes out as:

Feature

New Variables

Global Transaction IDs

5

Other Replication

19

Memcached Plugin

6

Validate Password Plugin

6

Other Security Related

5

InnoDB

54

Optimizer Traces

5

Performance Schema

15

Exposing Previously Existing Variables

2

Other

12

New Variables in MySQL 5.6

The 54 new InnoDB variables span a number of different changes and additions such as:

New adaptive flushing algorithm

Buffer Pool dumps to disk and restore

Support for additional checksum algorithms

Improvements for compression

Full text indexes

New monitoring options (the information_schema.metrics table)

Configurable page size

Persistent statistics

Undo logs improvements

And more …

For reference I have added a list of the new variables with the release they were introduced and the default value (additionally innodb_print_all_deadlocks is also new, but that was also added to 5.5.30):