We have a 3 data holding node Galera cluster managed with Puppet. The VMs small with only 4GB am RAM. Exact the same configuration of sizing VM and MariaDB/Galera (RHEL7). On Production there is more load, on Int where the query runs very slow this query is the only process not in sleep. The tables have more records on Prd than on Int.
This query runs on Int Galera cluster 1 min 30 secs. On Prd the same query / same schema / same execution plan runs in 2 secs.
We did ANALAYZE TABLE and OPTIMIZE TABLE. We checked the fragmentation, which is on Prd 100x more than in Int. No errors in /var/log/mariadb/mariadb.log. When running the query with SQL_NO_CACHE there is no difference.
here the execution plan
select count(jobexecuti0_.JOB_EXECUTION_ID) as col_0_0_
from BATCH_JOB_EXECUTION jobexecuti0_
where jobexecuti0_.JOB_EXECUTION_ID=
( SELECT max(jobexecuti1_.JOB_EXECUTION_ID)
from BATCH_JOB_EXECUTION jobexecuti1_
where jobexecuti1_.JOB_INSTANCE_ID=jobexecuti0_.JOB_INSTANCE_ID
);
+----------+
| col_0_0_ |
+----------+
| 140167 |
+----------+
1 row in set (1 min 33.53 sec)
> EXPLAIN EXTENDED select count(jobexecuti0_.JOB_EXECUTION_ID) as col_0_0_ from BATCH_JOB_EXECUTION jobexecuti0_ where jobexecuti0_.JOB_EXECUTION_ID=(select max(jobexecuti1_.JOB_EXECUTION_ID) from BATCH_JOB_EXECUTION jobexecuti1_ where jobexecuti1_.JOB_INSTANCE_ID=jobexecuti0_.JOB_INSTANCE_ID);
+------+--------------------+--------------+-------+------------------+------------------+---------+---------------------------------------+--------+----------+--------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+------+--------------------+--------------+-------+------------------+------------------+---------+---------------------------------------+--------+----------+--------------------------+
| 1 | PRIMARY | jobexecuti0_ | index | NULL | JOB_INST_EXEC_FK | 8 | NULL | 228607 | 100.00 | Using where; Using index |
| 2 | DEPENDENT SUBQUERY | jobexecuti1_ | ref | JOB_INST_EXEC_FK | JOB_INST_EXEC_FK | 8 | exampledb.jobexecuti0_.JOB_INSTANCE_ID | 1 | 100.00 | Using index |
+------+--------------------+--------------+-------+------------------+------------------+---------+---------------------------------------+--------+----------+--------------------------+
2 rows in set, 2 warnings (0.01 sec)
> show warnings;
+-------+------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Level | Code | Message |
+-------+------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Note | 1276 | Field or reference 'exampledb.jobexecuti0_.JOB_INSTANCE_ID' of SELECT #2 was resolved in SELECT #1 |
| Note | 1003 | select count(`exampledb`.`jobexecuti0_`.`JOB_EXECUTION_ID`) AS `col_0_0_` from `exampledb`.`BATCH_JOB_EXECUTION` `jobexecuti0_` where (`exampledb`.`jobexecuti0_`.`JOB_EXECUTION_ID` = <expr_cache><`exampledb`.`jobexecuti0_`.`JOB_INSTANCE_ID`>((select max(`exampledb`.`jobexecuti1_`.`JOB_EXECUTION_ID`) from `exampledb`.`BATCH_JOB_EXECUTION` `jobexecuti1_` where (`exampledb`.`jobexecuti1_`.`JOB_INSTANCE_ID` = `exampledb`.`jobexecuti0_`.`JOB_INSTANCE_ID`)))) |
+-------+------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
2 rows in set (0.00 sec)
cluster status, was after reboot.
MariaDB [(none)]> select VERSION(); [10/513]
+----------------------+
| VERSION() |
+----------------------+
| 5.5.42-MariaDB-wsrep |
+----------------------+
1 row in set (0.00 sec)
MariaDB [(none)]> show global status like '%wsrep%';
+------------------------------+-------------------------------------------------+
| Variable_name | Value |
+------------------------------+-------------------------------------------------+
| wsrep_local_state_uuid | c8a04671-8ad3-11e6-80c5-03ef3c60deca |
| wsrep_protocol_version | 5 |
| wsrep_last_committed | 135510458 |
| wsrep_replicated | 19 |
| wsrep_replicated_bytes | 7735 |
| wsrep_repl_keys | 57 |
| wsrep_repl_keys_bytes | 893 |
| wsrep_repl_data_bytes | 5626 |
| wsrep_repl_other_bytes | 0 |
| wsrep_received | 14534 |
| wsrep_received_bytes | 15266581 |
| wsrep_local_commits | 19 |
| wsrep_local_cert_failures | 0 |
| wsrep_local_replays | 0 |
| wsrep_local_send_queue | 0 |
| wsrep_local_send_queue_avg | 0.000000 |
| wsrep_local_recv_queue | 0 |
| wsrep_local_recv_queue_avg | 0.157837 |
| wsrep_local_cached_downto | 135496025 |
| wsrep_flow_control_paused_ns | 1335634 |
| wsrep_flow_control_paused | 0.000001 |
| wsrep_flow_control_sent | 1 |
| wsrep_flow_control_recv | 1 |
| wsrep_cert_deps_distance | 34.346543 |
| wsrep_apply_oooe | 0.000271 |
| wsrep_apply_oool | 0.000000 |
| wsrep_apply_window | 1.000271 |
| wsrep_commit_oooe | 0.000000 |
| wsrep_commit_oool | 0.000000 |
| wsrep_commit_window | 1.000068 |
| wsrep_local_state | 4 |
| wsrep_local_state_comment | Synced |
| wsrep_cert_index_size | 9 |
| wsrep_causal_reads | 0 |
| wsrep_cert_interval | 0.049120 |
| wsrep_incoming_addresses | censured |
| wsrep_cluster_conf_id | 3 |
| wsrep_cluster_size | 3 |
| wsrep_cluster_state_uuid | c8a04671-8ad3-11e6-80c5-03ef3c60deca |
| wsrep_cluster_status | Primary |
| wsrep_connected | ON |
| wsrep_local_bf_aborts | 0 |
| wsrep_local_index | 2 |
| wsrep_provider_name | Galera |
| wsrep_provider_vendor | Codership Oy <info@codership.com> |
| wsrep_provider_version | 3.5(rXXXX) |
| wsrep_ready | ON |
| wsrep_thread_count | 2 |
+------------------------------+-------------------------------------------------+
48 rows in set (0.00 sec)
my.cnf.d directory files (configuration)
# grep "^[^#;]" galera.cnf server.cnf
galera.cnf:[mysqld]
galera.cnf:binlog_format=ROW
galera.cnf:default-storage-engine=innodb
galera.cnf:innodb_autoinc_lock_mode=2
galera.cnf:innodb_locks_unsafe_for_binlog=1
galera.cnf:query_cache_type=1
galera.cnf:bind-address=0.0.0.0
galera.cnf:wsrep_provider=/usr/lib64/galera/libgalera_smm.so
galera.cnf:wsrep_provider_options="socket.ssl=false"
galera.cnf:wsrep_cluster_name="galera_cluster"
galera.cnf:wsrep_cluster_address="gcomm://censured"
galera.cnf:wsrep_slave_threads=1
galera.cnf:wsrep_certify_nonPK=1
galera.cnf:wsrep_max_ws_rows=131072
galera.cnf:wsrep_max_ws_size=1073741824
galera.cnf:wsrep_debug=0
galera.cnf:wsrep_convert_LOCK_to_trx=0
galera.cnf:wsrep_retry_autocommit=1
galera.cnf:wsrep_auto_increment_control=1
galera.cnf:wsrep_drupal_282555_workaround=0
galera.cnf:wsrep_causal_reads=0
galera.cnf:wsrep_notify_cmd=
galera.cnf:wsrep_sst_method=rsync
galera.cnf:wsrep_sst_auth=sst_user:xxxxxxx
galera.cnf:skip-name-resolve=1
server.cnf:[client]
server.cnf:port = 3306
server.cnf:socket = /var/lib/mysql/mysql.sock
server.cnf:[isamchk]
server.cnf:key_buffer_size = 16M
server.cnf:[mysqld]
server.cnf:basedir = /usr
server.cnf:bind-address = 0.0.0.0
server.cnf:datadir = /var/lib/mysql/data
server.cnf:default-storage-engine = InnoDB
server.cnf:expire_logs_days = 10
server.cnf:interactive_timeout = 2147483
server.cnf:key_buffer_size = 16M
server.cnf:log-error = /var/log/mariadb/mariadb.log
server.cnf:max_allowed_packet = 500M
server.cnf:max_binlog_size = 100M
server.cnf:max_connections = 15360
server.cnf:open_files_limit = 16384
server.cnf:pid-file = /var/run/mariadb/mariadb.pid
server.cnf:port = 3306
server.cnf:query_cache_limit = 1M
server.cnf:query_cache_size = 16M
server.cnf:skip-external-locking
server.cnf:socket = /var/lib/mysql/mysql.sock
server.cnf:ssl = false
server.cnf:ssl-ca = /etc/pki/galera/mysql.ca.crt
server.cnf:ssl-cert = /etc/pki/galera/mysql.crt
server.cnf:ssl-key = /etc/pki/galera/mysql.key
server.cnf:thread_cache_size = 8
server.cnf:thread_stack = 256K
server.cnf:tmpdir = /var/lib/mysql/tmp
server.cnf:user = mysql
server.cnf:wait_timeout = 2147483
server.cnf:[mysqld-5.0]
server.cnf:myisam-recover = BACKUP
server.cnf:[mysqld-5.1]
server.cnf:myisam-recover = BACKUP
server.cnf:[mysqld-5.5]
server.cnf:myisam-recover = BACKUP
server.cnf:[mysqld-5.6]
server.cnf:myisam-recover-options = BACKUP
server.cnf:[mysqld-5.7]
server.cnf:myisam-recover-options = BACKUP
server.cnf:[mysqld_safe]
server.cnf:log-error = /var/log/mariadb/mariadb.log
server.cnf:nice = 0
server.cnf:socket = /var/lib/mysql/mysql.sock
server.cnf:[mysqldump]
server.cnf:max_allowed_packet = 500M
server.cnf:quick
server.cnf:quote-names
any ideas? Howto troubleshoot?
Update after comments:
fragmentation on Prd
> select ENGINE, TABLE_NAME,Round( DATA_LENGTH/1024/1024) as data_length , round(INDEX_LENGTH/1024/1024) as index_length, round(DATA_FREE/ 1024/1024) as data_free, (data_free/(index_length+data_length)) as frag_ratio from information_schema.tables where DATA_FREE > 0 and TABLE_SCHEMA = 'exampledb' order by frag_ratio desc;
+--------+------------------------------------------------+-------------+--------------+-----------+------------+
| ENGINE | TABLE_NAME | data_length | index_length | data_free | frag_ratio |
+--------+------------------------------------------------+-------------+--------------+-----------+------------+
| InnoDB | security_group_request_rule | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | BATCH_STEP_EXECUTION_SEQ | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | role_invitation_account_role | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | BATCH_JOB_SEQ | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | BATCH_JOB_EXECUTION_SEQ | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | zerm_process_uninstall_status_transition | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | zerm_process_install_status_transition | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | security_group_request | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | security_group_definition_rule | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | zerm_ca_registration | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | country | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | buildpackdata | 0 | 0 | 1178 | 75392.0000 |
| InnoDB | security_group_definition | 0 | 0 | 1178 | 37696.0000 |
| InnoDB | servicedata | 0 | 0 | 1178 | 37696.0000 |
| InnoDB | security_zone | 0 | 0 | 1178 | 37696.0000 |
| InnoDB | role_invitation_account_status_transition | 0 | 0 | 1178 | 25130.6667 |
| InnoDB | user_management_local_user | 0 | 0 | 1178 | 25130.6667 |
| InnoDB | role_invitation_account | 0 | 0 | 1178 | 18848.0000 |
| InnoDB | zerm_process_revoke_status_transition | 0 | 0 | 1178 | 18848.0000 |
| InnoDB | schema_version | 0 | 0 | 1178 | 18848.0000 |
fragmentation on Int
> select ENGINE, TABLE_NAME,Round( DATA_LENGTH/1024/1024) as data_length , round(INDEX_LENGTH/1024/1024) as index_length, round(DATA_FREE/ 1024/1024) as data_free, (data_free/(index_length+data_length)) as frag_ratio from information_schema.tables where DATA_FREE > 0 and TABLE_SCHEMA = 'exampledb' order by frag_ratio desc;
+--------+------------------------------------------------+-------------+--------------+-----------+------------+
| ENGINE | TABLE_NAME | data_length | index_length | data_free | frag_ratio |
+--------+------------------------------------------------+-------------+--------------+-----------+------------+
| InnoDB | BATCH_JOB_SEQ | 0 | 0 | 11 | 704.0000 |
| InnoDB | security_group_request_rule | 0 | 0 | 11 | 704.0000 |
| InnoDB | security_group_request | 0 | 0 | 11 | 704.0000 |
| InnoDB | BATCH_JOB_EXECUTION_SEQ | 0 | 0 | 11 | 704.0000 |
| InnoDB | security_group_definition_rule | 0 | 0 | 11 | 704.0000 |
| InnoDB | user_preference | 0 | 0 | 11 | 704.0000 |
| InnoDB | zerm_process_renew_status_transition | 0 | 0 | 11 | 704.0000 |
| InnoDB | country | 0 | 0 | 11 | 704.0000 |
| InnoDB | role_invitation_account_role | 0 | 0 | 11 | 704.0000 |
| InnoDB | buildpackdata | 0 | 0 | 11 | 704.0000 |
| InnoDB | BATCH_STEP_EXECUTION_SEQ | 0 | 0 | 11 | 704.0000 |
| InnoDB | zerm_ca_registration | 0 | 0 | 11 | 704.0000 |
| InnoDB | security_zone | 0 | 0 | 11 | 352.0000 |
| InnoDB | security_group_definition | 0 | 0 | 11 | 352.0000 |
| InnoDB | filter_account_organization | 0 | 0 | 11 | 352.0000 |
| InnoDB | zerm_challenge | 0 | 0 | 11 | 352.0000 |
| InnoDB | servicedata | 0 | 0 | 11 | 352.0000 |
| InnoDB | user_management_local_user | 0 | 0 | 11 | 234.6667 |
| InnoDB | zerm_process_install_status_transition | 0 | 0 | 11 | 234.6667 |
| InnoDB | schema_version | 0 | 0 | 11 | 176.0000 |
| InnoDB | zerm_process_uninstall_status_transition | 0 | 0 | 11 | 176.0000 |
| InnoDB | role_invitation_space_role | 0 | 0 | 11 | 117.3333 |
| InnoDB | role_invitation_account_status_transition | 0 | 0 | 11 | 117.3333 |
| InnoDB | role_invitation_account | 0 | 0 | 11 | 117.3333 |
| InnoDB | filter_account_user | 0 | 0 | 11 | 88.0000 |
| InnoDB | role_invitation_space | 0 | 0 | 11 | 54.1538 |
| InnoDB | zerm_process_revoke_status_transition | 0 | 0 | 11 | 44.0000 |
Network latency between nodes. The values almost the same for Prd env. The Prd env also 3 node Galera cluster. But anyway network latency doesn't matter with a SELECT? It query one node local. Do I understand wrong?
node1 # ping -c 3 192.168.5.32
PING 192.168.5.32 (192.168.5.32) 56(84) bytes of data.
64 bytes from 192.168.5.32: icmp_seq=1 ttl=64 time=0.384 ms
64 bytes from 192.168.5.32: icmp_seq=2 ttl=64 time=0.334 ms
64 bytes from 192.168.5.32: icmp_seq=3 ttl=64 time=0.265 ms
--- 192.168.5.32 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2000ms
rtt min/avg/max/mdev = 0.265/0.327/0.384/0.053 ms
node1 # ping -c 3 192.168.5.33
PING 192.168.5.33 (192.168.5.33) 56(84) bytes of data.
64 bytes from 192.168.5.33: icmp_seq=1 ttl=64 time=0.284 ms
64 bytes from 192.168.5.33: icmp_seq=2 ttl=64 time=0.370 ms
64 bytes from 192.168.5.33: icmp_seq=3 ttl=64 time=0.460 ms
--- 192.168.5.33 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 1999ms
rtt min/avg/max/mdev = 0.284/0.371/0.460/0.073 ms
node2 # ping -c 3 192.168.5.31
PING 192.168.5.31 (192.168.5.31) 56(84) bytes of data.
64 bytes from 192.168.5.31: icmp_seq=1 ttl=64 time=0.319 ms
64 bytes from 192.168.5.31: icmp_seq=2 ttl=64 time=0.331 ms
64 bytes from 192.168.5.31: icmp_seq=3 ttl=64 time=0.414 ms
--- 192.168.5.31 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 1999ms
rtt min/avg/max/mdev = 0.319/0.354/0.414/0.047 ms
node 3 # ping -c 3 192.168.5.32
PING 192.168.5.32 (192.168.5.32) 56(84) bytes of data.
64 bytes from 192.168.5.32: icmp_seq=1 ttl=64 time=0.292 ms
64 bytes from 192.168.5.32: icmp_seq=2 ttl=64 time=0.210 ms
64 bytes from 192.168.5.32: icmp_seq=3 ttl=64 time=0.310 ms
--- 192.168.5.32 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 1999ms
rtt min/avg/max/mdev = 0.210/0.270/0.310/0.047 ms
disk I/O "benchmark"
int # ioping -c 8 /var/lib/mysql/data/
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=1 time=736 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=2 time=819 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=3 time=1.1 ms
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=4 time=902 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=5 time=869 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=6 time=945 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=7 time=898 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=8 time=1.1 ms
--- /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv) ioping statistics ---
8 requests completed in 7.0 s, 1.1 k iops, 4.2 MiB/s
min/avg/max/mdev = 736 us / 921 us / 1.1 ms / 118 us
prd # ioping -c 8 /var/lib/mysql/data/
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=1 time=498 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=2 time=1.0 ms
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=3 time=1.0 ms
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=4 time=933 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=5 time=655 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=6 time=781 us
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=7 time=1.9 ms
4.0 KiB from /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv): request=8 time=2.1 ms
--- /var/lib/mysql/data/ (ext4 /dev/mapper/vdatavg-mysql_datalv) ioping statistics ---
8 requests completed in 7.0 s, 900 iops, 3.5 MiB/s
min/avg/max/mdev = 498 us / 1.1 ms / 2.1 ms / 542 us
I don't know details about the query. It's from developers. The main question why do big performance difference between to clusters (Int, Prd).
Best Answer
Alas, this addresses some side issues, but not the original question of "why is a particular
SELECTsignificantly slower in one system than another".The tables are so tiny that
OPTIMIZEandANALYZEare really irrelevant.Data_freeis confusing. Let me explain.When you have
innodb_file_per_table=OFF, all subsequently created InnoDB tables will be put into a single "tablespace", the fileibdata1. That file will grow, but never shrink.DELETEandDROP TABLEwill, instead, put the blocks into the "free" space, which will be held for futureINSERTs,CREATE TABLE, etc. In one machine you have 1178MB "free"; in the other you have only 11. That is, one server had a lot of growth, followed by shrinkage; the other did not.Although it is possible to shrink
ibdata1, it is painful, and rarely worth the effort. The size of the file has no impact on performance. Unless you really need to recover some of that 1178MB for something other than table growth, I would do nothing.Sub-millisecond ping time tells me that you are not using Galera to protect against floods, earthquakes, tornadoes, etc.
SELECTscare only about the latency from the client to the chosen node.INSERTsdo care about the maximum latency.