mysqldiskusage – source code examination

As you know there is a great toolset named “MySQL Utilities”, which you can use for solving various administrative tasks. mysqldiskusage utility is for calculating MySQL Server’s disk usage and generating informative reports. Of course this project is open source and everybody could review the source code. A few words about how mysqldiskusage calculates database disk usage will be crucial for understanding algorithm. The source tree is: mysql-utilities-1.5.4/scripts/mysqldiskusage.py If you open this Python file you will see (line 169-175) :

# We do database disk usage by default. 
try: 
    diskusage.show_database_usage(servers[0], datadir, args, options) 
except UtilError: _, e, _ = sys.exc_info() 
    print("ERROR: %s" % e.errmsg) 
    sys.exit(1) 

By default it shows database disk usage and calling another function named show_database_usage from mysql-utilities-1.5.4/mysql/utilities/command/diskusage.py file. Now if we open up this diskusage.py file and search for show_database_usage function, you should see that in turn this function uses another function named _build_db_list. From _build_db_list it gets back all necessary information as in code stated clearly(line 550-562):

# Get list of databases with sizes and formatted when necessary columns, rows     
db_total = _build_db_list(server, res, dblist, datadir, fmt == "grid", have_read, verbosity, include_empty or do_all, is_remote) 
if not quiet: 
    print "# Database totals:" print_list(sys.stdout, fmt, columns, rows, no_headers) 
if not quiet: _print_size("nTotal database disk usage = ", db_total) 
    print 

Now we know that all calculations are happened in _build_db_list function. If you search and find this function(begins from line 360) you can see that, in fact mysqldiskusage is calculating database disk usage as follows:

It finds (data_length + index_length) from information_schema.tables per database manner

Then it sum ups (data_length + index_length) with misc_files variable data which is in fact returned by _get_db_dir_size function. But what is this misc_files? Logically misc_files must be .opt and .frm files. So misc_files must not be an “.MYD” , “.MYI”, “.IBD”, “general_log”, “slow_log”.

So in fact mysqldiskusage calculates database disk usage as -> (data_length + index_length)[size in bytes] + (.opt+.frm)[size in bytes]. First of all we must insist on not using information_schema for accurate disk usage calculation because of simple rule: “InnoDB preallocates pages(16Kib) for further table usage, but data_length column will not show these pages”

As proof of concept let’s create sample empty table:

mysql> create database test; 
Query OK, 
1 row affected (0,01 sec) 
mysql> use test; 
Database changed 
mysql> 
select data_length, index_length from information_schema.tables where table_schema='test' and table_name='t1'; 
+-------------+--------------+ 
| data_length | index_length | 
+-------------+--------------+ 
| 16384 | 0 | 
+-------------+--------------+ 
1 row in set (0,00 sec) 

If we consider that our exact table size is 16384 bytes, we are in wrong direction. In fact if we use OS commands we could see that the exact size of table is 98304 bytes:

[root@node1 ~]# ls -lt /var/lib/mysql/test/ 
total 208 
-rw-rw----. 1 mysql mysql 98304 Apr 18 11:44 t1.ibd 

So when we create an InnoDB table it is preallocates 6 pages(16Kib*6 = 98304) but only 1 page shown up from data_length column. Now let’s come back to our misc_files or exactly _get_db_dir_size() function. From source code we can see that there is no a check for “.IBD” files:

... 
for item in os.listdir(folder): 
    name, ext = os.path.splitext(item) 
    if ext.upper() not in (".MYD", ".MYI") and  name.upper() not in ('SLOW_LOG', 'GENERAL_LOG'): 
        itemfolder = os.path.join(folder, item) 
    ... 

Because of this calculation is wrong for databases as we see from output:

[root@node1 ~]# mysqldiskusage --server=root_pass -vvv 
# Source on localhost: ... connected. 
# Database totals: 
+---------------------+--------------+--------------+--------------+--------------+ | db_name | db_dir_size | data_size | misc_files | total | +---------------------+--------------+--------------+--------------+--------------+ | employees | 242.523.049 | 205.979.648 | 242.523.049 | 448.502.697 | 

As you see it sum ups data_size with misc_files and gets back total as 448.502.697 bytes. But in fact our employees database is exactly 242.523.049 bytes. And of course the: Total database disk usage = 450.940.391 bytes or 430,05 MB is wrong as well. For further exploration and how to patch source code see related BUG REPORT #76703.

Add Patch to MySQL source code in Linux

Due to reported BUG report(BUG 73365) i am testing full disk error conditions with MySQL 5.6.19-debug-log.

There were some interesting error messages in error log:

2014-07-23 08:09:59 7f44500f0700 InnoDB: Error: Write to file ./xxx/news.ibd failed at offset 218103808.
InnoDB: 1048576 bytes should have been written, only -1 were written.
InnoDB: Operating system error number 28.
InnoDB: Check that your OS and file system support files of this size.
InnoDB: Check also that the disk is not full or a disk quota exceeded.
InnoDB: Error number 28 means 'No space left on device'.

InnoDB: 1048576 bytes should have been written, only -1 were written.
So what is “-1” here?

The answer from:

[24 Jul 16:02] David Bennett

The -1 value is an error return from the os_file_pwrite() function in storage/innobase/os/os0file.c. This only occurs on non-Windows platforms. On Windows the WriteFile functions _Out_opt_ lpNumberOfBytesWritten is used which will return 0 on error. A patch is attached which will correct the error message.

David Bennett attached an patch to my report.
There is no such terrible situation with patches.Patch is simply a text file which describe code difference and etc.
So content of attached patch file:

=== modified file 'storage/innobase/os/os0file.c'
--- storage/innobase/os/os0file.c       2014-02-06 10:25:06 +0000
+++ storage/innobase/os/os0file.c       2014-07-24 15:56:14 +0000
@@ -3045,6 +3045,8 @@

        if (!os_has_said_disk_full) {

+               if (ret == -1) ret++;
+
                ut_print_timestamp(stderr);

                fprintf(stderr,

It is clear that at line 3045 or nearby you must add if (ret == -1) ret++; line to os0file.c file which is in storage/innobase/os/.

Let’s try:

[root@localhost ~]# cd mysql-5.6.19/storage/innobase/os/
[root@localhost os]# ls
os0file.cc  os0proc.cc  os0sync.cc  os0thread.cc

Open this file with option to go to 3045’s line:

[root@localhost os]# nano +3045 os0file.cc
*
*
*
if (!os_has_said_disk_full) {
                // Added New Line 
                if (ret == -1) ret++;

                ut_print_timestamp(stderr);

                fprintf(stderr,
                        " InnoDB: Error: Write to file %s failed"
                        " at offset " UINT64PF ".n"
                        "InnoDB: %lu bytes should have been written,"
                        " only %ld were written.n"
                        "InnoDB: Operating system error number %lu.n"
                        "InnoDB: Check that your OS and file system"
                        " support files of this size.n"
                        "InnoDB: Check also that the disk is not full"
                        " or a disk quota exceeded.n",
                        name, offset, n, (lint) ret,
                        (ulint) errno);
                if (strerror(errno) != NULL) {
                        fprintf(stderr,
                                "InnoDB: Error number %d means '%s'.n",
                                errno, strerror(errno));
                }

                fprintf(stderr,
                        "InnoDB: Some operating system error numbers"
                        " are described atn"
                        "InnoDB: "
                        REFMAN "operating-system-error-codes.htmln");

                os_has_said_disk_full = TRUE;
        }

As you see, error messages is provided by this code lines and we added new line from patch.
Save this file and build/compile MySQL again. (See: Install MySQL from source with debugging option in Linux)

And again i create a full disk error condition but now the “-1” dissappears from error log, it is fixed:

InnoDB: 1048576 bytes should have been written, only 0 were written.
InnoDB: Operating system error number 28.
InnoDB: Check that your OS and file system support files of this size.
InnoDB: Check also that the disk is not full or a disk quota exceeded.
InnoDB: Error number 28 means 'No space left on device'.
InnoDB: Some operating system error numbers are described at

Thank you.

Install MySQL from source with debugging option in Linux

Dear all, our today’s topic is about finding out the cause of MySQL crash and in depth examining issue for BUG reporting. So what is exact mean of this article? While i reported BUGs for MySQL, developers(experts) every time ask for a core dump (with gdb) and full stack-trace. Yeap they are right, finding an issue is only one step. You must also provide all necessary information to MySQL developers if you really interested in fixing bugs in open source. You have to help to find the core of problem. For this purpose you must have a DEBUG MySQL edition on your hand to generate core dump and to see full stack-trace. Yes as you think, we will install MySQL from source with DEBUG option and will create core dump. But first of all let to tell a few theory: * There are several kinds of logging in MySQL:

1. General Log -> will log all kind of database activity. Surely you will not enable it in production because off heavy load, Maybe for a few minutes for auditing will be sufficient to your needs.

2. Slow Quer Log -> will log all queries which is default running more than 10 seconds. Ofcourse you can change default time to less value.

3. Error Log -> From start of MySQL it will log all warnings, errors and events to this log file. It is the first file where you must watch for any kind of problem. There will be somewhat stack-trace looking something like:

Thread pointer: 0x0 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 0 thread_stack 0x40000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x35)[0xab6ead]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x404)[0x736ee0]
/lib64/libpthread.so.0[0x35df20f710] /usr/local/mysql/bin/mysqld[0xd27e2e]
/usr/local/mysql/bin/mysqld[0xd1cc5e] /usr/local/mysql/bin/mysqld[0xc5d5f6]
/usr/local/mysql/bin/mysqld[0xc5dca7] /usr/local/mysql/bin/mysqld[0xc5e152]
/lib64/libpthread.so.0[0x35df2079d1] /lib64/libc.so.6(clone+0x6d)[0x35deee8b5d]

Appending trace to BUG report will be valuable, but most of times developers want core dump. Now it is time to install MySQL from source with DEBUG option. Go through every step: ** Install Dependencies:**

[root@localhost ~]# yum groupinstall "Development Tools" 
[root@localhost ~]# yum install cmake 
[root@localhost ~]# yum install ncurses ncurses-devel 
[root@localhost ~]# yum install wget  

Download tar archive from: mysql-5.6.19.tar.gz Then:

1. [root@localhost ~]# wget http://dev.mysql.com/get/Downloads/MySQL-5.6/mysql-5.6.19.tar.gz 
2. [root@localhost ~]# tar -xvf mysql-5.6.19.tar.gz 
3. [root@localhost ~]# groupadd mysql 
4. [root@localhost ~]# useradd -r -g mysql mysql 
5. [root@localhost ~]# cd mysql-5.6.19 
6. [root@localhost mysql-5.6.19]# cmake -DWITH_DEBUG=1 
7. [root@localhost mysql-5.6.19]# make 
8. [root@localhost mysql-5.6.19]# make install

After install finished:

8. [root@localhost mysql-5.6.19]# cd /usr/local/mysql 
9. [root@localhost mysql]# chown -R mysql  
10. [root@localhost mysql]# chgrp -R mysql 
11. [root@localhost mysql]# scripts/mysql_install_db --user=mysql 2014-07-21 03:52:05 14280 [Note] InnoDB: Using atomics to ref count buffer pool pages 2014-07-21 03:52:05 7f6e8f793720 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!! 2014-07-21 03:52:05 7f6e8f793720 InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!

You will see difference in error log too. After all:

12. [root@localhost mysql]# chown -R root
13. [root@localhost mysql]# chown -R mysql data 
14. [root@localhost mysql]# bin/mysqld_safe --user=mysql & 
15. [root@localhost mysql]# bin/mysqld_safe --user=mysql & [1] 14525 [root@localhost mysql]# 140721 03:55:41 mysqld_safe Logging to '/var/log/mysqld.log'. 140721 03:55:41 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 

AS you see MySQL is started and at this point you can begin to test whatever you want. When you connect you will see difference:

[root@localhost bin]# ./mysql -u root --socket=/usr/local/mysql/data/mysql.sock
Welcome to the MySQL monitor. Commands end with ; or g. Your MySQL connection id is 1 Server version: 5.6.19-debug-log Source distribution 

Now we have a DEBUG MySQL , we can try to create a core dump: Add this line under [mysqld] catalog: [mysqld] core-file And also append this to the end of my.cnf file: [mysqld_safe] core_file_size=unlimited And restart MySQL. If some crash happens you will see :

    bin/mysqld_safe: line 166: 27247 Segmentation fault (core dumped) 

Core Dumped indicates that, core file is created. Default core file will reside in MySQL datadir. Thank You!.