Chris on MySQL

Getting LuaSocket to Work with MySQL Proxy

chris — Sat, 21 Aug 2010 02:21:06 +0000

I’ve seen some interest in trying to get LuaSocket working with MySQL Proxy, and most of those interested have run into issues getting this set up, so I want to provide a brief walk-through on how to get this set-up and working properly.

Note I tested this on Windows, so use .so instead of .dll on *nix systems.

1. Download LuaSocket (contains lua/ and lib/ directories)

2. Copy contents of ‘lua/’ into the following directory:

C:\Program Files\MySQL\mysql-proxy-0.8.0\lib\mysql-proxy\lua

3. Copy contents of ‘lib/’ into the following directory:

C:\Program Files\MySQL\mysql-proxy-0.8.0\bin

4. In step #3, you should have copied a ’socket/’ and ‘mime/’ directories into bin/. Rename the directory named “socket” to “lua-socket”. This will get you past one set of errors.

5. Next, in the C:\Program Files\MySQL\mysql-proxy-0.8.0\bin, there is a file named lua51.dll. If you try to run it now, you’ll get an error saying “lua5.1.dll was not found”. So make a *copy* of “lua51.dll” and rename it “lua5.1.dll” (in the same directory).

6. Invoke your proxy script with the correct –lua-cpath and –lua-path options (below is correct relative to my basedir and with regards to where I copied the contents of the LuaSocket):

C:\Program Files\MySQL\mysql-proxy-0.8.0\bin>mysql-proxy.exe --proxy-lua-script=show-vars.lua --lua-cpath=!\\lua-?.dll --lua-path=!\\..\\lib\\mysql-proxy\\lua\\?.lua;!\\..\\lib\\mysql-proxy\\lua\\socket\\?.lua

Proxy should start up fine with the script, it works, and you can access the socket functions within your own lua script.

For instance, my proxy basedir, which is also where my script is located, is:

C:\Program Files\MySQL\mysql-proxy-0.8.0\

show-vars.lua is the name of my lua script.

In it, I have the following 2 lines:

socket = require("socket")
print(socket._VERSION)

And when I start up the script, and connect to my instance, it outputs the following:

LuaSocket 2.0.1

Using EXPLAIN EXTENDED / SHOW WARNINGS to Help Troubleshoot Inefficient Queries in MySQL

chris — Fri, 09 Jul 2010 01:37:03 +0000

When examining the execution plan of troublesome queries in MySQL, most users are aware of using EXPLAIN. However, an often overlooked, yet very helpful extension of EXPLAIN, is EXPLAIN EXTENDED coupled with the SHOW WARNINGS command.

The reason being is because it provides a little more information about how the optimizer processes the query, and thus it could help to quickly identify a problem that you might not otherwise recognize with just EXPLAIN.

For instance, here is a common query which could be inefficient:

SELECT id FROM t WHERE id='1';

And here is the CREATE TABLE output:

mysql> show create table t\G
*************************** 1. row ***************************
       Table: t
Create Table: CREATE TABLE `t` (
  `id` decimal(10,0) default NULL,
  KEY `id` (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

You can see it’s a very basic table, and a very basic query.

And looking at the EXPLAIN output, everything still appears normal:

mysql> explain select id from t where id='1';
+----+-------------+-------+------+---------------+------+---------+-------+------+--------------------------+
| id | select_type | table | type | possible_keys | key  | key_len | ref   | rows | Extra                    |
+----+-------------+-------+------+---------------+------+---------+-------+------+--------------------------+
|  1 | SIMPLE      | t     | ref  | id            | id   | 6       | const |    1 | Using where; Using index |
+----+-------------+-------+------+---------------+------+---------+-------+------+--------------------------+
1 row in set (0.00 sec)

However, now let’s look at the EXPLAIN EXTENDED and SHOW WARNINGS output:

mysql> explain extended select id from t where id='1';
+----+-------------+-------+------+---------------+------+---------+-------+------+--------------------------+
| id | select_type | table | type | possible_keys | key  | key_len | ref   | rows | Extra                    |
+----+-------------+-------+------+---------------+------+---------+-------+------+--------------------------+
|  1 | SIMPLE      | t     | ref  | id            | id   | 6       | const |    1 | Using where; Using index |
+----+-------------+-------+------+---------------+------+---------+-------+------+--------------------------+
1 row in set, 1 warning (0.00 sec)

mysql> show warnings;
+-------+------+----------------------------------------------------------------------------------------------+
| Level | Code | Message                                                                                      |
+-------+------+----------------------------------------------------------------------------------------------+
| Note  | 1003 | select `testing`.`t`.`id` AS `id` from `testing`.`t` where (`testing`.`t`.`id` = _latin1'1') |
+-------+------+----------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

In the WHERE clause of the SHOW WARNINGS output, you see this:

where (`testing`.`t`.`id` = _latin1'1')

The _latin1′1′ is key, as it shows the value of 1 is getting cast as a latin1 value. This is because we surrounded the 1 with single quotes in the query.

Note that this does not happen if you do not surround the 1 with single quotes:

mysql> show warnings;
+-------+------+-------------------------------------------------------------------------------------+
| Level | Code | Message                                                                             |
+-------+------+-------------------------------------------------------------------------------------+
| Note  | 1003 | select `testing`.`t`.`id` AS `id` from `testing`.`t` where (`testing`.`t`.`id` = 1) |
+-------+------+-------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

In this example, the constant value of 1 is being cast, which is not horrible, but still not as efficient as it should be. However, depending on how the query is written, I’ve seen where it might choose to cast/convert the row retrived from the database (especially in a JOIN scenario - it will need to convert one column if they differ). These conversions or casts can be very inefficient (especially if within a JOIN or worse, a sub-query), and would not be otherwise caught without using EXPLAIN EXTENDED / SHOW WARNINGS.

And in addition to the above example, it is common to see similar types of conversions occurring if you try to match two columns whose character sets differ. This can be another easy-to-overlook problem, which can lead to poor performance, and you wouldn’t know it wasn’t running efficiently unless you used EXPLAIN EXTENDED (or unless it brings your system to a halt during a heavy load ..).

So in conclusion, consider using EXPLAIN EXTENDED / SHOW WARNINGS in lieu of just EXPLAIN when analyzing your queries.

Note: If you are using pre-5.1.46, you may want to consider running both EXPLAIN and EXPLAIN EXTENDED to ensure the optimization plans match. This is due to the following bug which existed:

http://bugs.mysql.com/bug.php?id=47669

Click here to give this article a “Thumbs Up” on Planet MySQL !

Ease of Switching to the InnoDB Plugin and the Numerous Benefits

chris — Thu, 01 Jul 2010 14:18:27 +0000

In my last post, I discussed how to troubleshoot InnoDB locks using the new InnoDB Plugin’s new Information Schema tables.

However, that got me to thinking about how many MySQL 5.1 users who have still not switched to use the plugin as opposed to the built-in version of InnoDB.

There are many advantages to using the plugin as opposed to the built-in version (aside from just the new I_S tables, and more importantly, numerous performance enhancements), and it’s breeze to set up, so I wanted to provide a quick start guide to using the new InnoDB plugin.

Note that the InnoDB plugin is now GA (as of plugin version 1.0.7) and as of 5.1.38 it is included with the MySQL downloads (it just needs to be enabled).

If you’re running pre-5.1.38, then you may want to consider upgrading to a newer MySQL anyways (5.1.48 is the latest as of this posting). But if not, then you’ll need to download the plugin and extract it.

But if you’re using 5.1.38 or newer, then just take the following steps:

1. Update your my.cnf (or my.ini) by adding the following 2 lines (note the dll should already exist in BASEDIR\lib\plugin):

ignore_builtin_innodb
plugin-load=innodb=ha_innodb_plugin.dll;innodb_trx=ha_innodb_plugin.dll;
                innodb_locks=ha_innodb_plugin.dll;innodb_lock_waits=ha_innodb_plugin.dll;
                innodb_cmp=ha_innodb_plugin.dll;innodb_cmp_reset=ha_innodb_plugin.dll;
                innodb_cmpmem=ha_innodb_plugin.dll;innodb_cmpmem_reset=ha_innodb_plugin.dll

2. Restart mysqld

3. Now you can check some various commands to verify it’s enabled.

I’ll post the BEFORE and AFTER, so you can see the differences:

SHOW GLOBAL VARIABLES LIKE ‘%innodb%’ Output:

BEFORE Plugin:

mysql> show global variables like '%innodb%';
+-----------------------------------------+------------------------+
| Variable_name                           | Value                  |
+-----------------------------------------+------------------------+
| have_innodb                             | YES                    |
| ignore_builtin_innodb                   | OFF                    |
| innodb_adaptive_hash_index              | ON                     |
| innodb_additional_mem_pool_size         | 2097152                |
| innodb_autoextend_increment             | 8                      |
| innodb_autoinc_lock_mode                | 1                      |
| innodb_buffer_pool_size                 | 49283072               |
| innodb_checksums                        | ON                     |
| innodb_commit_concurrency               | 0                      |
| innodb_concurrency_tickets              | 500                    |
| innodb_data_file_path                   | ibdata1:10M:autoextend |
| innodb_data_home_dir                    |                        |
| innodb_doublewrite                      | ON                     |
| innodb_fast_shutdown                    | 1                      |
| innodb_file_io_threads                  | 4                      |
| innodb_file_per_table                   | ON                     |
| innodb_flush_log_at_trx_commit          | 1                      |
| innodb_flush_method                     |                        |
| innodb_force_recovery                   | 0                      |
| innodb_lock_wait_timeout                | 50                     |
| innodb_locks_unsafe_for_binlog          | OFF                    |
| innodb_log_buffer_size                  | 1048576                |
| innodb_log_file_size                    | 25165824               |
| innodb_log_files_in_group               | 2                      |
| innodb_log_group_home_dir               | .\                     |
| innodb_max_dirty_pages_pct              | 90                     |
| innodb_max_purge_lag                    | 0                      |
| innodb_mirrored_log_groups              | 1                      |
| innodb_open_files                       | 300                    |
| innodb_rollback_on_timeout              | OFF                    |
| innodb_stats_on_metadata                | ON                     |
| innodb_support_xa                       | ON                     |
| innodb_sync_spin_loops                  | 20                     |
| innodb_table_locks                      | ON                     |
| innodb_thread_concurrency               | 8                      |
| innodb_thread_sleep_delay               | 10000                  |
| innodb_use_legacy_cardinality_algorithm | ON                     |
+-----------------------------------------+------------------------+
37 rows in set (0.00 sec)

AFTER Plugin:

mysql> show global variables like '%innodb%';
+---------------------------------+------------------------+
| Variable_name                   | Value                  |
+---------------------------------+------------------------+
| have_innodb                     | YES                    |
| ignore_builtin_innodb           | ON                     |
| innodb_adaptive_flushing        | ON                     |
| innodb_adaptive_hash_index      | ON                     |
| innodb_additional_mem_pool_size | 2097152                |
| innodb_autoextend_increment     | 8                      |
| innodb_autoinc_lock_mode        | 1                      |
| innodb_buffer_pool_size         | 49283072               |
| innodb_change_buffering         | inserts                |
| innodb_checksums                | ON                     |
| innodb_commit_concurrency       | 0                      |
| innodb_concurrency_tickets      | 500                    |
| innodb_data_file_path           | ibdata1:10M:autoextend |
| innodb_data_home_dir            |                        |
| innodb_doublewrite              | ON                     |
| innodb_fast_shutdown            | 1                      |
| innodb_file_format              | Antelope               |
| innodb_file_format_check        | Antelope               |
| innodb_file_per_table           | ON                     |
| innodb_flush_log_at_trx_commit  | 1                      |
| innodb_flush_method             |                        |
| innodb_force_recovery           | 0                      |
| innodb_io_capacity              | 200                    |
| innodb_lock_wait_timeout        | 50                     |
| innodb_locks_unsafe_for_binlog  | OFF                    |
| innodb_log_buffer_size          | 1048576                |
| innodb_log_file_size            | 25165824               |
| innodb_log_files_in_group       | 2                      |
| innodb_log_group_home_dir       | .\                     |
| innodb_max_dirty_pages_pct      | 75                     |
| innodb_max_purge_lag            | 0                      |
| innodb_mirrored_log_groups      | 1                      |
| innodb_old_blocks_pct           | 37                     |
| innodb_old_blocks_time          | 0                      |
| innodb_open_files               | 300                    |
| innodb_read_ahead_threshold     | 56                     |
| innodb_read_io_threads          | 4                      |
| innodb_replication_delay        | 0                      |
| innodb_rollback_on_timeout      | OFF                    |
| innodb_spin_wait_delay          | 6                      |
| innodb_stats_on_metadata        | ON                     |
| innodb_stats_sample_pages       | 8                      |
| innodb_strict_mode              | OFF                    |
| innodb_support_xa               | ON                     |
| innodb_sync_spin_loops          | 30                     |
| innodb_table_locks              | ON                     |
| innodb_thread_concurrency       | 8                      |
| innodb_thread_sleep_delay       | 10000                  |
| innodb_use_sys_malloc           | ON                     |
| innodb_version                  | 1.0.9                  |
| innodb_write_io_threads         | 4                      |
+---------------------------------+------------------------+
51 rows in set (0.00 sec)

In the above, with the plugin, you can see the value of ignore_builtin_innodb is now “ON”.

Also, the innodb_file_format and innodb_file_format_check is “Antelope” for this particular version of the plugin.

There are also a number of new variables, such as innodb_adaptive_flushing, innodb_change_buffering, innodb_file_format, innodb_file_format_check, innodb_io_capacity, innodb_old_blocks_pct, innodb_old_blocks_time, innodb_read_ahead_threshold, innodb_read_io_threads, innodb_replication_delay, innodb_spin_wait_delay, innodb_stats_sample_pages, innodb_stats_sample_pages, innodb_strict_mode, innodb_use_sys_malloc, innodb_version, and innodb_write_io_threads.

The only two missing from the new plugin are innodb_file_io_threads and innodb_use_legacy_cardinality_algorithm.

SELECT * FROM PLUGINS Output:

BEFORE Plugin:

mysql> use information_schema;
Database changed
mysql> select * from plugins;
+-------------+----------------+---------------+----------------+---------------------+----------------+------------------------+--------------------------------------------+--------------------------------------------------------------------------+----------------+
| PLUGIN_NAME | PLUGIN_VERSION | PLUGIN_STATUS | PLUGIN_TYPE    | PLUGIN_TYPE_VERSION | PLUGIN_LIBRARY | PLUGIN_LIBRARY_VERSION | PLUGIN_AUTHOR                              | PLUGIN_DESCRIPTION                                                       | PLUGIN_LICENSE |
+-------------+----------------+---------------+----------------+---------------------+----------------+------------------------+--------------------------------------------+--------------------------------------------------------------------------+----------------+
| binlog      | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | MySQL AB                                   | This is a pseudo storage engine to represent the binlog in a transaction | GPL            |
| ARCHIVE     | 3.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | Brian Aker, MySQL AB                       | Archive storage engine                                                   | GPL            |
| BLACKHOLE   | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | MySQL AB                                   | /dev/null storage engine (anything you write to it disappears)           | GPL            |
| CSV         | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | Brian Aker, MySQL AB                       | CSV storage engine                                                       | GPL            |
| FEDERATED   | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | Patrick Galbraith and Brian Aker, MySQL AB | Federated MySQL storage engine                                           | GPL            |
| MEMORY      | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | MySQL AB                                   | Hash based, stored in memory, useful for temporary tables                | GPL            |
| InnoDB      | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | Innobase OY                                | Supports transactions, row-level locking, and foreign keys               | GPL            |
| MyISAM      | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | MySQL AB                                   | Default engine as of MySQL 3.23 with great performance                   | GPL            |
| MRG_MYISAM  | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | MySQL AB                                   | Collection of identical MyISAM tables                                    | GPL            |
| partition   | 1.0            | ACTIVE        | STORAGE ENGINE | 50148.0             | NULL           | NULL                   | Mikael Ronstrom, MySQL AB                  | Partition Storage Engine Helper                                          | GPL            |
+-------------+----------------+---------------+----------------+---------------------+----------------+------------------------+--------------------------------------------+--------------------------------------------------------------------------+----------------+
10 rows in set (0.01 sec)

AFTER Plugin:

mysql> use information_schema; Database changed mysql> select * from plugins; +---------------------+---- | PLUGIN_NAME +---------------------+---- | binlog              | 1.0 | ARCHIVE             | 3.0 | BLACKHOLE           | 1.0 | CSV                 | 1.0 | FEDERATED           | 1.0 | MEMORY              | 1.0 | MyISAM              | 1.0 | MRG_MYISAM          | 1.0 | partition           | 1.0 | InnoDB              | 1.0 | INNODB_TRX          | 1.0 | INNODB_LOCKS        | 1.0 | INNODB_LOCK_WAITS   | 1.0 | INNODB_CMP          | 1.0 | INNODB_CMP_RESET    | 1.0 | INNODB_CMPMEM       | 1.0 | INNODB_CMPMEM_RESET | 1.0 +---------------------+---- 17 rows in set (0.01 sec)

------------+---------------+--------------------+---------------------+----------------------+------------------------+--------------------------------------------+--------------------------------------------------------------------------+----------------+ | PLUGIN_VERSION | PLUGIN_STATUS | PLUGIN_TYPE | PLUGIN_TYPE_VERSION | PLUGIN_LIBRARY | PLUGIN_LIBRARY_VERSION | PLUGIN_AUTHOR | PLUGIN_DESCRIPTION | PLUGIN_LICENSE | ------------+---------------+--------------------+---------------------+----------------------+------------------------+--------------------------------------------+--------------------------------------------------------------------------+----------------+ | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | MySQL AB | This is a pseudo storage engine to represent the binlog in a transaction | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | Brian Aker, MySQL AB | Archive storage engine | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | MySQL AB | /dev/null storage engine (anything you write to it disappears) | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | Brian Aker, MySQL AB | CSV storage engine | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | Patrick Galbraith and Brian Aker, MySQL AB | Federated MySQL storage engine | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | MySQL AB | Hash based, stored in memory, useful for temporary tables | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | MySQL AB | Default engine as of MySQL 3.23 with great performance | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | MySQL AB | Collection of identical MyISAM tables | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | NULL | NULL | Mikael Ronstrom, MySQL AB | Partition Storage Engine Helper | GPL | | ACTIVE | STORAGE ENGINE | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | Supports transactions, row-level locking, and foreign keys | GPL | | ACTIVE | INFORMATION SCHEMA | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | InnoDB transactions | GPL | | ACTIVE | INFORMATION SCHEMA | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | InnoDB conflicting locks | GPL | | ACTIVE | INFORMATION SCHEMA | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | InnoDB which lock is blocking which | GPL | | ACTIVE | INFORMATION SCHEMA | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | Statistics for the InnoDB compression | GPL | | ACTIVE | INFORMATION SCHEMA | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | Statistics for the InnoDB compression; reset cumulated counts | GPL | | ACTIVE | INFORMATION SCHEMA | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | Statistics for the InnoDB compressed buffer pool | GPL | | ACTIVE | INFORMATION SCHEMA | 50148.0 | ha_innodb_plugin.dll | 1.0 | Innobase Oy | Statistics for the InnoDB compressed buffer pool; reset cumulated counts | GPL | ------------+---------------+--------------------+---------------------+----------------------+------------------------+--------------------------------------------+--------------------------------------------------------------------------+----------------+

In the above output, you can see the values for the InnoDB Plugin have changed. For instance, the PLUGIN_LIBRARY now shows ha_innodb_plugin.dll. Additionally, you can see the new INFORMATION SCHEMA plugins listed, which are INNODB_TRX, INNODB_LOCKS, INNODB_LOCK_WAITS, INNODB_CMP, INNODB_CMP_RESET, INNODB_CMPMEM, INNODB_CMPMEM_RESET.

Lastly, I’ll just post the output from SHOW ENGINE INNODB STATUS from the new Plugin only. There’s new information provided here as well (see “Pages made young 0, not young 0″ amongst numerous others).

mysql> show engine innodb status\G
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
100622 19:22:06 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 39 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 1 1_second, 1 sleeps, 0 10_second, 2 background, 2 flush
srv_master_thread log flush and writes: 1
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 3, signal count 3
Mutex spin waits 0, rounds 0, OS waits 0
RW-shared spins 3, OS waits 3; RW-excl spins 0, OS waits 0
Spin rounds per wait: 0.00 mutex, 30.00 RW-shared, 0.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 20E00
Purge done for trx's n:o < 20C18 undo n:o < 0
History list length 11
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started, OS thread id 8812
MySQL thread id 1, query id 7 localhost 127.0.0.1 root
show engine innodb status
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (write thread)
I/O thread 7 state: wait Windows aio (write thread)
I/O thread 8 state: wait Windows aio (write thread)
I/O thread 9 state: wait Windows aio (write thread)
Pending normal aio reads: 0, aio writes: 0,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
27 OS file reads, 7 OS file writes, 7 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 2174, seg size 2176,
0 inserts, 0 merged recs, 0 merges
Hash table size 195193, node heap has 0 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 745473833
Log flushed up to   745473833
Last checkpoint at  745473833
0 pending log writes, 0 pending chkp writes
10 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 50184192; in additional pool allocated 0
Dictionary memory allocated 20888
Buffer pool size   3008
Free buffers       2992
Database pages     16
Old database pages 0
Modified db pages  0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 16, created 0, written 1
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s
LRU len: 16, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread id 9800, state: waiting for server activity
Number of rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

So in conclusion, it’s very easy to enable the InnoDB Plugin (add 2 lines to your my.cnf file and restart). So if you’re running 5.1, you should definitely consider enablig the InnoDB plugin if you haven’t already, and you will gain the following numerous benefits (posted from the manual):

Fast index creation: add or drop indexes without copying the data
Data compression: shrink tables, to significantly reduce storage and i/o
New row format: fully off-page storage of long BLOB, TEXT, and VARCHAR columns
File format management: protects upward and downward compatibility
INFORMATION_SCHEMA tables: information about compression and locking
Performance and scalability enhancements:

Faster locking for improved scalability
Using operating system memory allocators
Controlling InnoDB insert buffering
Controlling adaptive hash indexing
Changes regarding thread concurrency
Changes in read ahead algorithm
Multiple background I/O threads
Group Commit
Controlling master thread I/O rate
Controlling flushing rate of dirty pages
Using a portable PAUSE to InnoDB spin loop
Control Over Spin Lock Polling
Changing defaults of parameters
Making Buffer Cache Scan Resistant
Improvements to Crash Recovery Performance

Other changes for flexibility, ease of use and reliability:

Dynamic control of system configuration parameters
TRUNCATE TABLE reclaims space
InnoDB “strict mode”
Control over statistics estimation
Better error handling when dropping indexes
More compact output of SHOW ENGINE INNODB MUTEX
More Read Ahead Statistics

http://dev.mysql.com/doc/innodb-plugin/1.0/en/innodb-plugin-introduction-features.html

Click here to give this article a “Thumbs Up” on Planet MySQL !

Debugging InnoDB Locks using the new InnoDB Plugin’s Information Schema Tables

chris — Tue, 29 Jun 2010 19:47:41 +0000

Tracking down InnoDB lock information using the new Information Schema tables provided with the InnoDB plugin has never been easier.

Long story short, the other day I was trying to identify what transaction was holding the lock for a particular UPDATE. The UPDATE would not complete and kept timing out with “Lock wait timeout exceeded; try restarting transaction”.

Of course I checked the output of SHOW ENGINE INNODB STATUS. From that output, I could tell it was the replication thread holding the lock, *since* it was the only other transaction running. But I could not verify this with output, it just had to be the case.

Next I enabled the InnoDB lock monitor, and examined that output too. Here, it showed more detail on the locks being held, however, it only shows the first 10 locks held by the replication thread. In this case, the replication thread was holding more than 2000 record locks from a large, open transaction. Needless to say, the lock I was looking for was not amongst the 10 displayed.

So I enabled InnoDB plugin (just added the following 2 lines to my config file and restarted mysqld):

ignore_builtin_innodb
plugin-load=innodb=ha_innodb_plugin.dll;innodb_trx=ha_innodb_plugin.dll;
innodb_locks=ha_innodb_plugin.dll;innodb_lock_waits=ha_innodb_plugin.dll;
innodb_cmp=ha_innodb_plugin.dll;innodb_cmp_reset=ha_innodb_plugin.dll;
innodb_cmpmem=ha_innodb_plugin.dll;innodb_cmpmem_reset=ha_innodb_plugin.dll

After the above, you’ll notice the following new tables in Information Schema:

mysql> SHOW TABLES IN INFORMATION_SCHEMA LIKE 'INNODB_%';
+-----------------------------------------+
| Tables_in_information_schema (INNODB_%) |
+-----------------------------------------+
| INNODB_CMP_RESET                        |
| INNODB_TRX                              |
| INNODB_CMPMEM_RESET                     |
| INNODB_LOCK_WAITS                       |
| INNODB_CMPMEM                           |
| INNODB_CMP                              |
| INNODB_LOCKS                            |
+-----------------------------------------+
7 rows in set (0.00 sec)

For this particular problem, I wanted to see what was in INNODB_TRX, INNODB_LOCKS, and INNODB_LOCK_WAITS:

mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_TRX; +--------+-----------+---------------------+-----------------------+---------------------+------------+---------------------+-----------+ | trx_id | trx_state | trx_started | trx_requested_lock_id | trx_wait_started | trx_weight | trx_mysql_thread_id | trx_query | +--------+-----------+---------------------+-----------------------+---------------------+------------+---------------------+-----------+ | 124616 | LOCK WAIT | 2010-06-23 13:51:52 | 124616:1301:1572:6 | 2010-06-23 13:51:52 | 2 | 496854 | NULL | | 123900 | RUNNING | 2010-06-23 09:30:59 | NULL | NULL | 506 | 3 | NULL | +--------+-----------+---------------------+-----------------------+---------------------+------------+---------------------+-----------+ 2 rows in set (0.00 sec)


mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCKS;

+--------------------+-------------+-----------+-----------+-------------------------+------------+------------+-----------+----------+-----------+

| lock_id            | lock_trx_id | lock_mode | lock_type | lock_table              | lock_index | lock_space | lock_page | lock_rec | lock_data |

+--------------------+-------------+-----------+-----------+-------------------------+------------+------------+-----------+----------+-----------+

| 124616:1301:1572:6 | 124616      | X         | RECORD    | `db1`.`t1` | `PRIMARY`  |       1301 |      1572 |        6 | 4100      |

| 123900:1301:1572:6 | 123900      | S         | RECORD    | `db1`.`t1` | `PRIMARY`  |       1301 |      1572 |        6 | 4100      |

+--------------------+-------------+-----------+-----------+-------------------------+------------+------------+-----------+----------+-----------+

2 rows in set (0.01 sec)

mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCK_WAITS; +-------------------+--------------------+-----------------+--------------------+ | requesting_trx_id | requested_lock_id | blocking_trx_id | blocking_lock_id | +-------------------+--------------------+-----------------+--------------------+ | 124616 | 124616:1301:1572:6 | 123900 | 123900:1301:1572:6 | +-------------------+--------------------+-----------------+--------------------+ 1 row in set (0.00 sec)

Finally, I had conclusive evidence that it was indeed the replication thread (trx id 123900) holding the lock which was blocking the UPDATE.

I also found the exact row which was being held, and all of the details, such as it was a S (shared) record lock, and the the lock was on the primary key of table db1.t1. It even tells you the lock_space (1301), the lock_page (1572), the lock_rec (6) , and the actual data, lock_data (4100).

The other key piece was the time (or trx_started) for the running transaction, 123900. With that, we knew exactly where to check the binlogs for the exact statement where this all began.

In conclusion, I wish I had started here to begin with, so keep this in mind for the future. And this is just one example of how beneficial these new InnoDB Plugin Information Schema tables can be for troubleshooting. You can find even more details/examples at the following location:

http://dev.mysql.com/doc/innodb-plugin/1.0/en/innodb-information-schema-examples.html

Click here to give this article a “Thumbs Up” on Planet MySQL !

Proxy Trace : Tracing the Variables and Functions Available within MySQL Proxy

chris — Wed, 27 Jan 2010 22:16:30 +0000

Have you ever wanted a handy reference of all of the various variables available in MySQL Proxy?

I’ve written a Lua script that outputs many of the available variables, which is really useful for coding Lua scripts for MySQL Proxy. In addition to the variables, it also generates output during each main function it enters in the Proxy, so you can follow the execution trace, and then see the value of each variable when it is within a particular function.

I’ve tested this on MySQL Proxy 0.7.2 and the newly available Proxy 0.8.0.

Here is a sample of the output, where I just connect, and then issue a simple query (SELECT * FROM world.city LIMIT 1):

C:\Program Files\MySQL\mysql-proxy-0.8.0\bin>mysql-proxy.exe
 --proxy-lua-script=show-vars.lua

/* Entering function connect_server() */
   When the proxy accepts a connection from a MySQL client, the
   connect_server() function is called.  There are no arguments
   to the function, but you can use and if necessary manipulate
   the information in the proxy.connection table, which is unique
   to each client session.

/* Entering function read_handshake() */
   Handshake information is sent by the server to the client
   after the initial connection (through connect_server()) has
   been made.  read_handshake() doesn't receive a parameter
   anymore. Instead all the data is available in the connection
   tables.

/* Entering function read_auth() */
   The read_auth() function is triggered when an authentication
   handshake is initiated by the client.  read_auth() doesn't
   receive a parameter anymore. Instead all the data is
   available in the connection tables.

/* Entering function read_auth_result() */
   The return packet from the server during authentication is
   captured by read_auth_result().
...

/* Entering function read_query( packet ) */
| o = [backends] userdata: 01AD9298 (type=userdata)
[config] table: 01AD5890 (type=table)

| Query               = select * from world.city limit 1
| Time Stamp          = 2010-01-27 16:14:05
| Proxy Version       = 00800
| Lua Version         = Lua 5.1

/* Entering function read_query_result( inj ) */
| os.date                                      = 2010-01-27 16:14:05
| inj.query                                    = ♥select * from world.city limit 1
| proxy.connection.server.scramble_buffer      = "]CvKTD8,r|9B#&3oU>tO"
| proxy.connection.server.mysqld_version       = 50089
| proxy.connection.server.thread_id            = 21
| proxy.connection.client.default_db           = world
| proxy.connection.client.username             = root
| proxy.connection.client.scrambled_password   = "+δí!ò→g~\000h[BNòr∩+╦═"
| proxy.connection.client.dst.name             = 127.0.0.1:4040
| proxy.connection.client.dst.address          = 127.0.0.1
| proxy.connection.client.dst.port             = 4040
| proxy.connection.server.dst.name             = 127.0.0.1:3306
| proxy.connection.server.dst.address          = 127.0.0.1
| proxy.connection.server.dst.port             = 3306
| proxy.connection.client.src.name             = 127.0.0.1:58468
| proxy.connection.client.src.address          = 127.0.0.1
| proxy.connection.client.src.port             = 58468
| proxy.connection.server.src.name             = 127.0.0.1:58469
| proxy.connection.server.src.address          = 127.0.0.1
| proxy.connection.server.src.port             = 58469
| inj.query-time                               = 4.6ms
| inj.response-time                            = 4.613ms
| proxy.connection.backend_ndx                 = 1
| #proxy.global.backends                       = 1
| proxy.global.backends[ndx].dst.name          = 127.0.0.1:3306
| proxy.global.backends[ndx].dst.address       = 127.0.0.1
| proxy.global.backends[ndx].dst.port          = 3306
| proxy.global.backends[ndx].connected_clients = 1
| proxy.global.backends[ndx].state             = 1
| proxy.global.backends[ndx].pool.max_idle_connections = 0
| proxy.global.backends[ndx].pool.min_idle_connections = 0
| proxy.global.backends[ndx].pool.users[1]     = 0
| result.len                                   = 1
| result.flags.in_trans                        = false
| result.flags.auto_commit                     = true
| result.flags.no_good_index_used              = false
| result.flags.no_index_used                   = true
| result.warning_count                         = 0
| result.query_status                          = 0
| result.fields[1].type                        = 3
| result.fields[1].name                        = ID
| query returned                               = 1

/* Entering function read_query( packet ) */
| o = [backends] userdata: 01AD9298 (type=userdata)
[config] table: 01AD5890 (type=table)

/* Entering function disconnect_client() */
Client 21 has disconnected.

C:\Program Files\MySQL\mysql-proxy-0.8.0\bin>

And, here is the full script (named “show-vars.lua” in the above invocation):

function connect_server()
	print("/* Entering function connect_server() */")
	print("   When the proxy accepts a connection from a MySQL client, the")
	print("   connect_server() function is called.  There are no arguments")
	print("   to the function, but you can use and if necessary manipulate")
	print("   the information in the proxy.connection table, which is unique")
	print("   to each client session.\n")
end

function read_handshake()
	print("/* Entering function read_handshake() */")
	print("   Handshake information is sent by the server to the client")
	print("   after the initial connection (through connect_server()) has")
	print("   been made.  read_handshake() doesn't receive a parameter")
	print("   anymore. Instead all the data is available in the connection")
	print("   tables.\n")
end

function read_auth()
	print("/* Entering function read_auth() */")
	print("   The read_auth() function is triggered when an authentication")
	print("   handshake is initiated by the client.  read_auth() doesn't")
	print("   receive a parameter anymore. Instead all the data is")
	print("   available in the connection tables.\n")
end

function read_auth_result()
	print("/* Entering function read_auth_result() */")
	print("   The return packet from the server during authentication is")
	print("   captured by read_auth_result().\n")
end

function read_query( packet )
	print("/* Entering function read_query( packet ) */")
	o = ""
	for k, v in pairs(proxy.global) do
		o = o .. (("[%s] %s (type=%s)\n"):format(k, tostring(v), type(v)))
	end
	print("| o = " .. o)
	if string.byte(packet) == proxy.COM_QUERY then
		proxy.queries:append(1, packet, {resultset_is_needed = true} )
        print("| Query               = "
			.. string.sub(packet, 2))
		print("| Time Stamp          = "
			.. os.date('%Y-%m-%d %H:%M:%S'))
		print("| Proxy Version       = "
			.. string.format("%05x", proxy.PROXY_VERSION))
		print("| Lua Version         = "
			.. _VERSION)
		return proxy.PROXY_SEND_QUERY
	end
end

function read_query_result( inj )
	print("\n/* Entering function read_query_result( inj ) */")
	local res         = assert(inj.resultset)
	local raw_len     = assert(res.raw):len()
	local packet      = assert(inj.query)
	local flags       = res.flags
	local backend_ndx = proxy.connection.backend_ndx
	print("| os.date                                      = "
		.. os.date('%Y-%m-%d %H:%M:%S'))
	print("| inj.query                                    = "
		.. inj.query)
	print("| proxy.connection.server.scramble_buffer      = "
		.. string.format("%q",proxy.connection.server.scramble_buffer))
	print("| proxy.connection.server.mysqld_version       = "
		.. proxy.connection.server.mysqld_version)
	print("| proxy.connection.server.thread_id            = "
		.. proxy.connection.server.thread_id)
	print("| proxy.connection.client.default_db           = "
		.. proxy.connection.client.default_db)
	print("| proxy.connection.client.username             = "
		.. proxy.connection.client.username)
	print("| proxy.connection.client.scrambled_password   = "
		.. string.format("%q", proxy.connection.client.scrambled_password))
	print("| proxy.connection.client.dst.name             = "
		.. proxy.connection.client.dst.name)
	print("| proxy.connection.client.dst.address          = "
		.. proxy.connection.client.dst.address)
	print("| proxy.connection.client.dst.port             = "
		.. proxy.connection.client.dst.port)
	print("| proxy.connection.server.dst.name             = "
		.. proxy.connection.server.dst.name)
	print("| proxy.connection.server.dst.address          = "
		.. proxy.connection.server.dst.address)
	print("| proxy.connection.server.dst.port             = "
		.. proxy.connection.server.dst.port)
	print("| proxy.connection.client.src.name             = "
		.. proxy.connection.client.src.name)
	print("| proxy.connection.client.src.address          = "
		.. proxy.connection.client.src.address)
	print("| proxy.connection.client.src.port             = "
		.. proxy.connection.client.src.port)
	print("| proxy.connection.server.src.name             = "
		.. proxy.connection.server.src.name)
	print("| proxy.connection.server.src.address          = "
		.. proxy.connection.server.src.address)
	print("| proxy.connection.server.src.port             = "
		.. proxy.connection.server.src.port)
	print("| inj.query-time                               = "
		.. (inj.query_time / 1000) .. "ms")
	print("| inj.response-time                            = "
		.. (inj.response_time / 1000) .. "ms")
	print("| proxy.connection.backend_ndx                 = "
		.. proxy.connection.backend_ndx)
	print("| #proxy.global.backends                       = "
		.. #proxy.global.backends)
	print("| proxy.global.backends[ndx].dst.name          = "
		.. proxy.global.backends[backend_ndx].dst.name)
	print("| proxy.global.backends[ndx].dst.address       = "
		.. proxy.global.backends[backend_ndx].dst.address)
	print("| proxy.global.backends[ndx].dst.port          = "
		.. proxy.global.backends[backend_ndx].dst.port)
	print("| proxy.global.backends[ndx].connected_clients = "
		.. proxy.global.backends[backend_ndx].connected_clients)
	print("| proxy.global.backends[ndx].state             = "
		.. proxy.global.backends[backend_ndx].state)
	print("| proxy.global.backends[ndx].pool.max_idle_connections = "
		.. proxy.global.backends[backend_ndx].pool.max_idle_connections)
	print("| proxy.global.backends[ndx].pool.min_idle_connections = "
		.. proxy.global.backends[backend_ndx].pool.min_idle_connections)
	print("| proxy.global.backends[ndx].pool.users[1]     = "
		.. proxy.global.backends[backend_ndx].pool.users[1].cur_idle_connections)
	print("| result.len                                   = "
		.. raw_len)
	print("| result.flags.in_trans                        = "
		.. tostring(res.flags.in_trans))
	print("| result.flags.auto_commit                     = "
		.. tostring(res.flags.auto_commit))
	print("| result.flags.no_good_index_used              = "
		.. tostring(res.flags.no_good_index_used))
	print("| result.flags.no_index_used                   = "
		.. tostring(res.flags.no_index_used))
	print("| result.warning_count                         = "
		.. res.warning_count)
	print("| result.query_status                          = "
		.. res.query_status)
	if res.affected_rows then
		print("| result.affected_rows                         = "
			.. res.affected_rows)
		print("| result.insert_id                             = "
			.. res.insert_id)
	end
	if res.query_status == proxy.MYSQLD_PACKET_ERR then
		print("| result.err.code                              = "
			.. res.raw:byte(2) + (res.raw:byte(3) * 256))
		print("| result.err.sql_state                         = "
			.. string.format("%q", res.raw:sub(5, 9)))
		print("| result.err.msg                               = "
			.. string.format("%q", res.raw:sub(10)))
	end
	if res.query_status == proxy.MYSQLD_PACKET_OK then
		print("| result.fields[1].type                        = "
			.. res.fields[1].type)
		print("| result.fields[1].name                        = "
			.. res.fields[1].name)
		for row in inj.resultset.rows do
			print("| query returned                               = "
				.. row[1])
		end
	end
	print("\n")
end

function disconnect_client()
	print("/* Entering function disconnect_client() */")
	if proxy.connection.server.thread_id then
		print("Client " .. proxy.connection.server.thread_id
			.. " has disconnected.")
	end
end

Writing output to a log file using MySQL Proxy

chris — Mon, 30 Nov 2009 20:57:00 +0000

In my previous post, Capturing Erroneous Queries with MySQL Proxy, I showed how to capture erroneous queries, along with relevant information, that one could not effectively obtain from the MySQL general query log. However, in that post, I simply output the information to the terminal. Therefore, in this example, I want to show how to write this information to a proxy log file.

To change this to log to a log file does not require too many changes, and so this is a useful example on how to log any proxy-related information to a log file.

I perform a check for an existing log file (at least using the variable of name “log_file”), and then assign log_file to the location of where I want the log file to reside (at the beginning of the lua script).
```
if (log_file == nil) then
  log_file = "C:/Program Files/MySQL/mysql-proxy-0.7.2/proxy.log"
end
```
Directly after that, and a key element, is to then declare a file handle for this file and open it for writing purposes (directly after the above statements):
```
local fh = io.open(log_file, "a+")
```
I create a local variable named “out_string” and assign all output that I want to write to this variable.
Once you have “out_string” fully populated, then just issue the following two commands:
```
fh:write(out_string .. "\n")
fh:flush()
```

Now everything you have stored in the variable “out_string” will be written to the new proxy log file that you have opened.

Here is the full script for reference:

if (log_file == nil) then
  log_file = "C:/Program Files/MySQL/mysql-proxy-0.7.2/proxy.log"
end
local fh = io.open(log_file, "a+")

function read_query( packet )
  if string.byte(packet) == proxy.COM_QUERY then
    proxy.queries:append(1, packet, {resultset_is_needed = true} )
    local out_string = "+ ---------- Incoming query ---------- " .. "\n" ..
      "+ Query = " .. string.sub(packet, 2) .. "\n" ..
      "+ Time  = " .. os.date('%Y-%m-%d %H:%M:%S') .. "\n" ..
      "+ ------------------------------------ "
    fh:write(out_string .. "\n")
    fh:flush()
    return proxy.PROXY_SEND_QUERY
  end
end

function read_query_result (inj)
  local res = assert(inj.resultset)
  if res.query_status == proxy.MYSQLD_PACKET_ERR then
    local out_string = "---------- Returning results ----------" .. "\n" ..
      "- time stamp = "
        .. os.date('%Y-%m-%d %H:%M:%S') .. "\n" ..
      "- query = "
        .. inj.query .. "\n" ..
      "- result.err.code = "
        .. res.raw:byte(2) + (res.raw:byte(3) * 256) .. "\n" ..
      "- result.err.sql_state = "
        .. string.format("%q", res.raw:sub(5, 9)) .. "\n" ..
      "- result.err.msg = "
        .. string.format("%q", res.raw:sub(10)) .. "\n" ..
      "- proxy.connection.client.default_db = "
        .. proxy.connection.client.default_db .. "\n" ..
      "- proxy.connection.client.username = "
        .. proxy.connection.client.username .. "\n" ..
      "- proxy.connection.client.address = "
        .. proxy.connection.client.src.name .. "\n" ..
      "- proxy.connection.server.thread_id = "
        .. proxy.connection.server.thread_id .. "\n"
    fh:write(out_string .. "\n")
    fh:flush()
  end
end

Capturing Erroneous Queries with MySQL Proxy

chris — Wed, 28 Oct 2009 17:59:49 +0000

The MySQL General Query Log can be very beneficial as it records all queries sent to the server. However, there are times you want more specific information, which can be hard, if not impossible, to filter from this log.

For instance, say you want to capture only queries that cause an error. The errors are not included in the general query log, so filtering based on that is not possible. However, we can easily capture this information using MySQL Proxy with a simple Lua script.

To implement this, the key is to examine the query status in the returned packet from the server to see if there is an error or not. Should the query status be that of an error, then we have what we want, and all that remains is to output whatever relevant information we’d like to see.

Code-wise, we want to examine the returned packet in function read_query_result(), and then check the query status to see if it returns an error (i.e., proxy.MYSQLD_PACKET_ERR). So, we have the following:

function read_query_result (inj)
  local res = assert(inj.resultset)
  if res.query_status == proxy.MYSQLD_PACKET_ERR then
    -- here we have query that returns an error
    print(...)
  end
end

And that is basically all there is to it.

Here is the full script, so you can see it in its entirety:

function read_query( packet )
  if string.byte(packet) == proxy.COM_QUERY then
    proxy.queries:append(1, packet, {resultset_is_needed = true} )
    return proxy.PROXY_SEND_QUERY
  end
end

function read_query_result (inj)
  local res = assert(inj.resultset)
  if res.query_status == proxy.MYSQLD_PACKET_ERR then
    local out_string =
      "Time Stamp = " .. os.date('%Y-%m-%d %H:%M:%S') .. "\n" ..
      "Query      = " .. inj.query .. "\n" ..
      "Error Code = " .. res.raw:byte(2)+(res.raw:byte(3)*256) .. "\n" ..
      "SQL State  = " .. string.format("%q", res.raw:sub(5, 9)) .. "\n" ..
      "Err Msg    = " .. string.format("%q", res.raw:sub(10)) .. "\n" ..
      "Default DB = " .. proxy.connection.client.default_db .. "\n" ..
      "Username   = " .. proxy.connection.client.username .. "\n" ..
      "Address    = " .. proxy.connection.client.src.name .. "\n" ..
      "Thread ID  = " .. proxy.connection.server.thread_id .. "\n"
    print(out_string .. "\n")
  end
end

Notes:

In function read_query(), when I append the query, I also append the “{resultset_is_needed = true}” flag, as you need to set this to “true” in order to get the resultset returned to the proxy.
In function read_query_result(), I assign all information to a variable, and then simply “print()” the variable. This does add a line of code, but in the end, it makes it easier to write this to an output file instead of to the terminal (or to both), if you desire.

Setting up MySQL Proxy as a Service on Windows

chris — Wed, 28 Oct 2009 00:36:34 +0000

In the newer versions of MySQL Proxy (0.7.2 and newer), it is now possible to create a Windows service for MySQL Proxy due to the inclusion of “mysql-proxy-svc.exe”.

Basically, you could use “mysql-proxy-svc.exe” in lieu of “mysql-proxy.exe” from the command line and you would not notice a difference. However, just invoking this will not create a service for MySQL Proxy. Furthermore, you cannot invoke it with the “–install” option as you can with mysqld.

But, you can create a service for MySQL Proxy using the “sc” command with “mysql-proxy-svc.exe”.

Say I want to create a service that starts automatically when my system is started/rebooted. I also want it to load a certain lua script, say capture-errors.lua. Given this, I would use the following command:

sc create "proxy" DisplayName= "MySQL Proxy" start= "auto"
binPath= "C:\Program Files\MySQL\mysql-proxy-0.7.2\bin\mysql-proxy-svc.exe
--proxy-lua-script=capture-errors.lua"

Here is the session from my console:

C:\Program Files\MySQL\mysql-proxy-0.7.2\bin>sc create "proxy"
DisplayName= "MySQL Proxy" start= "auto"
binPath= "C:\Program Files\MySQL\mysql-proxy-0.7.2\bin\mysql-proxy-svc.exe
--proxy-lua-script=capture-errors.lua"
[SC] CreateService SUCCESS

Once you have this set-up, you can easily start-up or shutdown the proxy. For instance, the following two commands will start and stop the proxy, respectively:

net start proxy
net stop proxy

Now, a couple of notes about the “sc create” statement:

This will create the service with the name of “proxy”.
I used a “start” type of “auto”. This will mean it will start up automatically when you reboot your system. If you remove that option, it will default to “manual”.
You need a space after each equal sign (=).
I had to use double-quotes (”) around each parameter value, as well as the service name, otherwise it wouldn’t create the service properly on my machine.
The lua script, capture-errors.lua, is located in the proxy basedir (C:\Program Files\MySQL\mysql-proxy-0.7.2\) and so it can be read from that location without a full path. If you have this in a different location, you would need to specify the full path.

If for some reason you want to delete this service, you can issue the following command (where “proxy” is the name of the service that you gave it using the above command):

sc delete proxy

And for more details on “sc”, please refer to the following Microsoft KB article:

http://support.microsoft.com/kb/251192

How to Recover Data using the InnoDB Recovery Tool

chris — Wed, 15 Apr 2009 20:13:34 +0000

As you may or may not know, there is a tool called the InnoDB Recovery Tool which can allow you to recover data from InnoDB tables that you cannot otherwise get the data from.

“This set of tools could be used to check InnoDB tablespaces and to recover data from damaged tablespaces or from dropped/truncated InnoDB tables.”

http://code.google.com/p/innodb-tools/

This is a very handy tool, however, the documentation on how to use it is a bit limited when it comes to actually recovering the data, so I thought I’d post a step-by-step tutorial on how to use this tool.

1. Download the InnoDB Recovery Tool (latest version is 0.3)

2. Unpack the download to the location of your choice

3. Create your table_defs.h file using the create_defs.pl script. Note the below creates a table_defs.h file based on only one table, t1, from the database named test:

cd innodb-recovery-tool-0.3/
./create_defs.pl --user=root --password=mysql --db=test --table=t1 > table_defs.h

4. Copy the newly created table_defs.h fle to the innodb-recovery-tool-0.3/include/ directory.

5. Now is time to build/compile the InnoDB Recovery Tool

cd innodb-recovery-tool-0.3/mysql-source/
./configure
cd ..
make

At this point, you’re almost ready to begin to recover the data. However, let me point out a couple items at this stage. The InnoDB Recovery Tool documentation says you can use the page_parser program to split up the tablespace. Since this page_parser program is now created (after compilation and make), you can use this to break apart the tablespace. However, in my case, I did this, but the page_parser didn’t work as well as I expected. This could be due to the corruption in the tablespace files (ibdata1 and ibdata2). So, I simply tried to recover based off the entire ibdata files. I found that I recovered much more data by just running the recovery against the ibdata files, rather than against the split-up pages. If you opt for this method, then you can skip steps 6, 7, and 8.

6. Should you want to use the page_parser, here is how you run it:

cd innodb-recovery-tool-0.3/
./page_parser -f /home/chris/Desktop/test/ibdata1 /home/chris/Desktop/test/ibdata2 -5

Note that the -f indicates the file(s) to use, and the -5 indicates the ibdata files are from MySQL version 5.0.

7. Should you use the page_parser, you must also load the ibdata file(s) and capture the InnoDB tablespace monitor output. This part is described on the InnoDB Tools how-to.

8. After running the above, you’ll want to capture all of the primary key index positions for each table you want to recover. For instance, you might see something like “0 135″ for the index position of a primary key. This will correspond to the folder named “0-135″ that is created by page_parser.

9. Now you are ready to recover the data for the first table.

(Note that you could create a table_defs.h file based on all of the tables you want to recover. And then you can recover all of the data at once, however, the problem with this is the data is all mis-matched into one big file. So you might have a row for one table followed by a row from another table. If you’re good with sed/awk, this might not be a problem for you, as you can then split it apart. However, it might be easier to create a single table_defs.h file for each table, and then recover the data table-by-table.)

If you want to recover the data based on the page_parser output, then you would use the following command:

./constraints_parser -f /home/chris/Desktop/innodb-recovery-0.3/pages-1239037839/0-135/50-00000050.page -5 -V

Note that the -V is for verbose mode. It is best to use this initially to make sure the data being recovered looks to be correct. Once you’ve verified it looks correct, then simply run the above command without the -V and pipe the output to a text file.

Should you not want to use the page_parser, and just run constraints_parser directly against the ibdata file(s), then issue the following command instead:

./constraints_parser -f /home/chris/Desktop/test/ibdata1 /home/chris/Desktop/test/ibdata2 -5 > output.txt

As for the recovered data itself, note that this data is displayed in a tab-delimited text format that the InnoDB Recovery tool dumps it in (default, not configurable yet).

For instance, here is a sample of data recovered for the t1 table:

t1 128992703 84118144 301989888 224000 33558272 268435456 ""
t1 0 0 34796032 0 530 838926338 ""
t1 1886545261 268455808 256 497 880803840 2949392 ""
t1 1398034253 1953654117 1952672116 2037609569 1952801647 1970173042 ""
t1 402667648 755047491 1431524431 1296388657 825372977 825308725 "5"
t1 536884352 755050563 1431524431 1296388658 842150450 842162531 "t"
t1 671103872 755053635 1431524431 1296388663 926365495 926365495 "77"
t1 524288 0 755056707 1431524431 1296388705 1668573558 ""
t1 524288 0 755059779 1431524431 1296388705 1668573558 ""
t1 524288 0 755062851 1431524431 1296388705 1668573558 ""
t1 525312 0 755065923 1431524431 1296388705 1668573558 ""
t1 524288 0 755068995 1431524431 1296388705 1668573558 ""
t1 524288 0 755072067 1431524431 1296388705 1668573558 ""
t1 524288 0 755075139 1431524431 1296388705 1668573558 ""
t1 525312 0 755078211 1431524431 1296388705 1668573558 ""
t1 524288 0 755081283 1431524431 1296388705 1668573558 ""
t1 524288 0 755084355 1431524431 1296388705 1668573558 ""
t1 524288 0 755047491 1431524431 1296388705 1668573558 ""
t1 524288 0 755047491 1431524431 1296388705 1668573558 ""
t1 0 0 0 0 0 0 ""
t1 0 0 0 0 0 0 ""
t1 0 0 0 0 0 0 ""
t1 0 0 0 0 0 0 ""
t1 0 0 0 0 0 0 ""

You can see each line is pre-pended with the table name (followed by a tab).

You can also see at the end (of the above output) there are a number of empty rows. These are just garbage rows, and can be deleted before you import or afterwards. You’ll see similar such rows in most of the recovered tables’ data as well. However, don’t just delete from the end of the file, as actual data rows are scattered all throughout the files.

I’d also suggest creating some temporary tables using the same CREATE TABLE commands but without any keys or indexes. This will allow you to import the data easier, and then you can clean it up with simple SQL commands. And after that, then you could simply add back your primary keys, indexes, and referential keys.

Should you follow my approach and do this per-table, then you just need to create your new table_defs.h file, re-compile and make, then re-run the constraints_parser just as you did above. Since it is built with the new table_defs.h file, it will now extract the data for this table, so no other changes need to be made.

10. Format the dump file(s) so that it can be imported into the appropriate table(s).

11. Import the data, and clean up the garbage rows.

12. Re-create any needed indexes and/or referential keys.

SHOW PROXY PROCESSLIST : Another Proxy Tutorial Revisited

chris — Wed, 15 Apr 2009 18:46:52 +0000

In a previous post, Another Proxy Tutorial, I outlined how you could find and display the originating IP address of a particular query from within MySQL Proxy.

This was a nice illustration of how to accomplish the above, however, in practice, there were a couple of limitations. For one, the queries were “tagged” with the originating IP address, so the query cache would only work for the same query coming from the same IP address. So if you’re using the query cache, then this is not an optimal solution. Secondly, you could only see the IP address for a current query, and not for an idle connection. Thus when issuing a SHOW PROCESSLIST command, one would only see the IP address only for actual queries that are being executed, and not for any of the other idle connections.

This was bothersome to me, so I worked up a better and more efficient solution that addresses both of these concerns.

In this new solution, I implement a new command called SHOW PROXY PROCESSLIST. This leaves SHOW PROCESSLIST output unchanged, and instead, if you want to see the originating IP address of the every connection listed in the SHOW PROCESSLIST output, then simply issue a SHOW PROXY PROCESSLIST command.

Here is an example of the output when using 3 different connections from differing IP addresses:

mysql> SHOW PROXY PROCESSLIST; SHOW PROCESSLIST;
+------+---------------------+-------------------+
| Id   | IP Address          | Time              |
+------+---------------------+-------------------+
| 2    | 127.0.0.1:49528     | 04/15/09 13:22:14 |
| 3    | 192.168.1.100:1322  | 04/15/09 13:22:23 |
| 4    | 192.168.1.103:59374 | 04/15/09 13:22:44 |
+------+---------------------+-------------------+
3 rows in set (0.00 sec)

+----+------+-----------------+------+---------+------+-------+------------------+
| Id | User | Host            | db   | Command | Time | State | Info             |
+----+------+-----------------+------+---------+------+-------+------------------+
|  1 | root | localhost:49526 | NULL | Sleep   |   13 |       | NULL             |
|  2 | root | localhost:49529 | NULL | Query   |    0 | NULL  | SHOW PROCESSLIST |
|  3 | root | localhost:49533 | NULL | Sleep   |   50 |       | NULL             |
|  4 | root | localhost:49547 | NULL | Sleep   |   18 |       | NULL             |
+----+------+-----------------+------+---------+------+-------+------------------+
4 rows in set (0.00 sec)

Here, you can see I simply called both commands in a single call.

The first output is the SHOW PROXY PROCESSLIST output. In it you can see the “Id” which corresponds to the “Id” in the SHOW PROCESSLIST output. You can also see the corresponding originating IP address along with the client source port, as well as the time stamp of when the connection was created.

To implement this, I simply capture and store the client address information in an internal table. I’m able to capture this from within the read_auth_result() function.

function read_auth_result( auth )
	local state = auth.packet:byte()
	if state == proxy.MYSQLD_PACKET_OK then
		initialize_process_table()
		table.insert( proxy.global.process[proxy.connection.server["thread_id"]],
			{ ip = proxy.connection.client["address"], ts = os.time() } )
	end
end

So when within the function read_auth_result(), if state == proxy.MYSQLD_PACKET_OK, then we know the connection was auth’ed, and hence I log this information at this point.

Note that I’m storing the value of proxy.connection.client["address"] which is the original IP address along with the client source port (e.g., 192.168.1.100:1322). The nice thing about this is you can track down the port information too on the original machine.

(Also note that in MySQL Proxy 0.7.0, there are even more available ports (variables), so you could add more to capture, say the client destination port, or the server source port. For more on this, pelase see Jan Kneschke’s post about this.)

On the remote machine (192.168.1.100), if I run the following command, I can track this connection via netstat:

netstat -an | grep 1322
tcp 0 0 192.168.1.100:1322 192.168.1.101:4050 ESTABLISHED

There is also another internal function to proxy that I use, which is disconnect_client(). This is called when a client disconnects, so if this function is entered for a particular connection, I simply delete that connection entry from the internal table.

function disconnect_client()
	local connection_id = proxy.connection.server.thread_id
	if connection_id then
		-- client has disconnected, set this to nil
		proxy.global.process[connection_id] = nil
	end
end

The rest of the code is basically to display this information in a nice format.

Here is the full code:

function read_query( packet )
	if string.byte(packet) == proxy.COM_QUERY then
		if string.sub(packet, 2):lower() == 'select help' then
			return show_process_help()
		end
		if string.sub(packet, 2):lower() == 'show proxy processlist' then
			return show_process_table()
		end
		--debug output
		--dump_process_table()
		proxy.queries:append(1, packet )
		return proxy.PROXY_SEND_QUERY
	end
end

function make_dataset (header, dataset)
	proxy.response.type = proxy.MYSQLD_PACKET_OK

	proxy.response.resultset = {
		fields = {},
		rows = {}
	}
	for i,v in pairs (header) do
		table.insert(proxy.response.resultset.fields, {type = proxy.MYSQL_TYPE_STRING, name = v})
	end
	for i,v in pairs (dataset) do
		table.insert(proxy.response.resultset.rows, v )
	end
	return proxy.PROXY_SEND_RESULT
end

function initialize_process_table()
	if proxy.global.process == nil then
		proxy.global.process= {}
	end
	if proxy.global.process [proxy.connection.server["thread_id"] ]== nil then
		proxy.global.process[proxy.connection.server["thread_id"] ]= {}
	end
end

function show_process_table()
	initialize_process_table()
	local dataset = {}
	local header = { 'Id', 'IP Address', 'Time' }
	local rows = {}
	for t_i, t_v in pairs (proxy.global.process) do
		for s_i, s_v in pairs ( t_v ) do
			table.insert(rows, { t_i, s_v.ip, os.date('%c',s_v.ts) })
		end
	end
	return make_dataset(header,rows)
end

function show_process_help()
	local dataset = {}
	local header = { 'command',  'description' }
	local rows = {
		{'SELECT HELP',                 'This command.'},
		{'SHOW PROXY PROCESSLIST',      'Show all connections and their true IP Address.'},
	}
	return make_dataset(header,rows)
end

function dump_process_table()
	initialize_process_table()
	print('current contents of process table')
	for t_i, t_v in pairs (proxy.global.process) do
		print ('session id: ', t_i)
		for s_i, s_v in pairs ( t_v ) do
			print ( '\t', s_i, s_v.ip, s_v.ts )
		end
	end
	print ('---END PROCESS TABLE---')
end

function read_auth_result( auth )
	local state = auth.packet:byte()
	if state == proxy.MYSQLD_PACKET_OK then
		initialize_process_table()
		table.insert( proxy.global.process[proxy.connection.server["thread_id"]],
			{ ip = proxy.connection.client["address"], ts = os.time() } )
	end
end

function disconnect_client()
	local connection_id = proxy.connection.server.thread_id
	if connection_id then
		-- client has disconnected, set this to nil
		proxy.global.process[connection_id] = nil
	end
end

If you saved this to a file named show-ips.lua, then you would start MySQL Proxy as follows:

mysql-proxy --proxy-lua-script=share/mysql-proxy/show-ips.lua

And then you would connect to the Proxy as follows:

mysql -u root -pmysql -P4040

After that, you’ll be able to issue the commands implemented here such as SHOW PROXY PROCESSLIST and SELECT HELP:

mysql> SELECT HELP;
+------------------------+-------------------------------------------------+
| command                | description                                     |
+------------------------+-------------------------------------------------+
| SELECT HELP            | This command.                                   |
| SHOW PROXY PROCESSLIST | Show all connections and their true IP Address. |
+------------------------+-------------------------------------------------+
2 rows in set (0.00 sec)

mysql> SHOW PROXY PROCESSLIST;
+------+---------------------+-------------------+
| Id   | IP Address          | Time              |
+------+---------------------+-------------------+
| 5    | 127.0.0.1:51128     | 04/15/09 14:09:42 |
| 6    | 192.168.1.100:2341  | 04/15/09 14:10:22 |
| 8    | 192.168.1.103:52722 | 04/15/09 14:18:49 |
+------+---------------------+-------------------+
3 rows in set (0.00 sec)

Lastly, note that you can easily integrate these functions to the quan.lua script that the Query Analyzer Proxy uses (for MySQL Enterprise Monitor).