Archive for the ‘Error’ Category

An elaborate way to break a MySQL server with XtraBackup

Май 22nd, 2012

XtraBackup is a great piece of software from Percona, which allows creating (nearly) lock-less MySQL/InnoDB backups. The tool has been around for quite some time and recently even received a major version bump. I have relied on it many times over the years. As it turns out, using it in some configurations may lead to heavy swapping or prevent MySQL from running queries.

So far I only kept complaining about the wrapper script XtraBackup has been distributed with and which was taken from Oracle’s InnoDB Hot Backup. The infamous innobackupex-1.5.1 was neither well written, nor was it even fully compatible with the XtraBackup’s feature set. This sometimes led to weird problems where there should not be any.

This time the problem can appear elsewhere. Mostly when one using the tool does not understand how it works in certain circumstances.

How does XtraBackup work?

In a few short words. XtraBackup performs two major tasks while it is running. The primary task is of course copying tablespaces, which constitutes the core of each backup. Because the process isn’t anything like making a point-in-time snapshot, it takes a significant amount of time as InnoDB files are sequentially read and written into another location one after another. There will always be transactions changing data in tables between when a backup started and when it ended. So in order to provide a fully consistent, point-in-time backup, XtraBackup has to work on another task. It follows and archives InnoDB transaction logs contents as new transactions commit while the process is running. The end result is an inconsistent backup of tablespaces and a transaction log that enables XtraBackup to fix the inconsistencies during prepare phase.

Streaming mode.

In many cases XtraBackup is used in streaming mode. It enables sending a backup straight over a network link into another system without storing any of the files on a database server itself. This is very useful for larger databases which may simply not fit two complete copies of data on available storage. It may be also useful for busy databases as it removes many disk I/Os that would otherwise be used for writing an archive to local disks.

However it is not entirely true that a streaming backup does not use any disk space on the source server:

–tmpdir=DIRECTORY
This option specifies the location where a temporary file will be stored. The option accepts a string argument. It should be used when –remote-host or –stream is specified. For these options, the transaction log will first be stored to a temporary file, before streaming or copying to a remote host. This option specifies the location where that temporary file will be stored. If the option is not specifed, the default is to use the value of tmpdir read from the server configuration.

A transaction log backup will always be written to the local storage first, even if it has to be shipped out elsewhere later.

The problem.

What if you want to run XtraBackup, but also have configured database to use memory-based storage for temporary space, e.g. tmpdir in my.cnf was set to /dev/shm or other location that mounts a tmpfs volume? Such configuration is often used to help performance when a lot of temporary tables are being created on disk. Assuming that you fail to notice the tmpdir option comment for XtraBackup, which is not actually very unlikely as I have seen very few people use it, you will be running a backup that by default (temporarily) archives the database transaction log into RAM.

If the option is not specifed, the default is to use the value of tmpdir read from the (MySQL) server configuration.

Given your database is sufficiently large and busy, or perhaps because you throttle XtraBackup, the backup process may run many hours. In several hours time the transaction logs can grow a lot, even by several gigabytes or more. By default a tmpfs volume that is these days automatically mounted by any Linux distribution can use up to 50% of RAM. As in practice no one really changes the limit from its default value, the transaction log archive can possibly also eat up to 50% of system’s memory. If RAM utilization on a server was high, and usually a mature database system uses even more than 90% of the available memory, it could eventually end up like this:

Swapping. When it happens a database server that is under any real load essentially stops responding. In this case it may not even matter whether it is MySQL instance memory being paged out or perhaps tmpfs volume contents.

At the same time the memory volume contents would look like this:

garfield ~ # ls -lh /dev/shm/
-rw-r--r--  1 root root   75 05-22 09:08 mysql-stderr
-rw-r--r--  1 root root  226 05-22 09:08 mysql-stdout
-rw-r--r--  1 root root   2G 05-22 09:08 xtrabackup_logfile
More problems.

The above does not have to be the only problem. Regardless of what MySQL uses for its temporary directory, if the storage is too small (e.g. some use a few gigabytes large /tmp partition), more bad things can happen.

If it gets full during backup, MySQL will not be able to run any queries that rely on temporary files, e.g. some that use GROUP BY or ORDER BY:

mysql> SELECT * FROM sbtest ORDER BY pad DESC LIMIT 5;
ERROR 3 (HY000): Error writing file '/dev/shm/MYJee0PR' (Errcode: 28)
mysql> Bye
garfield ~ # perror 28
OS error code  28:  No space left on device

Another problem that I spotted was that XtraBackup continued performing backup even after it noticed and reported that one of its writes failed. This is clearly a bug, which permits creation of a broken backup.

innobackupex-1.5.1: Backing up file '/var/lib/mysql/sbtest/sbtest.ibd'
>> log scanned up to (1 4052543506)
>> log scanned up to (1 4052543506)
>> log scanned up to (1 4052543506)
write: 65536 > 2048
xtrabackup: Error: write to stdout
xtrabackup: Error: xtrabackup_copy_logfile() failed.
innobackupex-1.5.1: Backing up file '/var/lib/mysql/sbtest/sbtest2.ibd'
[..]
xtrabackup: The latest check point (for incremental): '1:4115657100'
xtrabackup: Error: log_copying_thread failed.
120522 13:16:19  innobackupex-1.5.1: All tables unlocked
120522 13:16:19  innobackupex-1.5.1: Connection to database server closed

innobackupex-1.5.1: Backup created in directory '/root/backup'
innobackupex-1.5.1: MySQL binlog position: filename 'mysqld-bin.000067', position 107090
120522 13:16:19  innobackupex-1.5.1: completed OK!
innobackupex-1.5.1: You must use -i (--ignore-zeros) option for extraction of the tar stream.
garfield backup # echo $?
0
Conclusions.

Be careful when implementing streaming backup with XtraBackup. Make sure to check where it will store its temporary files as they may grow relatively large or even better always explicitly set tmpdir in the command line.

This problem also raises another important matter. If you configure a MySQL server to use a RAM based volume for a database temporary storage, make sure to tune tmpfs volume configuration rather than leave it with the default limit of 50%.


PlanetMySQL Voting: Vote UP / Vote DOWN

How To – Fix MySQL Option Without Preceding Group

Май 8th, 2012

Background Knowledge


You try starting, stopping or connecting to MySQL and receive the following error, “Error: Found option without preceding group in config file: /etc/mysql/conf.d/char_collation_set.cnf at line: 1″. The error message my vary but comes to the same issue. MySQL may not start or might experience connectivity issues.

This issue was experienced on Debian Squeeze v6.04 AMD64 system with MySQL v14.14 Distrib 5.1.61.

Solution


This issue is caused by a improperly formatted MySQL configuration file(s) and refers to one missing the group heading (e.g. [mysqld], [mysqld_safe], etc.).

Source: MySQL 5.1 Reference Manual :: 4.2.3.3. Using Option Files
Source: [Solved] Mysql won’t start. my.cnf problem.


PlanetMySQL Voting: Vote UP / Vote DOWN

Running out of disk space on MySQL partition? A quick rescue.

Май 7th, 2012

No space left on device – this can happen to anyone. Sooner or later you may face the situation where a database either has already or is only minutes away from running out of disk space. What many people do in such cases, they just start looking for semi-random things to remove – perhaps a backup, a few older log files, or pretty much anything that seems redundant. However this means acting under a lot of stress and without much thinking, so it would be great if there was a possibility to avoid that. Often there is. Or what if there isn’t anything to remove?

While xfs is usually the recommended filesystem for a MySQL data partition on Linux, the extended filesystem family continues to be very popular as it is used as default in all major Linux distributions. There is a feature specific to ext3 and ext4 that can help the goal of resolving the full disk situation.

Unless explicitly changed during filesystem creation, both by default reserve five percent of a volume capacity to the superuser (root). It helps preventing non-privileged processes from filling up all disk, leaving no room for system logging or system applications. However such reservation only makes sense for the system volumes, while MySQL often sits on its own, dedicated partition, so there is no real reason to keep any number of blocks away from it.

So if your database files are stored on a partition formatted with ext3 or ext4 and MySQL runs out of disk space, you may be in luck as there may be some extra capacity the database may be able to use.

How to enable it?

I had a server that ran out of space on the MySQL volume. The system was reporting 5.7M free and MySQL essentially blocked waiting on the opportunity to complete the writes:

[root@db4 ~]# df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/mapper/vg_centos-lv_root
                       30G   25G  3.4G  89% /
tmpfs                 3.9G     0  3.9G   0% /dev/shm
/dev/sda1             243M   47M  183M  21% /boot
/dev/mapper/vg_centos-lv_mysql
                      145G  145G  5.7M 100% /vol/mysql

A quick verification of the filesystem used for that volume:

[root@db4 ~]# mount
[..]
/dev/mapper/vg_centos-lv_mysql on /vol/mysql type ext4 (rw,noatime,nodiratime)

As the next step, I had to verify if the volume had any reserved blocks that could be freed. I have not seen many servers that actually had the default setting changed during the installation process, so in many cases there should be something:

[root@db4 ~]# dumpe2fs /dev/mapper/vg_centos-lv_mysql | grep 'Reserved block count'
dumpe2fs 1.41.12 (17-May-2010)
Reserved block count: 1927884

It turned out 1927884 of 4KB blocks were reserved for the superuser, which was exactly five percent of the volume capacity. I was able to free this space and make it available to MySQL:

[root@db4 ~]# tune2fs -m 0 /dev/mapper/vg_centos-lv_mysql
tune2fs 1.41.12 (17-May-2010)
Setting reserved blocks percentage to 0% (0 blocks)

This works instantaneously. Simply applications start to see more disk space available.

[root@db4 ~]# df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/mapper/vg_centos-lv_root
                       30G   25G  3.4G  89% /
tmpfs                 3.9G     0  3.9G   0% /dev/shm
/dev/sda1             243M   47M  183M  21% /boot
/dev/mapper/vg_centos-lv_mysql
                      145G  145G  7.3G  95% /vol/mysql

Without removing a single file I managed to create over seven gigabytes of free space that allowed MySQL to resume operations. That didn’t solve the problem entirely, but it got me a lot of time to figure out a long term solution.

The method is a quick remedy for the emergency situation when your database runs out of disk space. I used it numerous times while helping many people to solve such problems. Of course, it is not a proper solution, but rather something that buys you time to figure out the options. As it only works once in a system lifetime, because after you remove the entire reservation, there would not be anything to remove if the server ran out of space for the second time, you should make sure to avoid facing such problem twice. Learn your lesson and work on implementing proper monitoring to alert you early enough.


PlanetMySQL Voting: Vote UP / Vote DOWN

Running out of disk space on MySQL partition? A quick rescue.

Май 7th, 2012

No space left on device – this can happen to anyone. Sooner or later you may face the situation where a database either has already or is only minutes away from running out of disk space. What many people do in such cases, they just start looking for semi-random things to remove – perhaps a backup, a few older log files, or pretty much anything that seems redundant. However this means acting under a lot of stress and without much thinking, so it would be great if there was a possibility to avoid that. Often there is. Or what if there isn’t anything to remove?

While xfs is usually the recommended filesystem for a MySQL data partition on Linux, the extended filesystem family continues to be very popular as it is used as default in all major Linux distributions. There is a feature specific to ext3 and ext4 that can help the goal of resolving the full disk situation.

Unless explicitly changed during filesystem creation, both by default reserve five percent of a volume capacity to the superuser (root). It helps preventing non-privileged processes from filling up all disk, leaving no room for system logging or system applications. However such reservation only makes sense for the system volumes, while MySQL often sits on its own, dedicated partition, so there is no real reason to keep any number of blocks away from it.

So if your database files are stored on a partition formatted with ext3 or ext4 and MySQL runs out of disk space, you may be in luck as there may be some extra capacity the database may be able to use.

How to enable it?

I had a server that ran out of space on the MySQL volume. The system was reporting 5.7M free and MySQL essentially blocked waiting on the opportunity to complete the writes:

[root@db4 ~]# df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/mapper/vg_centos-lv_root
                       30G   25G  3.4G  89% /
tmpfs                 3.9G     0  3.9G   0% /dev/shm
/dev/sda1             243M   47M  183M  21% /boot
/dev/mapper/vg_centos-lv_mysql
                      145G  145G  5.7M 100% /vol/mysql

A quick verification of the filesystem used for that volume:

[root@db4 ~]# mount
[..]
/dev/mapper/vg_centos-lv_mysql on /vol/mysql type ext4 (rw,noatime,nodiratime)

As the next step, I had to verify if the volume had any reserved blocks that could be freed. I have not seen many servers that actually had the default setting changed during the installation process, so in many cases there should be something:

[root@db4 ~]# dumpe2fs /dev/mapper/vg_centos-lv_mysql | grep 'Reserved block count'
dumpe2fs 1.41.12 (17-May-2010)
Reserved block count: 1927884

It turned out 1927884 of 4KB blocks were reserved for the superuser, which was exactly five percent of the volume capacity. I was able to free this space and make it available to MySQL:

[root@db4 ~]# tune2fs -m 0 /dev/mapper/vg_centos-lv_mysql
tune2fs 1.41.12 (17-May-2010)
Setting reserved blocks percentage to 0% (0 blocks)

This works instantaneously. Simply applications start to see more disk space available.

[root@db4 ~]# df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/mapper/vg_centos-lv_root
                       30G   25G  3.4G  89% /
tmpfs                 3.9G     0  3.9G   0% /dev/shm
/dev/sda1             243M   47M  183M  21% /boot
/dev/mapper/vg_centos-lv_mysql
                      145G  145G  7.3G  95% /vol/mysql

Without removing a single file I managed to create over seven gigabytes of free space that allowed MySQL to resume operations. That didn’t solve the problem entirely, but it got me a lot of time to figure out a long term solution.

The method is a quick remedy for the emergency situation when your database runs out of disk space. I used it numerous times while helping many people to solve such problems. Of course, it is not a proper solution, but rather something that buys you time to figure out the options. As it only works once in a system lifetime, because after you remove the entire reservation, there would not be anything to remove if the server ran out of space for the second time, you should make sure to avoid facing such problem twice. Learn your lesson and work on implementing proper monitoring to alert you early enough.


PlanetMySQL Voting: Vote UP / Vote DOWN

Why a statement can be unsafe when it uses LIMIT clause?

Апрель 17th, 2012

MySQL 5.1 or newer can sometimes start throwing a strange message into an error log. The message states that a query was unsafe for binary logging along with some additional information. What does it mean? Is it a problem?

From time to time you might spot MySQL error log filling with the following warning:

“[Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. The statement is unsafe because it uses a LIMIT clause. This is unsafe because the set of rows included cannot be predicted. Statement: DELETE FROM score WHERE user_id = 12345 AND created = ’2012-04-15′ LIMIT 1″

If binary logging is enabled and the log format is set to STATEMENT, MySQL generates such message when it considers that a query is ambiguous and could behave differently each time it executes against the same data set. Such situation could happen, for example, on a replication slave, or on a restored backup where binary logs are used for point-in-time recovery.

Why? The reason lies in the relational database theory, which defines table as a set of rows, while a set does not assume any particular order. What if there were a few rows matching user_id = 12345 and created = '2012-04-15'? Well, in theory, such DELETE statement could read and remove a different row each time, because if all share the same values in user_id and created, how to decide which one comes first or last? Of course, a database implementation, such as MySQL, typically relies on some implicit order even if the theory behind it does not. But then again, there may be a different problem. Even if MySQL uses some implicit sort order for storing rows, does it guarantee the order is always the same? No.

On master and slave rows can be stored in different order

Two rows appear in different order on Master and Slave. The two databases are still identical from the SQL point of view, although the way they organized data is different. Now, if our statement started deleting rows from the top, it would remove two different rows from each instance and the two databases would drift out of sync. This is what MySQL is warning you about by saying This is unsafe because the set of rows included cannot be predicted. The problem does not exist when there is no LIMIT clause, because then MySQL simply removes all rows matching the criteria and it does not matter to the final result in which order it does that.

So is seeing such warning message a problem? Definitely not, if binary logs aren’t used for anything – not replication, not recovery. Otherwise the answer would have to be yes, although it does not imply there is anything wrong with the data already. And although chances are that nothing bad will happen even when MySQL keeps complaining, you should never rely on luck – fix the problem.

The real option to address this is moving to either MIXED or ROW format for binary logging, which is defined in binlog_format MySQL option. And what is cool, it can also be set at runtime with SET (for current session only) or SET GLOBAL (globally), so no restart is even necessary. However don’t rush to change it just yet. Be sure to read and understand what the differences between all these formats are first as making this change might break something that your applications rely on. But in the end, although it seems like a nasty workaround, it’s even possible to use ROW format for just one specific query by using the following sequence:

SET SESSION binlog_format = ROW;
DELETE ...;
SET SESSION binlog_format = STATEMENT;

An alternative approach to alleviate the potential problem could increasing the chances the same row gets chosen, however it can only be done under the assumption that all instances contain identical data.

To make the example a little bit more complete, here is the query again along with the underlying data structure:

DELETE FROM score WHERE user_id = 12345 AND created = '2012-04-15' LIMIT 1

CREATE TABLE `score` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`user_id` int(11) NOT NULL,
`created` date NOT NULL,
`score` int(11) NOT NULL,
[..]
PRIMARY KEY (`id`),
KEY `user_id` (`user_id`, `created`)
)

If data on master and slave is identical, to prevent potential problems, one could use ORDER BY on a unique column, such as id for example. That could help ensuring that such query would always pick the youngest or the oldest row out of the matching ones. There should be no confusion anymore as the order would be always the same regardless of the circumstances. Again, this may fail to work if some instances involved are not identical to others (e.g. master keeps only recent data, while some slave holds the full archive).

The modified query would look like this:

DELETE FROM score WHERE user_id = 12345 AND created = '2012-04-15' ORDER BY id ASC LIMIT 1

The warning message discussed in this articles isn’t necessarily a nasty problem that needs urgent attention, however it might be a sign of problems ahead. It is definitely worth an investigation to verify whether it may or may not be causing any damage to data. A fix is relatively trivial, although it should be done carefully and with analysis of the possible consequences of implementing the changes.


PlanetMySQL Voting: Vote UP / Vote DOWN

Why a statement can be unsafe when it uses LIMIT clause?

Апрель 17th, 2012

MySQL 5.1 or newer can sometimes start throwing a strange message into an error log. The message states that a query was unsafe for binary logging along with some additional information. What does it mean? Is it a problem?

From time to time you might spot MySQL error log filling with the following warning:

“[Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. The statement is unsafe because it uses a LIMIT clause. This is unsafe because the set of rows included cannot be predicted. Statement: DELETE FROM score WHERE user_id = 12345 AND created = ’2012-04-15′ LIMIT 1″

If binary logging is enabled and the log format is set to STATEMENT, MySQL generates such message when it considers that a query is ambiguous and could behave differently each time it executes against the same data set. Such situation could happen, for example, on a replication slave, or on a restored backup where binary logs are used for point-in-time recovery.

Why? The reason lies in the relational database theory, which defines table as a set of rows, while a set does not assume any particular order. What if there were a few rows matching user_id = 12345 and created = '2012-04-15'? Well, in theory, such DELETE statement could read and remove a different row each time, because if all share the same values in user_id and created, how to decide which one comes first or last? Of course, a database implementation, such as MySQL, typically relies on some implicit order even if the theory behind it does not. But then again, there may be a different problem. Even if MySQL uses some implicit sort order for storing rows, does it guarantee the order is always the same? No.

On master and slave rows can be stored in different order

Two rows appear in different order on Master and Slave. The two databases are still identical from the SQL point of view, although the way they organized data is different. Now, if our statement started deleting rows from the top, it would remove two different rows from each instance and the two databases would drift out of sync. This is what MySQL is warning you about by saying This is unsafe because the set of rows included cannot be predicted. The problem does not exist when there is no LIMIT clause, because then MySQL simply removes all rows matching the criteria and it does not matter to the final result in which order it does that.

So is seeing such warning message a problem? Definitely not, if binary logs aren’t used for anything – not replication, not recovery. Otherwise the answer would have to be yes, although it does not imply there is anything wrong with the data already. And although chances are that nothing bad will happen even when MySQL keeps complaining, you should never rely on luck – fix the problem.

The real option to address this is moving to either MIXED or ROW format for binary logging, which is defined in binlog_format MySQL option. And what is cool, it can also be set at runtime with SET (for current session only) or SET GLOBAL (globally), so no restart is even necessary. However don’t rush to change it just yet. Be sure to read and understand what the differences between all these formats are first as making this change might break something that your applications rely on. But in the end, although it seems like a nasty workaround, it’s even possible to use ROW format for just one specific query by using the following sequence:

SET SESSION binlog_format = ROW;
DELETE ...;
SET SESSION binlog_format = STATEMENT;

An alternative approach to alleviate the potential problem could increasing the chances the same row gets chosen, however it can only be done under the assumption that all instances contain identical data.

To make the example a little bit more complete, here is the query again along with the underlying data structure:

DELETE FROM score WHERE user_id = 12345 AND created = '2012-04-15' LIMIT 1

CREATE TABLE `score` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`user_id` int(11) NOT NULL,
`created` date NOT NULL,
`score` int(11) NOT NULL,
[..]
PRIMARY KEY (`id`),
KEY `user_id` (`user_id`, `created`)
)

If data on master and slave is identical, to prevent potential problems, one could use ORDER BY on a unique column, such as id for example. That could help ensuring that such query would always pick the youngest or the oldest row out of the matching ones. There should be no confusion anymore as the order would be always the same regardless of the circumstances. Again, this may fail to work if some instances involved are not identical to others (e.g. master keeps only recent data, while some slave holds the full archive).

The modified query would look like this:

DELETE FROM score WHERE user_id = 12345 AND created = '2012-04-15' ORDER BY id ASC LIMIT 1

The warning message discussed in this articles isn’t necessarily a nasty problem that needs urgent attention, however it might be a sign of problems ahead. It is definitely worth an investigation to verify whether it may or may not be causing any damage to data. A fix is relatively trivial, although it should be done carefully and with analysis of the possible consequences of implementing the changes.


PlanetMySQL Voting: Vote UP / Vote DOWN

Lost connection to MySQL server during query

Апрель 5th, 2012

From time to time, when an application runs a query in MySQL, it may receive various errors. Some are related to syntax errors in the query text itself, some occur because the statement attempted an illegal operation such as for example writing a duplicate value into a column with unique constraint. But there are a few that are not as easy to figure out, because they have no direct relationship with the actual work being done. One of such error messages reads “Lost connection to MySQL server during query”. What does it actually mean? If it appears frequently, how to diagnose what the problem may be?

The first thing to know about the “Lost connection to MySQL server during query” message is that this is not a MySQL error. It is a MySQL client error. The difference may seem subtle, but it is significant. A MySQL error would be a problem reported by database server, i.e. handling a query did not succeed, because the server decided it couldn’t be done. A client error, on the other hand, is generated by application itself, or one of its modules in this case, for reasons that are beyond the MySQL server’s control. That’s why this error message won’t be seen anywhere on the server.

“Lost connection to MySQL server during query” occurs when application establishes connection to MySQL, sends a query, but then does not hear back from the server before the connection is closed. In other words, a query was already sent when from the client’s point of view the database disappeared.

What are the common reasons?

  1. A connection was killed by MySQL: Typically because someone or something ran KILL thread_id command. If there are any daemons monitoring database for idle connections, such as for example pt-kill script, there could be a race condition, where a thread was qualified for killing due to long idle time, but shortly before it happened, a query arrived. The error would also happen when a long running query was killed.
  2. MySQL was shut down or crashed while query was being executed: Check both application and database error logs and compare timestamps of these evens on either side.
  3. A network problem occurred: However unlikely, something between the client system and the server system may cause the connection to be interrupted. Usually verifying this problem is next to impossible.

In many cases, however, diagnosing the root cause for this error message may prove to be difficult. And the more difficult the less control you have over the software environment and the infrastructure in which your applications and databases work. There is probably nothing to worry about if this only happens occasionally, but seeing this more frequently, on a regular basis, should be a cause for concern.


PlanetMySQL Voting: Vote UP / Vote DOWN

Lost connection to MySQL server during query

Апрель 5th, 2012

From time to time, when an application runs a query in MySQL, it may receive various errors. Some are related to syntax errors in the query text itself, some occur because the statement attempted an illegal operation such as for example writing a duplicate value into a column with unique constraint. But there are a few that are not as easy to figure out, because they have no direct relationship with the actual work being done. One of such error messages reads “Lost connection to MySQL server during query”. What does it actually mean? If it appears frequently, how to diagnose what the problem may be?

The first thing to know about the “Lost connection to MySQL server during query” message is that this is not a MySQL error. It is a MySQL client error. The difference may seem subtle, but it is significant. A MySQL error would be a problem reported by database server, i.e. handling a query did not succeed, because the server decided it couldn’t be done. A client error, on the other hand, is generated by application itself, or one of its modules in this case, for reasons that are beyond the MySQL server’s control. That’s why this error message won’t be seen anywhere on the server.

“Lost connection to MySQL server during query” occurs when application establishes connection to MySQL, sends a query, but then does not hear back from the server before the connection is closed. In other words, a query was already sent when from the client’s point of view the database disappeared.

What are the common reasons?

  1. A connection was killed by MySQL: Typically because someone or something ran KILL thread_id command. If there are any daemons monitoring database for idle connections, such as for example pt-kill script, there could be a race condition, where a thread was qualified for killing due to long idle time, but shortly before it happened, a query arrived. The error would also happen when a long running query was killed.
  2. MySQL was shut down or crashed while query was being executed: Check both application and database error logs and compare timestamps of these evens on either side.
  3. A network problem occurred: However unlikely, something between the client system and the server system may cause the connection to be interrupted. Usually verifying this problem is next to impossible.

In many cases, however, diagnosing the root cause for this error message may prove to be difficult. And the more difficult the less control you have over the software environment and the infrastructure in which your applications and databases work. There is probably nothing to worry about if this only happens occasionally, but seeing this more frequently, on a regular basis, should be a cause for concern.


PlanetMySQL Voting: Vote UP / Vote DOWN

MySQL 5.6 too verbose when creating data directory

Март 18th, 2012

When I install a MySQL package using MySQL Sandbox, if everything goes smoothly, I get an informative message on standard output, and I keep working.

This is OK


$HOME/opt/mysql/5.5.15/scripts/mysql_install_db --no-defaults \
--user=$USER --basedir=$HOME/opt/mysql/5.5.15 \
--datadir=$HOME/sandboxes/msb_5_5_15/data \
--lower_case_table_names=2
Installing MySQL system tables...
OK
Filling help tables...
OK

To start mysqld at boot time you have to copy
support-files/mysql.server to the right place for your system

PLEASE REMEMBER TO SET A PASSWORD FOR THE MySQL root USER !
To do so, start the server, then issue the following commands:

/Users/gmax/opt/mysql/5.5.15/bin/mysqladmin -u root password 'new-password'
/Users/gmax/opt/mysql/5.5.15/bin/mysqladmin -u root -h gmac4.local password 'new-password'

Alternatively you can run:
/Users/gmax/opt/mysql/5.5.15/bin/mysql_secure_installation

which will also give you the option of removing the test
databases and anonymous user created by default. This is
strongly recommended for production servers.

See the manual for more instructions.

You can start the MySQL daemon with:
cd /Users/gmax/opt/mysql/5.5.15 ; /Users/gmax/opt/mysql/5.5.15/bin/mysqld_safe &

You can test the MySQL daemon with mysql-test-run.pl
cd /Users/gmax/opt/mysql/5.5.15/mysql-test ; perl mysql-test-run.pl

Please report any problems with the /Users/gmax/opt/mysql/5.5.15/scripts/mysqlbug script!
I can actually suppress this output, confident that, if something goes wrong, the error comes to my screen loud and clear. For example, if I try to install to a data directory that is write protected, I get this:

chmod 444 $HOME/sandboxes/msb_5_5_15/data
$HOME/opt/mysql/5.5.15/scripts/mysql_install_db --no-defaults \
--user=$USER --basedir=$HOME/opt/mysql/5.5.15 \
--datadir=$HOME/sandboxes/msb_5_5_15/data \
--lower_case_table_names=2 > /dev/null

mkdir: /Users/gmax/sandboxes/msb_5_5_15/data: Permission denied
chmod: /Users/gmax/sandboxes/msb_5_5_15/data: Permission denied
chown: /Users/gmax/sandboxes/msb_5_5_15/data: Permission denied
This, way, I know that there was an error, it is very clear and readable. I don't need to hunt it down within the regular messages. The standard error is a separate file descriptor, which can be read independently from the standard input.

After fixing permissions:


chmod 755 ~/sandboxes/msb_5_5_15/
$HOME/opt/mysql/5.5.15/scripts/mysql_install_db --no-defaults \
--user=$USER --basedir=$HOME/opt/mysql/5.5.15 \
--datadir=$HOME/sandboxes/msb_5_5_15/data \
--lower_case_table_names=2 > /dev/null
# empty line: means all OK

This is very convenient, and it is the Unix way.

This is not OK

Now, let's try the same with MySQL 5.6


$BASEDIR/scripts/mysql_install_db --no-defaults --user=tungsten \
--basedir=$BASEDIR --datadir=/home/tungsten/sandboxes/msb_5_6_4/data \
--tmpdir=/home/tungsten/sandboxes/msb_5_6_4/tmp > /dev/null
120318 10:10:44 InnoDB: The InnoDB memory heap is disabled
120318 10:10:44 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120318 10:10:44 InnoDB: Compressed tables use zlib 1.2.3
120318 10:10:44 InnoDB: Using Linux native AIO
120318 10:10:44 InnoDB: CPU supports crc32 instructions
120318 10:10:44 InnoDB: Initializing buffer pool, size = 128.0M
120318 10:10:44 InnoDB: Completed initialization of buffer pool
InnoDB: The first specified data file ./ibdata1 did not exist:
InnoDB: a new database to be created!
120318 10:10:44 InnoDB: Setting file ./ibdata1 size to 10 MB
InnoDB: Database physically writes the file full: wait...
120318 10:10:44 InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 5 MB
InnoDB: Database physically writes the file full: wait...
120318 10:10:44 InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 5 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Doublewrite buffer not found: creating new
InnoDB: Doublewrite buffer created
120318 10:10:44 InnoDB: 128 rollback segment(s) are active.
InnoDB: Creating foreign key constraint system tables
InnoDB: Foreign key constraint system tables created
120318 10:10:44 InnoDB: 1.2.4 started; log sequence number 0
120318 10:10:44 [Warning] Info table is not ready to be used. Table 'mysql.slave_master_info' cannot be opened.
120318 10:10:44 [Warning] Error while checking replication metadata. Setting the requested repository in order to give users the chance to fix the problem and restart the server. If this is a live upgrade please consider using mysql_upgrade to fix the problem.
120318 10:10:44 [Warning] Info table is not ready to be used. Table 'mysql.slave_relay_log_info' cannot be opened.
120318 10:10:44 [Warning] Error while checking replication metadata. Setting the requested repository in order to give users the chance to fix the problem and restart the server. If this is a live upgrade please consider using mysql_upgrade to fix the problem.
120318 10:10:44 [Note] Binlog end
120318 10:10:44 [Note] Shutting down plugin 'partition'
120318 10:10:44 [Note] Shutting down plugin 'ARCHIVE'
120318 10:10:44 [Note] Shutting down plugin 'BLACKHOLE'
120318 10:10:44 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_DELETED'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_INSERTED'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_METRICS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMPMEM'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMP_RESET'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMP'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_LOCKS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_TRX'
120318 10:10:44 [Note] Shutting down plugin 'InnoDB'
120318 10:10:44 InnoDB: FTS optimize thread exiting.
120318 10:10:44 InnoDB: Starting shutdown...
120318 10:10:46 InnoDB: Shutdown completed; log sequence number 1602841
120318 10:10:46 [Note] Shutting down plugin 'CSV'
120318 10:10:46 [Note] Shutting down plugin 'MEMORY'
120318 10:10:46 [Note] Shutting down plugin 'MyISAM'
120318 10:10:46 [Note] Shutting down plugin 'MRG_MYISAM'
120318 10:10:46 [Note] Shutting down plugin 'mysql_old_password'
120318 10:10:46 [Note] Shutting down plugin 'mysql_native_password'
120318 10:10:46 [Note] Shutting down plugin 'binlog'
120318 10:10:46 InnoDB: The InnoDB memory heap is disabled
120318 10:10:46 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120318 10:10:46 InnoDB: Compressed tables use zlib 1.2.3
120318 10:10:46 InnoDB: Using Linux native AIO
120318 10:10:46 InnoDB: CPU supports crc32 instructions
120318 10:10:46 InnoDB: Initializing buffer pool, size = 128.0M
120318 10:10:46 InnoDB: Completed initialization of buffer pool
120318 10:10:46 InnoDB: highest supported file format is Barracuda.
120318 10:10:46 InnoDB: 128 rollback segment(s) are active.
120318 10:10:46 InnoDB: Waiting for the background threads to start
120318 10:10:47 InnoDB: 1.2.4 started; log sequence number 1602841
120318 10:10:47 [Note] Binlog end
120318 10:10:47 [Note] Shutting down plugin 'partition'
120318 10:10:47 [Note] Shutting down plugin 'ARCHIVE'
120318 10:10:47 [Note] Shutting down plugin 'BLACKHOLE'
120318 10:10:47 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_DELETED'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_INSERTED'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_METRICS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMPMEM'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMP_RESET'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMP'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_LOCKS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_TRX'
120318 10:10:47 [Note] Shutting down plugin 'InnoDB'
120318 10:10:47 InnoDB: FTS optimize thread exiting.
120318 10:10:47 InnoDB: Starting shutdown...
120318 10:10:49 InnoDB: Shutdown completed; log sequence number 1602851
120318 10:10:49 [Note] Shutting down plugin 'CSV'
120318 10:10:49 [Note] Shutting down plugin 'MEMORY'
120318 10:10:49 [Note] Shutting down plugin 'MyISAM'
120318 10:10:49 [Note] Shutting down plugin 'MRG_MYISAM'
120318 10:10:49 [Note] Shutting down plugin 'mysql_old_password'
120318 10:10:49 [Note] Shutting down plugin 'mysql_native_password'
120318 10:10:49 [Note] Shutting down plugin 'binlog'
Why is this bad? Because you don't see at a glance what is right and what is wrong. All the above messages are printed to the standard error, the kind of output that should be reserved for, well, errors! If the standard error is used for regular messages, you may miss the important error messages that are instead mixed with the "all is OK" messages.

There is Bug#60934 filed about this issue, but it has been considered a feature request, and as such unlikely to be fixed.

In the above text there is something more. There are warnings, mixed with the standard text, telling me of errors that the bootstrap operation is not in a position to fix, like replication metadata and slave_master_info.

MySQL developers, please fix this issue. Users need error messages when there is something wrong, and warning or error messages about something that can actually be fixed. When MySQL 5.6 goes GA, this issue will hit most everybody.

PlanetMySQL Voting: Vote UP / Vote DOWN

MySQL 5.6 too verbose when creating data directory

Март 18th, 2012
When I install a MySQL package using MySQL Sandbox, if everything goes smoothly, I get an informative message on standard output, and I keep working.

This is OK


$HOME/opt/mysql/5.5.15/scripts/mysql_install_db --no-defaults \
--user=$USER --basedir=$HOME/opt/mysql/5.5.15 \
--datadir=$HOME/sandboxes/msb_5_5_15/data \
--lower_case_table_names=2
Installing MySQL system tables...
OK
Filling help tables...
OK

To start mysqld at boot time you have to copy
support-files/mysql.server to the right place for your system

PLEASE REMEMBER TO SET A PASSWORD FOR THE MySQL root USER !
To do so, start the server, then issue the following commands:

/Users/gmax/opt/mysql/5.5.15/bin/mysqladmin -u root password 'new-password'
/Users/gmax/opt/mysql/5.5.15/bin/mysqladmin -u root -h gmac4.local password 'new-password'

Alternatively you can run:
/Users/gmax/opt/mysql/5.5.15/bin/mysql_secure_installation

which will also give you the option of removing the test
databases and anonymous user created by default. This is
strongly recommended for production servers.

See the manual for more instructions.

You can start the MySQL daemon with:
cd /Users/gmax/opt/mysql/5.5.15 ; /Users/gmax/opt/mysql/5.5.15/bin/mysqld_safe &

You can test the MySQL daemon with mysql-test-run.pl
cd /Users/gmax/opt/mysql/5.5.15/mysql-test ; perl mysql-test-run.pl

Please report any problems with the /Users/gmax/opt/mysql/5.5.15/scripts/mysqlbug script!
I can actually suppress this output, confident that, if something goes wrong, the error comes to my screen loud and clear. For example, if I try to install to a data directory that is write protected, I get this:

chmod 444 $HOME/sandboxes/msb_5_5_15/data
$HOME/opt/mysql/5.5.15/scripts/mysql_install_db --no-defaults \
--user=$USER --basedir=$HOME/opt/mysql/5.5.15 \
--datadir=$HOME/sandboxes/msb_5_5_15/data \
--lower_case_table_names=2 > /dev/null

mkdir: /Users/gmax/sandboxes/msb_5_5_15/data: Permission denied
chmod: /Users/gmax/sandboxes/msb_5_5_15/data: Permission denied
chown: /Users/gmax/sandboxes/msb_5_5_15/data: Permission denied
This, way, I know that there was an error, it is very clear and readable. I don't need to hunt it down within the regular messages. The standard error is a separate file descriptor, which can be read independently from the standard input.After fixing permissions:

chmod 755 ~/sandboxes/msb_5_5_15/
$HOME/opt/mysql/5.5.15/scripts/mysql_install_db --no-defaults \
--user=$USER --basedir=$HOME/opt/mysql/5.5.15 \
--datadir=$HOME/sandboxes/msb_5_5_15/data \
--lower_case_table_names=2 > /dev/null
# empty line: means all OK
This is very convenient, and it is the Unix way.

This is not OK

Now, let's try the same with MySQL 5.6

$BASEDIR/scripts/mysql_install_db --no-defaults --user=tungsten \
--basedir=$BASEDIR --datadir=/home/tungsten/sandboxes/msb_5_6_4/data \
--tmpdir=/home/tungsten/sandboxes/msb_5_6_4/tmp > /dev/null
120318 10:10:44 InnoDB: The InnoDB memory heap is disabled
120318 10:10:44 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120318 10:10:44 InnoDB: Compressed tables use zlib 1.2.3
120318 10:10:44 InnoDB: Using Linux native AIO
120318 10:10:44 InnoDB: CPU supports crc32 instructions
120318 10:10:44 InnoDB: Initializing buffer pool, size = 128.0M
120318 10:10:44 InnoDB: Completed initialization of buffer pool
InnoDB: The first specified data file ./ibdata1 did not exist:
InnoDB: a new database to be created!
120318 10:10:44 InnoDB: Setting file ./ibdata1 size to 10 MB
InnoDB: Database physically writes the file full: wait...
120318 10:10:44 InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 5 MB
InnoDB: Database physically writes the file full: wait...
120318 10:10:44 InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 5 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Doublewrite buffer not found: creating new
InnoDB: Doublewrite buffer created
120318 10:10:44 InnoDB: 128 rollback segment(s) are active.
InnoDB: Creating foreign key constraint system tables
InnoDB: Foreign key constraint system tables created
120318 10:10:44 InnoDB: 1.2.4 started; log sequence number 0
120318 10:10:44 [Warning] Info table is not ready to be used. Table 'mysql.slave_master_info' cannot be opened.
120318 10:10:44 [Warning] Error while checking replication metadata. Setting the requested repository in order to give users the chance to fix the problem and restart the server. If this is a live upgrade please consider using mysql_upgrade to fix the problem.
120318 10:10:44 [Warning] Info table is not ready to be used. Table 'mysql.slave_relay_log_info' cannot be opened.
120318 10:10:44 [Warning] Error while checking replication metadata. Setting the requested repository in order to give users the chance to fix the problem and restart the server. If this is a live upgrade please consider using mysql_upgrade to fix the problem.
120318 10:10:44 [Note] Binlog end
120318 10:10:44 [Note] Shutting down plugin 'partition'
120318 10:10:44 [Note] Shutting down plugin 'ARCHIVE'
120318 10:10:44 [Note] Shutting down plugin 'BLACKHOLE'
120318 10:10:44 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_DELETED'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_INSERTED'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_METRICS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMPMEM'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMP_RESET'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_CMP'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_LOCKS'
120318 10:10:44 [Note] Shutting down plugin 'INNODB_TRX'
120318 10:10:44 [Note] Shutting down plugin 'InnoDB'
120318 10:10:44 InnoDB: FTS optimize thread exiting.
120318 10:10:44 InnoDB: Starting shutdown...
120318 10:10:46 InnoDB: Shutdown completed; log sequence number 1602841
120318 10:10:46 [Note] Shutting down plugin 'CSV'
120318 10:10:46 [Note] Shutting down plugin 'MEMORY'
120318 10:10:46 [Note] Shutting down plugin 'MyISAM'
120318 10:10:46 [Note] Shutting down plugin 'MRG_MYISAM'
120318 10:10:46 [Note] Shutting down plugin 'mysql_old_password'
120318 10:10:46 [Note] Shutting down plugin 'mysql_native_password'
120318 10:10:46 [Note] Shutting down plugin 'binlog'
120318 10:10:46 InnoDB: The InnoDB memory heap is disabled
120318 10:10:46 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120318 10:10:46 InnoDB: Compressed tables use zlib 1.2.3
120318 10:10:46 InnoDB: Using Linux native AIO
120318 10:10:46 InnoDB: CPU supports crc32 instructions
120318 10:10:46 InnoDB: Initializing buffer pool, size = 128.0M
120318 10:10:46 InnoDB: Completed initialization of buffer pool
120318 10:10:46 InnoDB: highest supported file format is Barracuda.
120318 10:10:46 InnoDB: 128 rollback segment(s) are active.
120318 10:10:46 InnoDB: Waiting for the background threads to start
120318 10:10:47 InnoDB: 1.2.4 started; log sequence number 1602841
120318 10:10:47 [Note] Binlog end
120318 10:10:47 [Note] Shutting down plugin 'partition'
120318 10:10:47 [Note] Shutting down plugin 'ARCHIVE'
120318 10:10:47 [Note] Shutting down plugin 'BLACKHOLE'
120318 10:10:47 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_DELETED'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_INSERTED'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_METRICS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMPMEM'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMP_RESET'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_CMP'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_LOCKS'
120318 10:10:47 [Note] Shutting down plugin 'INNODB_TRX'
120318 10:10:47 [Note] Shutting down plugin 'InnoDB'
120318 10:10:47 InnoDB: FTS optimize thread exiting.
120318 10:10:47 InnoDB: Starting shutdown...
120318 10:10:49 InnoDB: Shutdown completed; log sequence number 1602851
120318 10:10:49 [Note] Shutting down plugin 'CSV'
120318 10:10:49 [Note] Shutting down plugin 'MEMORY'
120318 10:10:49 [Note] Shutting down plugin 'MyISAM'
120318 10:10:49 [Note] Shutting down plugin 'MRG_MYISAM'
120318 10:10:49 [Note] Shutting down plugin 'mysql_old_password'
120318 10:10:49 [Note] Shutting down plugin 'mysql_native_password'
120318 10:10:49 [Note] Shutting down plugin 'binlog'
Why is this bad? Because you don't see at a glance what is right and what is wrong. All the above messages are printed to the standard error, the kind of output that should be reserved for, well, errors! If the standard error is used for regular messages, you may miss the important error messages that are instead mixed with the "all is OK" messages.There is Bug#60934 filed about this issue, but it has been considered a feature request, and as such unlikely to be fixed.In the above text there is something more. THere are warnings, mixed with the standard text, telling me of errors that the bootstrap operation is not in a position to fix, like replication metadata and slave_master_info.MySQL developers, please fix this issue. Users need error messages when there is something wrong, and warning or error messages about something that can actually be fixed. When MySQL 5.6 goes GA, this issue will hit most everybody.

PlanetMySQL Voting: Vote UP / Vote DOWN