Wednesday, June 04, 2014

MariaDB 10 is a Sandbox killjoy?

Using MySQL Sandbox I can install multiple instances of MySQL. It is not uncommon for me to run 5 or 6 instances at once, and in some occasions, I get to have even 10 of them. It is usually not a problem. But today I had an issue while testing MariaDB, for which I needed 5 instances, and I the installation failed after the 4th one. To make sure that the host could run that many servers, I tried installing 10 instances of MySQL 5.6 and 5.7. All at once, for a grand total of 20 instances:

$ make_multiple_sandbox --how_many_nodes=10 5.6.14
installing node 1
installing node 2
installing node 3
installing node 4
installing node 5
installing node 6
installing node 7
installing node 8
installing node 9
installing node 10
group directory installed in $HOME/sandboxes/multi_msb_5_6_14
$ make_multiple_sandbox --how_many_nodes=10 5.7.4
installing node 1
installing node 2
installing node 3
installing node 4
installing node 5
installing node 6
installing node 7
installing node 8
installing node 9
installing node 10
group directory installed in $HOME/sandboxes/multi_msb_5_7_4

$ ~/sandboxes/use_all 'select @@port, @@version'
# server: 1:
@@port  @@version
14015   5.6.14-log
# server: 2:
@@port  @@version
14016   5.6.14-log
# server: 3:
@@port  @@version
14017   5.6.14-log
# server: 4:
@@port  @@version
14018   5.6.14-log
# server: 5:
@@port  @@version
14019   5.6.14-log
# server: 6:
@@port  @@version
14020   5.6.14-log
# server: 7:
@@port  @@version
14021   5.6.14-log
# server: 8:
@@port  @@version
14022   5.6.14-log
# server: 9:
@@port  @@version
14023   5.6.14-log
# server: 10:
@@port  @@version
14024   5.6.14-log
# server: 1:
@@port  @@version
7975    5.7.4-m14-log
# server: 2:
@@port  @@version
7976    5.7.4-m14-log
# server: 3:
@@port  @@version
7977    5.7.4-m14-log
# server: 4:
@@port  @@version
7978    5.7.4-m14-log
# server: 5:
@@port  @@version
7979    5.7.4-m14-log
# server: 6:
@@port  @@version
7980    5.7.4-m14-log
# server: 7:
@@port  @@version
7981    5.7.4-m14-log
# server: 8:
@@port  @@version
7982    5.7.4-m14-log
# server: 9:
@@port  @@version
7983    5.7.4-m14-log
# server: 10:
@@port  @@version
7984    5.7.4-m14-log

This worked fine. Then I removed all the instances, and tried again with MariaDB

 $ sbtool -o delete -s ~/sandboxes/multi_msb_5_6_14/ 
 ...
 $ sbtool -o delete -s ~/sandboxes/multi_msb_5_7_4/
 ...

With MariaDB 10, the installation failed after the 4th node.

$ make_multiple_sandbox --how_many_nodes=10 10.0.11
installing node 1
installing node 2
installing node 3
installing node 4
error while creating grant tables
Installing MariaDB/MySQL system tables in '/home/tungsten/sandboxes/multi_msb_10_0_11/node4/data' ...
140604  8:27:14 [Note] InnoDB: Using mutexes to ref count buffer pool pages
140604  8:27:14 [Note] InnoDB: The InnoDB memory heap is disabled
140604  8:27:14 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
140604  8:27:14 [Note] InnoDB: Compressed tables use zlib 1.2.3
140604  8:27:14 [Note] InnoDB: Using Linux native AIO
140604  8:27:14 [Note] InnoDB: Using CPU crc32 instructions
2014-06-04 08:27:14 7f207d353780 InnoDB: Warning: io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
InnoDB: Warning: io_setup() attempt 1 failed.
InnoDB: Warning: io_setup() attempt 2 failed.
InnoDB: Warning: io_setup() attempt 3 failed.
InnoDB: Warning: io_setup() attempt 4 failed.
InnoDB: Warning: io_setup() attempt 5 failed.
2014-06-04 08:27:16 7f207d353780 InnoDB: Error: io_setup() failed with EAGAIN after 5 attempts.
InnoDB: You can disable Linux Native AIO by setting innodb_use_native_aio = 0 in my.cnf
InnoDB: Warning: Linux Native AIO disabled because os_aio_linux_create_io_ctx() failed. To get rid of this warning you can try increasing system fs.aio-max-nr to 1048576 or larger or setting innodb_use_native_aio = 0 in my.cnf
140604  8:27:16 [Note] InnoDB: Initializing buffer pool, size = 128.0M
140604  8:27:16 [Note] InnoDB: Completed initialization of buffer pool
140604  8:27:16 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
140604  8:27:16 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB
140604  8:27:16 [Note] InnoDB: Database physically writes the file full: wait...
140604  8:27:16 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
140604  8:27:17 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
140604  8:27:18 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
140604  8:27:18 [Warning] InnoDB: New log files created, LSN=45781
140604  8:27:18 [Note] InnoDB: Doublewrite buffer not found: creating new
140604  8:27:18 [Note] InnoDB: Doublewrite buffer created
140604  8:27:18 [Note] InnoDB: 128 rollback segment(s) are active.
140604  8:27:19 [Warning] InnoDB: Creating foreign key constraint system tables.
140604  8:27:19 [Note] InnoDB: Foreign key constraint system tables created
140604  8:27:19 [Note] InnoDB: Creating tablespace and datafile system tables.
140604  8:27:19 [Note] InnoDB: Tablespace and datafile system tables created.
140604  8:27:19 [Note] InnoDB: Waiting for purge to start
140604  8:27:19 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.17-65.0 started; log sequence number 0
140604  8:27:24 [Note] InnoDB: FTS optimize thread exiting.
140604  8:27:24 [Note] InnoDB: Starting shutdown...
140604  8:27:25 [Note] InnoDB: Shutdown completed; log sequence number 1616697
OK
Filling help tables...
140604  8:27:25 [Note] InnoDB: Using mutexes to ref count buffer pool pages
140604  8:27:25 [Note] InnoDB: The InnoDB memory heap is disabled
140604  8:27:25 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
140604  8:27:25 [Note] InnoDB: Compressed tables use zlib 1.2.3
140604  8:27:25 [Note] InnoDB: Using Linux native AIO
140604  8:27:25 [Note] InnoDB: Using CPU crc32 instructions
2014-06-04 08:27:25 7f12bb0e9780 InnoDB: Warning: io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
InnoDB: Warning: io_setup() attempt 1 failed.
InnoDB: Warning: io_setup() attempt 2 failed.
InnoDB: Warning: io_setup() attempt 3 failed.
InnoDB: Warning: io_setup() attempt 4 failed.
InnoDB: Warning: io_setup() attempt 5 failed.
2014-06-04 08:27:28 7f12bb0e9780 InnoDB: Error: io_setup() failed with EAGAIN after 5 attempts.
InnoDB: You can disable Linux Native AIO by setting innodb_use_native_aio = 0 in my.cnf
InnoDB: Warning: Linux Native AIO disabled because os_aio_linux_create_io_ctx() failed. To get rid of this warning you can try increasing system fs.aio-max-nr to 1048576 or larger or setting innodb_use_native_aio = 0 in my.cnf
140604  8:27:28 [Note] InnoDB: Initializing buffer pool, size = 128.0M
140604  8:27:28 [Note] InnoDB: Completed initialization of buffer pool
140604  8:27:28 [Note] InnoDB: Highest supported file format is Barracuda.
140604  8:27:28 [Note] InnoDB: 128 rollback segment(s) are active.
140604  8:27:28 [Note] InnoDB: Waiting for purge to start
140604  8:27:28 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.17-65.0 started; log sequence number 1616697
140604  8:27:28 [Note] InnoDB: FTS optimize thread exiting.
140604  8:27:28 [Note] InnoDB: Starting shutdown...
140604  8:27:30 [Note] InnoDB: Shutdown completed; log sequence number 1616707

This smells like a bug. BTW, the installation fails with both MariaDB 10.0.10 and 10.0.11, and only on Ubuntu Linux. I can install 10 instances just fine on Mac OSX. I haven’t tried with CentOS.

7 comments:

Rautiainen said...

Works perfectly on Fedora 20 Heisenburg. From that we could guestimate that CentOS is fine also.

Run same command make_multiple_sandbox --how_many_nodes=10 10.0.11 after unpacking Maria to ~/opt/mysql/10.0.11

elenst said...

Have you, by any chance, tried MariaDB with InnoDB plugin and Percona 5.6?

The AIO warning (in MariaDB server) should be relatively harmless, it means what it says, native AIO gets disabled, and InnoDB continues initializing. It was a workaround for MySQL problem when InnoDB would abort in the same scenario. Apparently, it was finally fixed in 5.6.

The log looks weird, it seems that the server just shuts down after InnoDB initialized. I started 25 MariaDB servers with default options on my Wheezy VM (manually, not via sandbox) and still didn't get this effect. If you share more details about the machine (OS, memory) and MariaDB server configuration, I will try to reproduce it on a similar VM.

elenst said...

I took a very quick look at the sandbox code; I could be wrong, but it looks like sandbox aborts bootstrap if it finds in output anything that resembles an error. It could account for the strange server shutdown.

But then, there should be nothing new for sandbox here. MySQL used to just abort in this case and it was a documented limitation (http://bugs.mysql.com/bug.php?id=61575), then about 2 years ago in MariaDB 5.5 the fatal error was replaced with the error message, so MariaDB 5.5 would throw the same warning/error and continue, and the outcome for sandbox should be the same as now.

It is worth checking though why the error still happens with XtraDB, while with InnoDB it does not.

Giuseppe Maxia said...

@Elenst,
the only setting that MySQL::Sandbox applies to the database when running multiple sandboxes are server-id and binary logs activation.

The host is Ubuntu 12.04 with 16GB or RAM.

You are right about MySQL Sandbox stopping if it detects an error in the output. This is due to MySQL 5.6 and MariaDB 10 inconsistent behavior during bootstrap. Up to version 5.5, bootstrap was sending its output to STDOUT, and only errors to STDERR.
That way, it was easy to detect if there was ane error. With the current behavior, all output goes to STDERR, which forces me to parse for the word "error". So, if the database server says "error" in STDERR the application can legitimately assume that there was an error. If there isn't an error but the server says "error," then it's a different kind of bug.

elenst said...

It is an error, and the server is right saying so. It's just not a fatal error.

Giuseppe Maxia said...

@elenst:
It's just not a fatal error.

Does it mean that the server is safe to use, even though it says there is an error during bootstrap?

DBAs evaluating the software must be thrilled.

If it is not serious, it should say "WARNING."
It is bad enough that the server is mixing useless messages and errors in STDERR. If the errors being listed have different meaning, this is terrible for usability.

elenst said...

Server should be safe to use as much as it would be safe if you switched off native AIO manually in InnoDB options. It is still a real configuration error and should be noticed by the DBA who can then decide what to do about it: fix, get rid of the message by unsetting the option manually, or just ignore.

There is no particular reason to limit server to only having "warnings" or "fatal errors".

In MySQL it was a fatal error. In MariaDB, it became a non-fatal error. I don't see why a DBA should have a problem with this.

If the DBA wants to treat every error as a fatal error, they are free to do so just as you do in sandbox. Otherwise they have an option to filter more-serious-but-still-not-life-threatening problems out of the whole universe of warnings that the server can produce, and act accordingly.

For 5.6 vs 10.0 comparison, we'll investigate why MySQL doesn't produce the error anymore, whether there was a real fix, or the message is just suppressed, or it's something else. If it's a real fix that escaped the merge, it should be incorporated. If it was just a cosmetic change to have a nice-looking error, then it's better to keep a clear error message in MariaDB.

Vote on Planet MySQL