simple update slow (status "query end" takes 99% of the time)

[Arkadiy Arkadiy]

Hello,

I have noticed that a simple UPDATE takes too long in the "query end" status (88ms out of 90ms total).

MariaDB [sms_pay]> update `balance` set `balance`='300' WHERE `user_id`='1';

Query OK, 1 row affected (0.09 sec)

MariaDB [balance]> show profile for query 1;

+--------------------------------+----------+

| Status                         | Duration |

+--------------------------------+----------+

| starting                       | 0.000084 |

| checking permissions           | 0.000011 |

| Opening tables                 | 0.000021 |

| After opening tables           | 0.000010 |

| System lock                    | 0.000009 |

| Table lock                     | 0.000007 |

| init                           | 0.000046 |

| updating                       | 0.000193 |

| end                            | 0.000008 |

| Waiting for query cache lock   | 0.000007 |

| end                            | 0.000444 |

| query end                      | 0.088475 |

| innobase_commit_low():trx_comm | 0.000110 |

| query end                      | 0.000046 |

| closing tables                 | 0.000009 |

| Unlocking tables               | 0.000021 |

| freeing items                  | 0.000012 |

| updating status                | 0.000023 |

| cleaning up                    | 0.000008 |

+--------------------------------+----------+

I have a single node setup + mariadb arbitrator. Second node will be coming up soon, once I get all the issues sorted out.

The `balance` table is only 12 megabytes big. 

I suspect a problem in the replication certification mechanism, however I can't pinpoint the exact problem or tune it.

Here are my status and variables.

Variable_name	Value
Aborted_clients	6813
Aborted_connects	3248
Access_denied_errors	0
Acl_column_grants	0
Acl_database_grants	13
Acl_function_grants	0
Acl_procedure_grants	0
Acl_proxy_users	2
Acl_role_grants	0
Acl_roles	0
Acl_table_grants	0
Acl_users	21
Aria_pagecache_blocks_not_flushed	0
Aria_pagecache_blocks_unused	15706
Aria_pagecache_blocks_used	30
Aria_pagecache_read_requests	586185
Aria_pagecache_reads	57733
Aria_pagecache_write_requests	119678
Aria_pagecache_writes	0
Aria_transaction_log_syncs	0
Binlog_commits	0
Binlog_group_commits	0
Binlog_group_commit_trigger_count	0
Binlog_group_commit_trigger_lock_wait	0
Binlog_group_commit_trigger_timeout	0
Binlog_snapshot_file
Binlog_snapshot_position	0
Binlog_bytes_written	0
Binlog_cache_disk_use	12796
Binlog_cache_use	19853806
Binlog_stmt_cache_disk_use	0
Binlog_stmt_cache_use	0
Busy_time	0.000000
Bytes_received	566
Bytes_sent	13665
Com_admin_commands	0
Com_alter_db	0
Com_alter_db_upgrade	0
Com_alter_event	0
Com_alter_function	0
Com_alter_procedure	0
Com_alter_server	0
Com_alter_table	0
Com_alter_tablespace	0
Com_analyze	0
Com_assign_to_keycache	0
Com_begin	0
Com_binlog	0
Com_call_procedure	0
Com_change_db	2
Com_change_master	0
Com_check	0
Com_checksum	0
Com_commit	0
Com_compound_sql	0
Com_create_db	0
Com_create_event	0
Com_create_function	0
Com_create_index	0
Com_create_procedure	0
Com_create_role	0
Com_create_server	0
Com_create_table	0
Com_create_temporary_table	0
Com_create_trigger	0
Com_create_udf	0
Com_create_user	0
Com_create_view	0
Com_dealloc_sql	0
Com_delete	0
Com_delete_multi	0
Com_do	0
Com_drop_db	0
Com_drop_event	0
Com_drop_function	0
Com_drop_index	0
Com_drop_procedure	0
Com_drop_role	0
Com_drop_server	0
Com_drop_table	0
Com_drop_temporary_table	0
Com_drop_trigger	0
Com_drop_user	0
Com_drop_view	0
Com_empty_query	0
Com_execute_sql	0
Com_flush	0
Com_get_diagnostics	0
Com_grant	0
Com_grant_role	0
Com_ha_close	0
Com_ha_open	0
Com_ha_read	0
Com_help	0
Com_insert	0
Com_insert_select	0
Com_install_plugin	0
Com_kill	0
Com_load	0
Com_lock_tables	0
Variable_name	Value
Com_optimize	0
Com_preload_keys	0
Com_prepare_sql	0
Com_purge	0
Com_purge_before_date	0
Com_release_savepoint	0
Com_rename_table	0
Com_rename_user	0
Com_repair	0
Com_replace	0
Com_replace_select	0
Com_reset	0
Com_resignal	0
Com_revoke	0
Com_revoke_all	0
Com_revoke_role	0
Com_rollback	0
Com_rollback_to_savepoint	0
Com_savepoint	0
Com_select	2
Com_set_option	5
Com_show_authors	0
Com_show_binlog_events	0
Com_show_binlogs	0
Com_show_charsets	1
Com_show_collations	1
Com_show_contributors	0
Com_show_create_db	0
Com_show_create_event	0
Com_show_create_func	0
Com_show_create_proc	0
Com_show_create_table	0
Com_show_create_trigger	0
Com_show_databases	1
Com_show_engine_logs	0
Com_show_engine_mutex	0
Com_show_engine_status	0
Com_show_errors	0
Com_show_events	0
Com_show_explain	0
Com_show_fields	0
Com_show_function_status	0
Com_show_generic	0
Com_show_grants	1
Com_show_keys	0
Com_show_master_status	0
Com_show_open_tables	0
Com_show_plugins	0
Com_show_privileges	0
Com_show_procedure_status	0
Com_show_processlist	0
Com_show_profile	0
Com_show_profiles	0
Com_show_relaylog_events	0
Com_show_slave_hosts	0
Com_show_slave_status	0
Com_show_status	1
Com_show_storage_engines	0
Com_show_table_status	0
Com_show_tables	0
Com_show_triggers	0
Com_show_variables	3
Com_show_warnings	0
Com_shutdown	0
Com_signal	0
Com_start_all_slaves	0
Com_start_slave	0
Com_stmt_close	0
Com_stmt_execute	0
Com_stmt_fetch	0
Com_stmt_prepare	0
Com_stmt_reprepare	0
Com_stmt_reset	0
Com_stmt_send_long_data	0
Com_stop_all_slaves	0
Com_stop_slave	0
Com_truncate	0
Com_uninstall_plugin	0
Com_unlock_tables	0
Com_update	0
Com_update_multi	0
Com_xa_commit	0
Com_xa_end	0
Com_xa_prepare	0
Com_xa_recover	0
Com_xa_rollback	0
Com_xa_start	0
Compression	OFF
Connection_errors_accept	0
Connection_errors_internal	0
Connection_errors_max_connections	0
Connection_errors_peer_address	0
Connection_errors_select	0
Connection_errors_tcpwrap	0
Connections	68691119
Cpu_time	0.000000
Created_tmp_disk_tables	0
Created_tmp_files	5736
Created_tmp_tables	6
Delayed_errors	0
Variable_name	Value
Delayed_insert_threads	0
Delayed_writes	0
Empty_queries	0
Executed_events	0
Executed_triggers	0
Feature_delay_key_write	0
Feature_dynamic_columns	0
Feature_fulltext	0
Feature_gis	0
Feature_locale	0
Feature_subquery	0
Feature_timezone	0
Feature_trigger	0
Feature_xml	0
Flush_commands	1
Handler_commit	0
Handler_delete	0
Handler_discover	0
Handler_external_lock	0
Handler_icp_attempts	0
Handler_icp_match	0
Handler_mrr_init	0
Handler_mrr_key_refills	0
Handler_mrr_rowid_refills	0
Handler_prepare	0
Handler_read_first	0
Handler_read_key	0
Handler_read_last	0
Handler_read_next	0
Handler_read_prev	0
Handler_read_rnd	0
Handler_read_rnd_deleted	0
Handler_read_rnd_next	328
Handler_rollback	0
Handler_savepoint	0
Handler_savepoint_rollback	0
Handler_tmp_update	0
Handler_tmp_write	322
Handler_update	0
Handler_write	0
Innodb_available_undo_logs	128
Innodb_background_log_sync	413083
Innodb_buffer_pool_bytes_data	18185732096
Innodb_buffer_pool_bytes_dirty	148668416
Innodb_buffer_pool_dump_status	Dumping buffer pool(s) not yet started
Innodb_buffer_pool_load_status	Loading buffer pool(s) not yet started
Innodb_buffer_pool_pages_data	1109969
Innodb_buffer_pool_pages_dirty	9074
Innodb_buffer_pool_pages_flushed	8196171
Innodb_buffer_pool_pages_free	32768
Innodb_buffer_pool_pages_lru_flushed	0
Innodb_buffer_pool_pages_made_not_young	133616849
Innodb_buffer_pool_pages_made_young	21822986
Innodb_buffer_pool_pages_misc	167975
Innodb_buffer_pool_pages_old	409571
Innodb_buffer_pool_pages_total	1310712
Innodb_buffer_pool_read_ahead	55831
Innodb_buffer_pool_read_ahead_evicted	0
Innodb_buffer_pool_read_ahead_rnd	0
Innodb_buffer_pool_read_requests	12119685556
Innodb_buffer_pool_reads	6716718
Innodb_buffer_pool_wait_free	0
Innodb_buffer_pool_write_requests	1391559012
Innodb_checkpoint_age	50799239
Innodb_checkpoint_max_age	434154333
Innodb_data_fsyncs	2646682
Innodb_data_pending_fsyncs	0
Innodb_data_pending_reads	0
Innodb_data_pending_writes	0
Innodb_data_read	114217963520
Innodb_data_reads	6978275
Innodb_data_writes	9322637
Innodb_data_written	197774806528
Innodb_dblwr_pages_written	0
Innodb_dblwr_writes	0
Innodb_deadlocks	123
Innodb_have_atomic_builtins	ON
Innodb_history_list_length	2655
Innodb_ibuf_discarded_delete_marks	0
Innodb_ibuf_discarded_deletes	0
Innodb_ibuf_discarded_inserts	0
Innodb_ibuf_free_list	201
Innodb_ibuf_merged_delete_marks	143065
Innodb_ibuf_merged_deletes	24252
Innodb_ibuf_merged_inserts	198810
Innodb_ibuf_merges	235373
Innodb_ibuf_segment_size	203
Innodb_ibuf_size	1
Innodb_log_waits	0
Innodb_log_write_requests	143124863
Innodb_log_writes	1065756
Innodb_lsn_current	416441890849
Innodb_lsn_flushed	416441827897
Innodb_lsn_last_checkpoint	416391091610
Innodb_master_thread_active_loops	412744
Innodb_master_thread_idle_loops	339
Innodb_max_trx_id	897860629
Innodb_mem_adaptive_hash	3092101648
Innodb_mem_dictionary	106718204
Innodb_mem_total	22145925120
Variable_name	Value
Innodb_mutex_os_waits	4994538
Innodb_mutex_spin_rounds	234051887
Innodb_mutex_spin_waits	34950965
Innodb_oldest_view_low_limit_trx_id	0
Innodb_os_log_fsyncs	0
Innodb_os_log_pending_fsyncs	0
Innodb_os_log_pending_writes	0
Innodb_os_log_written	64949106176
Innodb_os_merge_buffers_written	0
Innodb_os_merge_buffers_read	0
Innodb_os_merge_buffers_merged	0
Innodb_page_size	16384
Innodb_pages_created	2430155
Innodb_pages_read	6971401
Innodb_pages_written	8198333
Innodb_purge_trx_id	897860615
Innodb_purge_undo_no	0
Innodb_read_views_memory	12008
Innodb_row_lock_current_waits	9
Innodb_row_lock_time	138131225
Innodb_row_lock_time_avg	183
Innodb_row_lock_time_max	51562
Innodb_row_lock_waits	752654
Innodb_rows_deleted	9701120
Innodb_rows_inserted	163185923
Innodb_rows_read	3179666059
Innodb_rows_updated	11417195
Innodb_system_rows_deleted	0
Innodb_system_rows_inserted	0
Innodb_system_rows_read	0
Innodb_system_rows_updated	0
Innodb_s_lock_os_waits	1319702
Innodb_s_lock_spin_rounds	55277816
Innodb_s_lock_spin_waits	5251346
Innodb_truncated_status_writes	0
Innodb_x_lock_os_waits	1626541
Innodb_x_lock_spin_rounds	83826186
Innodb_x_lock_spin_waits	11779857
Innodb_page_compression_saved	0
Innodb_page_compression_trim_sect512	0
Innodb_page_compression_trim_sect1024	0
Innodb_page_compression_trim_sect2048	0
Innodb_page_compression_trim_sect4096	0
Innodb_page_compression_trim_sect8192	0
Innodb_page_compression_trim_sect16384	0
Innodb_page_compression_trim_sect32768	0
Innodb_num_index_pages_written	7607507
Innodb_num_non_index_pages_written	1643158
Innodb_num_pages_page_compressed	0
Innodb_num_page_compressed_trim_op	0
Innodb_num_page_compressed_trim_op_saved	0
Innodb_num_pages_page_decompressed	0
Innodb_num_pages_page_compression_error	0
Innodb_num_pages_encrypted	0
Innodb_num_pages_decrypted	0
Innodb_have_lz4	OFF
Innodb_have_lzo	OFF
Innodb_have_lzma	OFF
Innodb_have_bzip2	OFF
Innodb_have_snappy	OFF
Innodb_defragment_compression_failures	0
Innodb_defragment_failures	0
Innodb_defragment_count	1
Innodb_onlineddl_rowlog_rows	0
Innodb_onlineddl_rowlog_pct_used	0
Innodb_onlineddl_pct_progress	0
Innodb_secondary_index_triggered_cluster_reads	2096242000
Innodb_secondary_index_triggered_cluster_reads_avo...	0
Innodb_encryption_rotation_pages_read_from_cache	0
Innodb_encryption_rotation_pages_read_from_disk	0
Innodb_encryption_rotation_pages_modified	0
Innodb_encryption_rotation_pages_flushed	0
Innodb_encryption_rotation_estimated_iops	0
Innodb_scrub_background_page_reorganizations	0
Innodb_scrub_background_page_splits	0
Innodb_scrub_background_page_split_failures_underf...	0
Innodb_scrub_background_page_split_failures_out_of...	0
Innodb_scrub_background_page_split_failures_missin...	0
Innodb_scrub_background_page_split_failures_unknow...	0
Key_blocks_not_flushed	0
Key_blocks_unused	208818
Key_blocks_used	72905
Key_blocks_warm	1356
Key_read_requests	36705945
Key_reads	480337
Key_write_requests	1943016
Key_writes	1654708
Last_query_cost	0.000000
Master_gtid_wait_count	0
Master_gtid_wait_time	0
Master_gtid_wait_timeouts	0
Max_statement_time_exceeded	0
Max_used_connections	167
Memory_used	2606200
Not_flushed_delayed_rows	0
Open_files	64
Open_streams	0
Open_table_definitions	2048
Open_tables	2047
Opened_files	258527
Variable_name	Value
Opened_plugin_libraries	0
Opened_table_definitions	0
Opened_tables	0
Opened_views	0
Performance_schema_accounts_lost	0
Performance_schema_cond_classes_lost	0
Performance_schema_cond_instances_lost	0
Performance_schema_digest_lost	0
Performance_schema_file_classes_lost	0
Performance_schema_file_handles_lost	0
Performance_schema_file_instances_lost	0
Performance_schema_hosts_lost	0
Performance_schema_locker_lost	0
Performance_schema_mutex_classes_lost	0
Performance_schema_mutex_instances_lost	0
Performance_schema_rwlock_classes_lost	0
Performance_schema_rwlock_instances_lost	0
Performance_schema_session_connect_attrs_lost	0
Performance_schema_socket_classes_lost	0
Performance_schema_socket_instances_lost	0
Performance_schema_stage_classes_lost	0
Performance_schema_statement_classes_lost	0
Performance_schema_table_handles_lost	0
Performance_schema_table_instances_lost	0
Performance_schema_thread_classes_lost	0
Performance_schema_thread_instances_lost	0
Performance_schema_users_lost	0
Prepared_stmt_count	0
Qcache_free_blocks	16563
Qcache_free_memory	26549840
Qcache_hits	173212714
Qcache_inserts	244135727
Qcache_lowmem_prunes	131053954
Qcache_not_cached	24440791
Qcache_queries_in_cache	53590
Qcache_total_blocks	132103
Queries	791823026
Questions	17
Rows_read	0
Rows_sent	324
Rows_tmp_read	322
Rpl_status	AUTH_MASTER
Select_full_join	0
Select_full_range_join	0
Select_range	0
Select_range_check	0
Select_scan	6
Slave_heartbeat_period	0.000
Slave_open_temp_tables	0
Slave_received_heartbeats	0
Slave_retried_transactions	0
Slave_running	OFF
Slave_skipped_errors	0
Slow_launch_threads	0
Slow_queries	0
Sort_merge_passes	0
Sort_priority_queue_sorts	0
Sort_range	0
Sort_rows	0
Sort_scan	0
Ssl_accept_renegotiates	0
Ssl_accepts	0
Ssl_callback_cache_hits	0
Ssl_cipher
Ssl_cipher_list
Ssl_client_connects	0
Ssl_connect_renegotiates	0
Ssl_ctx_verify_depth	0
Ssl_ctx_verify_mode	0
Ssl_default_timeout	0
Ssl_finished_accepts	0
Ssl_finished_connects	0
Ssl_server_not_after
Ssl_server_not_before
Ssl_session_cache_hits	0
Ssl_session_cache_misses	0
Ssl_session_cache_mode	NONE
Ssl_session_cache_overflows	0
Ssl_session_cache_size	0
Ssl_session_cache_timeouts	0
Ssl_sessions_reused	0
Ssl_used_session_cache_entries	0
Ssl_verify_depth	0
Ssl_verify_mode	0
Ssl_version
Subquery_cache_hit	174
Subquery_cache_miss	11578
Syncs	6729823
Table_locks_immediate	359663303
Table_locks_waited	221264
Tc_log_max_pages_used	5
Tc_log_page_size	4096
Tc_log_page_waits	0
Threadpool_idle_threads	0
Threadpool_threads	0
Threads_cached	77
Threads_connected	55
Threads_created	204
Threads_running	6
Uptime	425320
Variable_name	Value
Uptime_since_flush_status	425320
wsrep_apply_oooe	0.967535
wsrep_apply_oool	0.102096
wsrep_apply_window	40.363113
wsrep_causal_reads	0
wsrep_cert_deps_distance	144.516962
wsrep_cert_index_size	362
wsrep_cert_interval	39.426981
wsrep_cluster_conf_id	10
wsrep_cluster_size	2
wsrep_cluster_state_uuid	e723b34f-cd4b-11e5-b1ac-0a35a44cd2b1
wsrep_cluster_status	Primary
wsrep_commit_oooe	0.967521
wsrep_commit_oool	0.101912
wsrep_commit_window	40.361290
wsrep_connected	ON
wsrep_evs_delayed	1d9b29f2-ce0d-11e5-8ef7-7ac5a74def36:tcp://10.0.0....
wsrep_evs_evict_list
wsrep_evs_repl_latency	7.5732e-05/0.000167778/0.00245073/0.000137499/1086
wsrep_evs_state	OPERATIONAL
wsrep_flow_control_paused	0.000000
wsrep_flow_control_paused_ns	0
wsrep_flow_control_recv	0
wsrep_flow_control_sent	0
wsrep_gcomm_uuid	5ec42147-cd4d-11e5-9fda-7eba879ccc2f
wsrep_incoming_addresses	10.0.0.57:3306,
wsrep_last_committed	19863837
wsrep_local_bf_aborts	0
wsrep_local_cached_downto	12816434
wsrep_local_cert_failures	172739
wsrep_local_commits	19682559
wsrep_local_index	0
wsrep_local_recv_queue	0
wsrep_local_recv_queue_avg	0.001880
wsrep_local_recv_queue_max	3
wsrep_local_recv_queue_min	0
wsrep_local_replays	0
wsrep_local_send_queue	0
wsrep_local_send_queue_avg	0.122783
wsrep_local_send_queue_max	73
wsrep_local_send_queue_min	0
wsrep_local_state	4
wsrep_local_state_comment	Synced
wsrep_local_state_uuid	e723b34f-cd4b-11e5-b1ac-0a35a44cd2b1
wsrep_protocol_version	7
wsrep_provider_name	Galera
wsrep_provider_vendor	Codership Oy <in...@codership.com>
wsrep_provider_version	25.3.9(r3385)
wsrep_ready	ON
wsrep_received	160097
wsrep_received_bytes	1284111
wsrep_repl_data_bytes	6756463605
wsrep_repl_keys	77603014
wsrep_repl_keys_bytes	1077920002
wsrep_repl_other_bytes	0
wsrep_replicated	19863352
wsrep_replicated_bytes	9173972310
wsrep_thread_count	33

Variable_name	Value
aria_block_size	8192
aria_checkpoint_interval	30
aria_checkpoint_log_activity	1048576
aria_encrypt_tables	OFF
aria_force_start_after_recovery_failures	0
aria_group_commit	none
aria_group_commit_interval	0
aria_log_file_size	1073741824
aria_log_purge_type	immediate
aria_max_sort_file_size	9223372036853727232
aria_page_checksum	ON
aria_pagecache_age_threshold	300
aria_pagecache_buffer_size	134217728
aria_pagecache_division_limit	100
aria_pagecache_file_hash_size	512
aria_recover	NORMAL
aria_repair_threads	1
aria_sort_buffer_size	268434432
aria_stats_method	nulls_unequal
aria_sync_log_dir	NEWFILE
aria_used_for_temp_tables	ON
auto_increment_increment	2
auto_increment_offset	1
autocommit	ON
automatic_sp_privileges	ON
back_log	210
basedir	/usr
big_tables	OFF
binlog_annotate_row_events	OFF
binlog_cache_size	32768
binlog_checksum	CRC32
binlog_commit_wait_count	0
binlog_commit_wait_usec	100000
binlog_direct_non_transactional_updates	OFF
binlog_format	ROW
binlog_optimize_thread_scheduling	ON
binlog_row_image	FULL
binlog_stmt_cache_size	32768
bulk_insert_buffer_size	8388608
character_set_client	utf8
character_set_connection	utf8
character_set_database	latin1
character_set_filesystem	binary
character_set_results	utf8
character_set_server	latin1
character_set_system	utf8
character_sets_dir	/usr/share/mysql/charsets/
collation_connection	utf8_unicode_ci
collation_database	latin1_swedish_ci
collation_server	latin1_swedish_ci
completion_type	NO_CHAIN
concurrent_insert	AUTO
connect_timeout	600000
datadir	/var/lib/mysql/
date_format	%Y-%m-%d
datetime_format	%Y-%m-%d %H:%i:%s
deadlock_search_depth_long	15
deadlock_search_depth_short	4
deadlock_timeout_long	50000000
deadlock_timeout_short	10000
debug_no_thread_alarm	OFF
default_master_connection
default_regex_flags
default_storage_engine	InnoDB
default_tmp_storage_engine
default_week_format	0
delay_key_write	ON
delayed_insert_limit	100
delayed_insert_timeout	300
delayed_queue_size	1000
div_precision_increment	4
encrypt_binlog	OFF
encrypt_tmp_disk_tables	OFF
encrypt_tmp_files	OFF
enforce_storage_engine
error_count	0
event_scheduler	ON
expensive_subquery_limit	100
expire_logs_days	3
explicit_defaults_for_timestamp	OFF
external_user
extra_max_connections	1
extra_port	0
flush	OFF
flush_time	0
foreign_key_checks	ON
ft_boolean_syntax	+ -><()~*:""&|
ft_max_word_len	84
ft_min_word_len	4
ft_query_expansion_limit	20
ft_stopword_file	(built-in)
general_log	OFF
general_log_file	mariadb-02.log
group_concat_max_len	1024
gtid_binlog_pos
gtid_binlog_state
gtid_current_pos
gtid_domain_id	0
gtid_ignore_duplicates	OFF
gtid_seq_no	0
Variable_name	Value
gtid_slave_pos
gtid_strict_mode	OFF
have_compress	YES
have_crypt	YES
have_dynamic_loading	YES
have_geometry	YES
have_openssl	YES
have_profiling	YES
have_query_cache	YES
have_rtree_keys	YES
have_ssl	DISABLED
have_symlink	DISABLED
histogram_size	0
histogram_type	SINGLE_PREC_HB
host_cache_size	643
hostname	mariadb-02.local
identity	0
ignore_builtin_innodb	OFF
ignore_db_dirs
in_transaction	0
init_connect
init_file
init_slave
innodb_adaptive_flushing	ON
innodb_adaptive_flushing_lwm	10.000000
innodb_adaptive_hash_index	ON
innodb_adaptive_hash_index_partitions	1
innodb_adaptive_max_sleep_delay	150000
innodb_additional_mem_pool_size	8388608
innodb_api_bk_commit_interval	5
innodb_api_disable_rowlock	OFF
innodb_api_enable_binlog	OFF
innodb_api_enable_mdl	OFF
innodb_api_trx_level	0
innodb_autoextend_increment	64
innodb_autoinc_lock_mode	2
innodb_background_scrub_data_check_interval	3600
innodb_background_scrub_data_compressed	OFF
innodb_background_scrub_data_interval	604800
innodb_background_scrub_data_uncompressed	OFF
innodb_buf_dump_status_frequency	0
innodb_buffer_pool_dump_at_shutdown	OFF
innodb_buffer_pool_dump_now	OFF
innodb_buffer_pool_dump_pct	100
innodb_buffer_pool_filename	ib_buffer_pool
innodb_buffer_pool_instances	8
innodb_buffer_pool_load_abort	OFF
innodb_buffer_pool_load_at_startup	OFF
innodb_buffer_pool_load_now	OFF
innodb_buffer_pool_populate	OFF
innodb_buffer_pool_size	21474836480
innodb_change_buffer_max_size	25
innodb_change_buffering	all
innodb_checksum_algorithm	CRC32
innodb_checksums	ON
innodb_cleaner_lsn_age_factor	HIGH_CHECKPOINT
innodb_cmp_per_index_enabled	OFF
innodb_commit_concurrency	0
innodb_compression_algorithm	none
innodb_compression_failure_threshold_pct	5
innodb_compression_level	6
innodb_compression_pad_pct_max	50
innodb_concurrency_tickets	5000
innodb_corrupt_table_action	assert
innodb_data_file_path	ibdata1:10M:autoextend
innodb_data_home_dir
innodb_default_encryption_key_id	1
innodb_defragment	ON
innodb_defragment_fill_factor	0.900000
innodb_defragment_fill_factor_n_recs	20
innodb_defragment_frequency	40
innodb_defragment_n_pages	7
innodb_defragment_stats_accuracy	0
innodb_disable_sort_file_cache	OFF
innodb_disallow_writes	OFF
innodb_doublewrite	OFF
innodb_empty_free_list_algorithm	BACKOFF
innodb_encrypt_log	OFF
innodb_encrypt_tables	OFF
innodb_encryption_rotate_key_age	1
innodb_encryption_rotation_iops	100
innodb_encryption_threads	0
innodb_fake_changes	OFF
innodb_fast_shutdown	1
innodb_fatal_semaphore_wait_threshold	600
innodb_file_format	Barracuda
innodb_file_format_check	ON
innodb_file_format_max	Antelope
innodb_file_per_table	ON
innodb_flush_log_at_timeout	1
innodb_flush_log_at_trx_commit	0
innodb_flush_method	ALL_O_DIRECT
innodb_flush_neighbors	1
innodb_flushing_avg_loops	30
innodb_force_load_corrupted	OFF
innodb_force_primary_key	OFF
innodb_force_recovery	0
innodb_foreground_preflush	EXPONENTIAL_BACKOFF
innodb_ft_aux_table
innodb_ft_cache_size	8000000
Variable_name	Value
innodb_ft_enable_diag_print	OFF
innodb_ft_enable_stopword	ON
innodb_ft_max_token_size	84
innodb_ft_min_token_size	3
innodb_ft_num_word_optimize	2000
innodb_ft_result_cache_limit	2000000000
innodb_ft_server_stopword_table
innodb_ft_sort_pll_degree	2
innodb_ft_total_cache_size	640000000
innodb_ft_user_stopword_table
innodb_idle_flush_pct	100
innodb_immediate_scrub_data_uncompressed	OFF
innodb_instrument_semaphores	OFF
innodb_io_capacity	200
innodb_io_capacity_max	2000
innodb_kill_idle_transaction	0
innodb_large_prefix	OFF
innodb_lock_wait_timeout	50
innodb_locking_fake_changes	ON
innodb_locks_unsafe_for_binlog	ON
innodb_log_arch_dir	./
innodb_log_arch_expire_sec	0
innodb_log_archive	OFF
innodb_log_block_size	512
innodb_log_buffer_size	33554432
innodb_log_checksum_algorithm	INNODB
innodb_log_compressed_pages	OFF
innodb_log_file_size	268435456
innodb_log_files_in_group	2
innodb_log_group_home_dir	./
innodb_lru_scan_depth	4096
innodb_max_bitmap_file_size	104857600
innodb_max_changed_pages	1000000
innodb_max_dirty_pages_pct	75.000000
innodb_max_dirty_pages_pct_lwm	0.001000
innodb_max_purge_lag	0
innodb_max_purge_lag_delay	0
innodb_mirrored_log_groups	1
innodb_monitor_disable
innodb_monitor_enable
innodb_monitor_reset
innodb_monitor_reset_all
innodb_mtflush_threads	8
innodb_old_blocks_pct	37
innodb_old_blocks_time	1000
innodb_online_alter_log_max_size	134217728
innodb_open_files	512
innodb_optimize_fulltext_only	OFF
innodb_page_size	16384
innodb_prefix_index_cluster_optimization	OFF
innodb_print_all_deadlocks	OFF
innodb_purge_batch_size	300
innodb_purge_threads	1
innodb_random_read_ahead	OFF
innodb_read_ahead_threshold	56
innodb_read_io_threads	8
innodb_read_only	OFF
innodb_replication_delay	0
innodb_rollback_on_timeout	OFF
innodb_rollback_segments	128
innodb_sched_priority_cleaner	19
innodb_scrub_log	OFF
innodb_scrub_log_speed	256
innodb_show_locks_held	10
innodb_show_verbose_locks	0
innodb_simulate_comp_failures	0
innodb_sort_buffer_size	1048576
innodb_spin_wait_delay	6
innodb_stats_auto_recalc	ON
innodb_stats_method	nulls_equal
innodb_stats_modified_counter	0
innodb_stats_on_metadata	OFF
innodb_stats_persistent	ON
innodb_stats_persistent_sample_pages	20
innodb_stats_sample_pages	8
innodb_stats_traditional	ON
innodb_stats_transient_sample_pages	8
innodb_status_output	OFF
innodb_status_output_locks	OFF
innodb_strict_mode	OFF
innodb_support_xa	ON
innodb_sync_array_size	16
innodb_sync_spin_loops	30
innodb_table_locks	ON
innodb_thread_concurrency	0
innodb_thread_sleep_delay	10000
innodb_track_changed_pages	OFF
innodb_undo_directory	.
innodb_undo_logs	128
innodb_undo_tablespaces	0
innodb_use_atomic_writes	OFF
innodb_use_fallocate	ON
innodb_use_global_flush_log_at_trx_commit	ON
innodb_use_mtflush	ON
innodb_use_native_aio	ON
innodb_use_stacktrace	OFF
innodb_use_sys_malloc	ON
innodb_use_trim	OFF
innodb_version	5.6.26-76.0
innodb_write_io_threads	8
Variable_name	Value
insert_id	0
interactive_timeout	28800
join_buffer_size	8388608
join_buffer_space_limit	2097152
join_cache_level	2
keep_files_on_create	OFF
key_buffer_size	268435456
key_cache_age_threshold	300
key_cache_block_size	1024
key_cache_division_limit	100
key_cache_file_hash_size	512
key_cache_segments	0
large_files_support	ON
large_page_size	0
large_pages	OFF
last_gtid
last_insert_id	0
lc_messages	en_US
lc_messages_dir
lc_time_names	en_US
license	GPL
local_infile	ON
lock_wait_timeout	31536000
locked_in_memory	OFF
log_bin	OFF
log_bin_basename
log_bin_index
log_bin_trust_function_creators	OFF
log_error	/var/log/mysql/mysql-error.log
log_output	FILE
log_queries_not_using_indexes	OFF
log_slave_updates	ON
log_slow_filter	admin,filesort,filesort_on_disk,full_join,full_sca...
log_slow_rate_limit	1
log_slow_verbosity
log_tc_size	24576
log_warnings	2
long_query_time	10.000000
low_priority_updates	OFF
lower_case_file_system	OFF
lower_case_table_names	0
master_verify_checksum	ON
max_allowed_packet	536870912
max_binlog_cache_size	18446744073709547520
max_binlog_size	1073741824
max_binlog_stmt_cache_size	18446744073709547520
max_connect_errors	10000
max_connections	800
max_delayed_threads	20
max_digest_length	1024
max_error_count	64
max_heap_table_size	209715200
max_insert_delayed_threads	20
max_join_size	18446744073709551615
max_length_for_sort_data	1024
max_long_data_size	536870912
max_prepared_stmt_count	16382
max_relay_log_size	1073741824
max_seeks_for_key	4294967295
max_sort_length	1024
max_sp_recursion_depth	0
max_statement_time	0.000000
max_tmp_tables	32
max_user_connections	0
max_write_lock_count	4294967295
metadata_locks_cache_size	1024
metadata_locks_hash_instances	256
min_examined_row_limit	0
mrr_buffer_size	262144
multi_range_count	256
myisam_block_size	1024
myisam_data_pointer_size	6
myisam_max_sort_file_size	9223372036853727232
myisam_mmap_size	18446744073709551615
myisam_recover_options	DEFAULT
myisam_repair_threads	1
myisam_sort_buffer_size	134216704
myisam_stats_method	NULLS_UNEQUAL
myisam_use_mmap	OFF
mysql56_temporal_format	ON
net_buffer_length	16384
net_read_timeout	600000
net_retry_count	10
net_write_timeout	600000
old	OFF
old_alter_table	OFF
old_mode
old_passwords	OFF
open_files_limit	1048576
optimizer_prune_level	1
optimizer_search_depth	62
optimizer_selectivity_sampling_limit	100
optimizer_switch	index_merge=on,index_merge_union=on,index_merge_so...
optimizer_use_condition_selectivity	1
performance_schema	OFF
performance_schema_accounts_size	-1
performance_schema_digests_size	-1
performance_schema_events_stages_history_long_size	-1
performance_schema_events_stages_history_size	-1
performance_schema_events_statements_history_long_...	-1
Variable_name	Value
performance_schema_events_statements_history_size	-1
performance_schema_events_waits_history_long_size	-1
performance_schema_events_waits_history_size	-1
performance_schema_hosts_size	-1
performance_schema_max_cond_classes	80
performance_schema_max_cond_instances	-1
performance_schema_max_digest_length	1024
performance_schema_max_file_classes	50
performance_schema_max_file_handles	32768
performance_schema_max_file_instances	-1
performance_schema_max_mutex_classes	200
performance_schema_max_mutex_instances	-1
performance_schema_max_rwlock_classes	40
performance_schema_max_rwlock_instances	-1
performance_schema_max_socket_classes	10
performance_schema_max_socket_instances	-1
performance_schema_max_stage_classes	150
performance_schema_max_statement_classes	178
performance_schema_max_table_handles	-1
performance_schema_max_table_instances	-1
performance_schema_max_thread_classes	50
performance_schema_max_thread_instances	-1
performance_schema_session_connect_attrs_size	-1
performance_schema_setup_actors_size	100
performance_schema_setup_objects_size	100
performance_schema_users_size	-1
pid_file	/var/lib/mysql/mariadb-02.local.pid
plugin_dir	/usr/lib64/mysql/plugin/
plugin_maturity	unknown
port	3306
preload_buffer_size	32768
profiling	OFF
profiling_history_size	15
progress_report_time	5
protocol_version	10
proxy_user
pseudo_slave_mode	OFF
pseudo_thread_id	68689254
query_alloc_block_size	16384
query_cache_limit	1048576
query_cache_min_res_unit	2048
query_cache_size	134217728
query_cache_strip_comments	OFF
query_cache_type	ON
query_cache_wlock_invalidate	OFF
query_prealloc_size	24576
rand_seed1	851315877
rand_seed2	449775951
range_alloc_block_size	4096
read_buffer_size	131072
read_only	OFF
read_rnd_buffer_size	3145728
relay_log	/var/log/mysql/mysql-relay-bin
relay_log_basename	/var/log/mysql/mysql-relay-bin
relay_log_index	/var/log/mysql/mysql-relay-bin.index
relay_log_info_file	/var/log/mysql/mysql-relay-log.info
relay_log_purge	ON
relay_log_recovery	OFF
relay_log_space_limit	0
replicate_annotate_row_events	OFF
replicate_do_db
replicate_do_table
replicate_events_marked_for_skip	REPLICATE
replicate_ignore_db
replicate_ignore_table
replicate_wild_do_table
replicate_wild_ignore_table
report_host
report_password
report_port	3306
report_user
rowid_merge_buff_size	8388608
secure_auth	ON
secure_file_priv
server_id	226
skip_external_locking	ON
skip_name_resolve	ON
skip_networking	OFF
skip_parallel_replication	OFF
skip_replication	OFF
skip_show_database	OFF
slave_compressed_protocol	OFF
slave_ddl_exec_mode	IDEMPOTENT
slave_domain_parallel_threads	0
slave_exec_mode	STRICT
slave_load_tmpdir	/tmp
slave_max_allowed_packet	1073741824
slave_net_timeout	3600
slave_parallel_max_queued	131072
slave_parallel_mode	conservative
slave_parallel_threads	8
slave_run_triggers_for_rbr	NO
slave_skip_errors	1062,1146
slave_sql_verify_checksum	ON
slave_transaction_retries	10
slave_type_conversions	ALL_NON_LOSSY
slow_launch_time	2
slow_query_log	ON
slow_query_log_file	/var/log/mysql/mysql-slow.log
socket	/var/lib/mysql/mysql.sock
Variable_name	Value
sort_buffer_size	2097152
sql_auto_is_null	OFF
sql_big_selects	ON
sql_buffer_result	OFF
sql_log_bin	ON
sql_log_off	OFF
sql_mode	NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
sql_notes	ON
sql_quote_show_create	ON
sql_safe_updates	OFF
sql_select_limit	18446744073709551615
sql_slave_skip_counter	0
sql_warnings	OFF
ssl_ca
ssl_capath
ssl_cert
ssl_cipher
ssl_crl
ssl_crlpath
ssl_key
storage_engine	InnoDB
stored_program_cache	256
strict_password_validation	ON
sync_binlog	0
sync_frm	ON
sync_master_info	10000
sync_relay_log	10000
sync_relay_log_info	10000
system_time_zone	MSK
table_definition_cache	2048
table_open_cache	2048
thread_cache_size	128
thread_concurrency	10
thread_handling	one-thread-per-connection
thread_pool_idle_timeout	60
thread_pool_max_threads	1000
thread_pool_oversubscribe	3
thread_pool_size	8
thread_pool_stall_limit	500
thread_stack	294912
time_format	%H:%i:%s
time_zone	SYSTEM
timed_mutexes	OFF
timestamp	1455242088.463582
tmp_table_size	209715200
tmpdir	/tmp
transaction_alloc_block_size	8192
transaction_prealloc_size	4096
tx_isolation	READ-COMMITTED
tx_read_only	OFF
unique_checks	ON
updatable_views_with_limit	YES
use_stat_tables	NEVER
userstat	OFF
version	10.1.10-MariaDB
version_comment	MariaDB Server
version_compile_machine	x86_64
version_compile_os	Linux
version_malloc_library	system jemalloc
version_ssl_library	OpenSSL 1.0.1e-fips 11 Feb 2013
wait_timeout	28800
warning_count	0
wsrep_osu_method	TOI
wsrep_auto_increment_control	ON
wsrep_causal_reads	OFF
wsrep_certify_nonpk	ON
wsrep_cluster_address	gcomm://10.0.0.56,10.0.0.57,10.0.0.60,10.0.0.61
wsrep_cluster_name	cluster
wsrep_convert_lock_to_trx	OFF
wsrep_data_home_dir	/var/lib/mysql/
wsrep_dbug_option
wsrep_debug	OFF
wsrep_desync	OFF
wsrep_dirty_reads	OFF
wsrep_drupal_282555_workaround	OFF
wsrep_forced_binlog_format	NONE
wsrep_gtid_domain_id	0
wsrep_gtid_mode	OFF
wsrep_load_data_splitting	ON
wsrep_log_conflicts	OFF
wsrep_max_ws_rows	131072
wsrep_max_ws_size	1073741824
wsrep_mysql_replication_bundle	0
wsrep_node_address	10.0.0.57
wsrep_node_incoming_address	AUTO
wsrep_node_name	dev-db-new-02
wsrep_notify_cmd
wsrep_on	ON
wsrep_patch_version	wsrep_25.11
wsrep_provider	/usr/lib64/galera/libgalera_smm.so
wsrep_provider_options	base_host = 10.0.0.57; base_port = 4567; cert.log_...
wsrep_recover	OFF
wsrep_replicate_myisam	OFF
wsrep_restart_slave	OFF
wsrep_retry_autocommit	3
wsrep_slave_fk_checks	ON
wsrep_slave_uk_checks	OFF
wsrep_slave_threads	1
wsrep_sst_auth	********
wsrep_sst_donor
Variable_name	Value
wsrep_sst_donor_rejects_queries	OFF
wsrep_sst_method	xtrabackup-v2
wsrep_sst_receive_address	AUTO
wsrep_start_position	e723b34f-cd4b-11e5-b1ac-0a35a44cd2b1:488
wsrep_sync_wait	0

Thank you!

[James Wang]

post "show create table balance" here

also mysql and galera version

On Friday, 12 February 2016 06:41:31 UTC, Arkadiy Arkadiy wrote:

Hello,

I have noticed that a simple UPDATE takes too long in the "query end" status (88ms out of 90ms total).

MariaDB [sms_pay]> update `balance` set `balance`='300' WHERE `user_id`='1';

Query OK, 1 row affected (0.09 sec)

[Arkadiy Arkadiy]

CREATE TABLE `balance` (
 `user_id` int(10) unsigned NOT NULL DEFAULT '0',
 `balance` decimal(10,2) NOT NULL DEFAULT '0.00',
 PRIMARY KEY (`user_id`)
) ENGINE=InnoDB DEFAULT CHARSET=cp1251

Maria 10.1.10

wsrep_provider_version 25.3.9(r3385)

пятница, 12 февраля 2016 г., 16:22:24 UTC+7 пользователь James Wang написал:

[James Wang]

Suggestion: Try the same using Percona PXC 5.6 and see if you have the same issue.

Also a minor (may not help much but just follow the good practice :D):

update `balance` set `balance`=300.0 WHERE user_id=1;

[Arkadiy Arkadiy]

Thank you James!!!

I installed PXC 5.6 on 2 nodes and it worked!!!

I double checked by making a clean install of MariaDB and looks like there is some kind of a bug in Maria wsrep galera connection.

So good bye Maria, hello PXC!

mysql> update balance set balance=21343 where user_id=1;

Query OK, 1 row affected (0.00 sec)

Rows matched: 1  Changed: 1  Warnings: 0

mysql> show profile for query 1;

+--------------------------------+----------+

| Status                         | Duration |

+--------------------------------+----------+

| starting                       | 0.000079 |

| checking permissions           | 0.000010 |

| Opening tables                 | 0.000026 |

| init                           | 0.000029 |

| System lock                    | 0.000087 |

| updating                       | 0.000230 |

| end                            | 0.000004 |

| Waiting for query cache lock   | 0.000002 |

| end                            | 0.000010 |

| query end                      | 0.000010 |

| wsrep in pre-commit stage      | 0.000493 |

| ha_commit_one_phase(44)        | 0.000005 |

| innobase_commit_low():trx_comm | 0.000022 |

| ha_commit_one_phase(44)        | 0.000002 |

| wsrep in pre-commit stage      | 0.000015 |

| closing tables                 | 0.000010 |

| freeing items                  | 0.000019 |

| cleaning up                    | 0.000019 |

+--------------------------------+----------+

18 rows in set, 1 warning (0.00 sec)

пятница, 12 февраля 2016 г., 16:43:16 UTC+7 пользователь James Wang написал: