MySQL Binary Log activated = high-end server damn slow

binaryloggingMySQLperformancereplication

On MySQL 5.1(.57-1.dotdeb), I have a ~2.0Gb database, and an average of ~350 requests per second.

All is running fine if I don't activate the binary log. The CPU usage is decent (~15% of 1 CPU core).

And if I activate the binary log, all is suddenly HYPER slow. The requests average come down to ~90 requests / sec, and every request takes +/- 4 seconds to finish.

You have to know that :

  • MySQL is properly tuned, tuning-primer.sh gives good results in "normal" time
  • The hardware is a Bi-Xeon E5620 (Westmere generation) with 24 GO RAM
  • 12 GO of RAM is allowed for InnoDB
  • Running Debian 6 64bits

When the binary log is activated :

  • The CPU usage of MySQL is damn LOW. About 1 or 2% of 1 core. No much %wa for I/O in "top", about 5-7%.
  • The memory usage seems fine. I have tested with 1 GO for InnoDB instead of 12 GO, no change.
  • The queries are so long to execute, then php5-fpm create a lot of new processes to handle the traffic.

In normal time, I have ~15 PHP-FPM workers, and if the binary log is activated, this number can up to 150-200 (max).

No need to precise that all the system is frozen at this point. 🙂

Here is my.cnf :

    [client] 
    port     = 3306 
    socket   = /var/run/mysqld/mysqld.sock 


    [mysqld_safe] 
    socket   = /var/run/mysqld/mysqld.sock 
    nice     = 0 

    [mysqld] 
    user     = mysql 
    pid-file    = /var/run/mysqld/mysqld.pid 
    socket   = /var/run/mysqld/mysqld.sock 
    port     = 3306 
    basedir  = /usr 
    datadir  = /var/lib/mysql 
    tmpdir   = /tmp 
    language    = /usr/share/mysql/english 
    skip-external-locking 

    bind-address     = 127.0.0.1 

    key_buffer   = 16M 
    max_allowed_packet  = 16M 
    thread_stack     = 192K 
    thread_cache_size = 32 

    myisam-recover = BACKUP 
    max_connections = 200 

    table_cache = 512 

    #thread_concurrency = 10 

    query_cache_limit   = 1M 
    query_cache_size = 16M 

    max_heap_table_size = 64M 
    tmp_table_size = 64M 

    innodb_buffer_pool_size = 12G 

    #general_log_file = /var/log/mysql/mysql.log 
    #general_log = 1 

    long_query_time = 4 
    #log_slow_queries   = /var/log/mysql/mysql-slow.log 
    #log-queries-not-using-indexes 

    #server-id   = 1 
    #report-host=host 


    # NOTE : All the values here are uncommented when i activate binlog 

    #log-bin     = /var/log/mysql/mysql-bin.log 
    #log-error   = /var/log/mysql/mysql-err.log 
    #sync_binlog = 0 
    #binlog_cache_size = 128M 
    #expire_logs_days   = 2 
    #max_binlog_size = 100M 
    #max_binlog_cache_size = 1G 


    [mysqldump] 
    quick 
    quote-names 
    max_allowed_packet  = 16M 

    [mysql] 
    #no-auto-rehash # faster start of mysql but no tab completition 

    [isamchk] 
    key_buffer   = 16M 

    !includedir /etc/mysql/conf.d/ 

Tell me if you have any idea about that issue !

Thanks


EDIT 1 @Jason :

After setting innodb_log_file_size = 1G, shutting down the server, renamed the ib_logfile0 and ib_logfile1, restarted the server with binlog.

The mysql server just do not respond at all. It's so slow that no page is displayed this time.

Note that there is no problem if I deactivate the binlog again.

The load averages seems to be high : 3.5, even if the CPU is not so solicited…


EDIT 3 :

@Jason , @Bryan

After all,

It seems to be a bug of MySQL 5.1.

After many tests, nothing changed.

Not a CPU, RAM, or IO related problem.

I switched one of my server to Percona MySQL 5.5 and it just works fine now, with the same hardware, database and configuration.

Maybe 20% or 30% faster than MySQL 5.1…

What else?

Best Answer

What is your distribution of reads to writes? Do you have a write intensive application?

What is your disk subsystem like?

You have not specified innodb_log_file_size. On a busy server the default is way too low. Increasing this may help with your I/O woes when the binary log is enabled.

Also, sync_binlog = 0 is not recommended since if the server crashes your binary log will be out of sync with the transactions.

Cheers