Agate
Agate

Reputation: 3232

MySQL/MariaDB write/insert take a very long time

I'm facing a strange issue on my server. I have MariaDB installed and it works. I can set up databases and everything. But every time MariaDB need to write data (for example insert a new row, create a database, delete a row...) it takes ages.

Right now, I can't setup a basic WordPress website, because the creation of the database is so long that my browser times out.

Even drop database X statement takes more than 30 seconds, for an almost empty DB.

I really don't understand why, because I already installed MySQL with success on other machines, that were far less performant than this one (32 GB RAM, SSDdrive, Intel(R) Xeon(R) CPU E3-1245 V2 @ 3.40GHz, 8 cores CPU, etc.).

I don't know how to debug this. Here is what I did :

Run MySQLTuner (found in this question)

Outputs :

-------- General Statistics --------------------------------------------------
[--] Skipped version check for MySQLTuner script
[!!] Your MySQL version 10.0.7-MariaDB-1~wheezy-log is EOL software!  Upgrade soon!
[OK] Operating on 64-bit architecture

-------- Storage Engine Statistics -------------------------------------------
[--] Status: +Archive -BDB +Federated +InnoDB -ISAM -NDBCluster 
[--] Data in MyISAM tables: 6K (Tables: 39)
[--] Data in CSV tables: 0B (Tables: 2)
[--] Data in InnoDB tables: 237K (Tables: 214)
[--] Data in PERFORMANCE_SCHEMA tables: 0B (Tables: 52)
[!!] Total fragmented tables: 146

-------- Security Recommendations  -------------------------------------------
[OK] All database users have passwords assigned
Use of uninitialized value in addition (+) at ./mysqltuner.pl line 582, <> line
    2 (#1)
    (W uninitialized) An undefined value was used as if it were already
    defined.  It was interpreted as a "" or a 0, but maybe it was a mistake.
    To suppress this warning assign a defined value to your variables.
    
    To help you figure out what was undefined, perl will try to tell you the
    name of the variable (if any) that was undefined. In some cases it cannot
    do this, so it also tells you what operation you used the undefined value
    in.  Note, however, that perl optimizes your program and the operation
    displayed in the warning may not necessarily appear literally in your
    program.  For example, "that $foo" is usually optimized into "that "
    . $foo, and the warning will refer to the concatenation (.) operator,
    even though there is no . in your program.
    
Argument "xargs:" isn't numeric in addition (+) at ./mysqltuner.pl line 618, <>
    line 2 (#2)
    (W numeric) The indicated string was fed as an argument to an operator
    that expected a numeric value instead.  If you're fortunate the message
    will identify which operator was so unfortunate.
    
Argument "du:" isn't numeric in addition (+) at ./mysqltuner.pl line 618, <>
    line 2 (#2)

-------- Performance Metrics -------------------------------------------------
[--] Up for: 21m 17s (818 q [0.641 qps], 36 conn, TX: 395K, RX: 338K)
[--] Reads / Writes: 73% / 27%
[--] Total buffers: 1.3G global + 416.0K per thread (100 max threads)
[OK] Maximum possible memory usage: 1.4G (4% of installed RAM)
[OK] Slow queries: 0% (3/818)
[OK] Highest usage of available connections: 3% (3/100)
[!!] Cannot calculate MyISAM index size - re-run script as root user
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 11 sorts)
[!!] Temporary tables created on disk: 47% (90 on disk / 189 total)
[OK] Thread cache hit rate: 91% (3 created / 36 connections)
[OK] Table cache hit rate: 211% (91 open / 43 opened)
[OK] Open file limit used: 3% (34/1K)
[OK] Table locks acquired immediately: 100% (603 immediate / 603 locks)
[!!] Connections aborted: 16%
[OK] InnoDB data size / buffer pool: 237.4K/256.0M

-------- Recommendations -----------------------------------------------------
General recommendations:
    Run OPTIMIZE TABLE to defragment tables for better performance
    MySQL started within last 24 hours - recommendations may be inaccurate
    Upgrade MySQL to version 4+ to utilize query caching
    Temporary table size is already large - reduce result set size
    Reduce your SELECT DISTINCT queries without LIMIT clauses
    Upgrade to MySQL 4.1+ to use concurrent MyISAM inserts
    Your applications are not closing MySQL connections properly

It seems there are a lot of wrong things (!!). But why ? As far as I remember, I did a standard Mariadb install, via their website.

Profiling of a Drop database XXX

MariaDB [(none)]> set profiling = 1;
Query OK, 0 rows affected (0.00 sec)

MariaDB [(none)]> drop database XXX;
Query OK, 11 rows affected (20.08 sec)

MariaDB [(none)]> show profile for query 1;
+------------------------------+-----------+
| Status                       | Duration  |
+------------------------------+-----------+
| Table lock                   |  0.000008 |
| Waiting for query cache lock |  0.000004 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000008 |
| Table lock                   |  0.000008 |
| Opening tables               |  0.000010 |
| System lock                  |  0.000004 |
| Table lock                   |  0.000008 |
| Waiting for query cache lock |  0.000005 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000007 |
| Opening tables               |  0.000010 |
| System lock                  |  0.000004 |
| Table lock                   |  0.000008 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000007 |
| Opening tables               |  0.000010 |
| System lock                  |  0.000004 |
| Table lock                   |  0.000013 |
| Waiting for query cache lock |  0.000005 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000007 |
| Opening tables               |  0.000010 |
| System lock                  |  0.000004 |
| Table lock                   |  0.000008 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000008 |
| Opening tables               |  0.000010 |
| System lock                  |  0.000004 |
| Table lock                   |  0.000008 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000007 |
| Opening tables               |  0.000010 |
| System lock                  |  0.000004 |
| Table lock                   |  0.000008 |
| Waiting for query cache lock |  0.000004 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   | 12.399188 | # WHAAAT ?
| Waiting for query cache lock |  0.000012 |
| Table lock                   |  0.000005 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000004 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.000003 |
| Waiting for query cache lock |  0.000003 |
| Table lock                   |  0.299851 |
| Waiting for query cache lock |  0.000007 |
| Table lock                   |  0.000008 |
| Opening tables               |  0.000017 |
| System lock                  |  0.000008 |
| Table lock                   |  0.000019 |
| Waiting for query cache lock |  0.000004 |
| Table lock                   |  0.000013 |
| Opening tables               |  0.000012 |
| System lock                  |  0.000004 |
| Table lock                   |  0.000015 |
| Waiting for query cache lock |  0.000004 |
| Table lock                   |  0.000093 |
| query end                    |  0.000007 |
| closing tables               |  0.000014 |
| freeing items                |  0.000005 |
| updating status              |  0.000013 |
| cleaning up                  |  0.000015 |
+------------------------------+-----------+

So there is a problem with table lock, but I don't know to which settings it's related.

"Lock" related variables

show variables LIKE '%lock%';
+-----------------------------------------+------------+
| Variable_name                           | Value      |
+-----------------------------------------+------------+
| aria_block_size                         | 8192       |
| deadlock_search_depth_long              | 15         |
| deadlock_search_depth_short             | 4          |
| deadlock_timeout_long                   | 50000000   |
| deadlock_timeout_short                  | 10000      |
| innodb_api_disable_rowlock              | OFF        |
| innodb_autoinc_lock_mode                | 1          |
| innodb_lock_wait_timeout                | 50         |
| innodb_locks_unsafe_for_binlog          | OFF        |
| innodb_old_blocks_pct                   | 37         |
| innodb_old_blocks_time                  | 1000       |
| innodb_print_all_deadlocks              | OFF        |
| innodb_table_locks                      | ON         |
| key_cache_block_size                    | 1024       |
| lock_wait_timeout                       | 31536000   |
| locked_in_memory                        | OFF        |
| max_write_lock_count                    | 4294967295 |
| metadata_locks_cache_size               | 1024       |
| metadata_locks_hash_instances           | 8          |
| myisam_block_size                       | 1024       |
| performance_schema_max_rwlock_classes   | 40         |
| performance_schema_max_rwlock_instances | 1667       |
| query_alloc_block_size                  | 8192       |
| query_cache_wlock_invalidate            | OFF        |
| range_alloc_block_size                  | 4096       |
| skip_external_locking                   | ON         |
| transaction_alloc_block_size            | 8192       |
+-----------------------------------------+------------+

Variables (sudo mysqld --help --verbose)

Tell me if you need more informations. Thank you for your help !

Upvotes: 0

Views: 3933

Answers (1)

Agate
Agate

Reputation: 3232

OKay, I don't know exactly what was the issue, but after having a look at dozens of topics on the web, I updated my my.cnf file with the following values :

query_cache_type = OFF
slow_query_log = 1 # log slow queries, for debuging
long_query_time = 1 # log queries as slow when their duration > 1 sec
innodb_buffer_pool_size = 1500M
innodb_log_buffer_size  = 80M
innodb_flush_log_at_trx_commit = 0 # I know it's not good for transaction security but it seemed to help

That's all.

I can now create my database from browser and, even if it still a bit slow (in my opinion), it's far better now.

Thanks for our help !

Upvotes: 2

Related Questions