1

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).

  • "100x more" -- more what? – Rick James Jan 17 '17 at 23:09
  • What is the ping time between the nodes? – Rick James Jan 17 '17 at 23:09
  • What the heck is that query trying to do? It smells like it is much more complex than necessary. – Rick James Jan 17 '17 at 23:16
  • Is Prd also running a 3-node Galera cluster? – Rick James Jan 17 '17 at 23:20
1

Alas, this addresses some side issues, but not the original question of "why is a particular SELECT significantly slower in one system than another".

The tables are so tiny that OPTIMIZE and ANALYZE are really irrelevant.

Data_free is 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 file ibdata1. That file will grow, but never shrink. DELETE and DROP TABLE will, instead, put the blocks into the "free" space, which will be held for future INSERTs, 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.

SELECTs care only about the latency from the client to the chosen node. INSERTs do care about the maximum latency.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.