InnoDB Buffer causing a lot of deadlocks and connection/client timeouts












0















I have a PXC cluster (5.7) with three nodes running on CentOS 7 VMs, each with the following system info:



mysql_db# free 
total used free shared buff/cache available
Mem: 8009248 2591576 358504 146040 5059168 4875716
Swap: 5242876 3592 5239284
mysql_db# free -g
total used free shared buff/cache available
Mem: 7 2 0 0 4 4
Swap: 4 0 4
mysql_db# nproc
8

mysql_db# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/cl-root 44G 20G 25G 46% /
devtmpfs 3.9G 0 3.9G 0% /dev
tmpfs 3.9G 0 3.9G 0% /dev/shm
tmpfs 3.9G 146M 3.7G 4% /run
tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup
/dev/sda1 1014M 272M 743M 27% /boot
tmpfs 783M 0 783M 0% /run/user/1318214225
tmpfs 783M 0 783M 0% /run/user/0

mysql_db# top
top - 07:39:38 up 50 days, 4:54, 2 users, load average: 0.46, 0.61, 0.61
Tasks: 227 total, 1 running, 226 sleeping, 0 stopped, 0 zombie
%Cpu(s): 20.3 us, 4.0 sy, 0.0 ni, 75.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 8009248 total, 357176 free, 2592348 used, 5059724 buff/cache
KiB Swap: 5242876 total, 5239284 free, 3592 used. 4874700 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1574 mysql 20 0 9241472 2.3g 238932 S 104.8 30.1 6343:02 mysqld
3988 root 20 0 172268 2348 1580 R 19.0 0.0 0:00.12 top
13164 root 20 0 177264 94680 4676 S 19.0 1.2 2693:42 mysqld_exporter
1 root 20 0 191404 4420 2612 S 0.0 0.1 187:50.00 systemd

mysql_db# iostat
Linux 3.10.0-862.14.4.el7.x86_64 (dev_mysql_02.pd.local) 11/20/2018 _x86_64_ (8 CPU)

avg-cpu: %user %nice %system %iowait %steal %idle
2.35 0.00 0.36 0.05 0.00 97.24

Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn
sda 3.83 153.19 153.17 664744979 664666279
dm-0 3.74 139.26 153.17 604320443 664647691
dm-1 0.00 0.00 0.00 2236 2460

mysql_db#lscpu
Architecture: x86_64
CPU op-mode(s): 32-bit, 64-bit
Byte Order: Little Endian
CPU(s): 8
On-line CPU(s) list: 0-7
Thread(s) per core: 1
Core(s) per socket: 1
Socket(s): 8
NUMA node(s): 1
Vendor ID: AuthenticAMD
CPU family: 21
Model: 1
Model name: AMD Opteron(TM) Processor 6276
Stepping: 2
CPU MHz: 2300.028
BogoMIPS: 4600.05
Hypervisor vendor: VMware
Virtualization type: full
L1d cache: 16K
L1i cache: 64K
L2 cache: 2048K
L3 cache: 12288K
NUMA node0 CPU(s): 0-7


Below is some important InnoDB variables in the my.cnf config file:



...
back_log = 65535
binlog_format = ROW
character_set_server = utf8
collation_server = utf8_general_ci
default_storage_engine = InnoDB
enforce-gtid-consistency = 1
expand_fast_index_creation = 1
gtid_mode = ON
innodb_autoinc_lock_mode = 2
innodb_buffer_pool_instances = 3
innodb_buffer_pool_size = 3G
innodb_data_file_path = ibdata1:64M;ibdata2:64M:autoextend
innodb_file_format = Barracuda
innodb_file_per_table
innodb_flush_log_at_trx_commit = 2
innodb_flush_method = O_DIRECT
innodb_io_capacity = 1600
innodb_large_prefix
innodb_log_file_size = 256M
innodb_print_all_deadlocks = 1
innodb_read_io_threads = 64
innodb_stats_on_metadata = FALSE
innodb_write_io_threads = 64
long_query_time = 1
log_bin_trust_function_creators = 1
master_info_repository = TABLE
max_allowed_packet = 64M
max_connect_errors = 4294967295
max_connections = 2600
max_user_connections = 2500
min_examined_row_limit = 1000
relay_log_info_repository = TABLE
relay-log-recovery = TRUE
skip-name-resolve
slave_parallel_workers = 8
slow_query_log = 1
#slow_query_log_timestamp_always = 1
#thread_cache = 1024
tmpdir = /srv/tmp
transaction_isolation = READ-COMMITTED
updatable_views_with_limit = 0
user = mysql
wait_timeout = 60
userstat
table_open_cache = 4096
innodb_open_files = 10240
open_files_limit = 10240
connect_timeout=60
thread_cache_size = 4096
sql_mode = NO_ENGINE_SUBSTITUTION
query_cache_size = 0
slave_pending_jobs_size_max=32M
range_optimizer_max_mem_size=8M
log_timestamps=SYSTEM
server-id= 172162 #use IP
userstat=1
...


As seen above, i have set innodb_buffer_pool_size to 3GB, but not sure if this is a good value given the system info provided above, especially that Total RAM is 7.6GB, with about 5GB allocated to SWAP. We have noticed in the mysql error logs a lot of timeouts and deadlocks frequently happening, and running SHOW ENGINE INNODB STATUS shows this:



    Status: 
=====================================
2018-11-20 07:46:14 0x7f6acc0f9700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 8 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 201141 srv_active, 0 srv_shutdown, 2836117 srv_idle
srv_master_thread log flush and writes: 3037214
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 32658
OS WAIT ARRAY INFO: signal count 33393
RW-shared spins 0, rounds 156414, OS waits 27395
RW-excl spins 0, rounds 222081, OS waits 1171
RW-sx spins 11313, rounds 167795, OS waits 1583
Spin rounds per wait: 156414.00 RW-shared, 222081.00 RW-excl, 14.83 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2018-11-20 07:06:51 0x7f6aad2eb700 Transaction:
TRANSACTION 25842563, ACTIVE 1 sec updating or deleting
mysql tables in use 1, locked 1
12 lock struct(s), heap size 1136, 6 row lock(s), undo log entries 3
MySQL thread id 577793, OS thread handle 140096148780800, query id 3550710 10.168.103.11 slashire_dev update
INSERT INTO member_bank_acct (`ba_member_id`,`ba_create_user`,`ba_update_user`,`ba_country`,`ba_name`,`ba_currency`,`ba_bank_name`,`ba_bank_acct_num`,`ba_swift_code`,`ba_city`,`ba_branch`,`ba_iban`,`ba_beneficiary_bank`) VALUES ('00000000000000000252','SYSTEM','SYSTEM','','','','','','','','','','') ON DUPLICATE KEY UPDATE `ba_country` = '',`ba_name` = '',`ba_currency` = '',`ba_bank_name` = '',`ba_bank_acct_num` = '',`ba_swift_code` = '',`ba_city` = '',`ba_branch` = '',`ba_iban` = '',`ba_beneficiary_bank` = ''
Foreign key constraint fails for table `slashire_dev`.`member_bank_acct`:
,
CONSTRAINT `member_bank_acct_fk02` FOREIGN KEY (`ba_country`) REFERENCES `country` (`c_code`)
Trying to add in child table, in index member_bank_acct_fk02 tuple:
DATA TUPLE: 2 fields;
0: len 0; hex ; asc ;;
1: len 20; hex 3030303030303030303030303030303030323532; asc 00000000000000000252;;

But in parent table `slashire_dev`.`country`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 2; hex 3030; asc 00;;
1: len 6; hex 00000000566c; asc Vl;;
2: len 7; hex b0000001eb0110; asc ;;
3: len 3; hex 416c6c; asc All;;
4: len 2; hex 8000; asc ;;
5: len 5; hex 999f0c0000; asc ;;
6: len 6; hex 53595354454d; asc SYSTEM;;
7: len 5; hex 999f0c0000; asc ;;
8: len 6; hex 53595354454d; asc SYSTEM;;

------------
TRANSACTIONS
------------
Trx id counter 25989367
Purge done for trx's n:o < 25989079 undo n:o < 0 state: running but idle
History list length 27
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421576625901616, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625897008, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625900464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625899312, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625895856, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625898160, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625890096, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625893552, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625888944, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625867056, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625894704, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625892400, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625891248, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625886640, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625887792, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625885488, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625884336, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625883184, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625882032, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625880880, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625879728, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625878576, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625877424, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625876272, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625875120, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625873968, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625872816, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625871664, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625870512, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625869360, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625868208, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (read thread)
I/O thread 7 state: waiting for completed aio requests (read thread)
I/O thread 8 state: waiting for completed aio requests (read thread)
I/O thread 9 state: waiting for completed aio requests (read thread)
I/O thread 10 state: waiting for completed aio requests (read thread)
I/O thread 11 state: waiting for completed aio requests (read thread)
I/O thread 12 state: waiting for completed aio requests (read thread)
I/O thread 13 state: waiting for completed aio requests (read thread)
I/O thread 14 state: waiting for completed aio requests (read thread)
I/O thread 15 state: waiting for completed aio requests (read thread)
I/O thread 16 state: waiting for completed aio requests (read thread)
I/O thread 17 state: waiting for completed aio requests (read thread)
I/O thread 18 state: waiting for completed aio requests (read thread)
I/O thread 19 state: waiting for completed aio requests (read thread)
I/O thread 20 state: waiting for completed aio requests (read thread)
I/O thread 21 state: waiting for completed aio requests (read thread)
I/O thread 22 state: waiting for completed aio requests (read thread)
I/O thread 23 state: waiting for completed aio requests (read thread)
I/O thread 24 state: waiting for completed aio requests (read thread)
I/O thread 25 state: waiting for completed aio requests (read thread)
I/O thread 26 state: waiting for completed aio requests (read thread)
I/O thread 27 state: waiting for completed aio requests (read thread)
I/O thread 28 state: waiting for completed aio requests (read thread)
I/O thread 29 state: waiting for completed aio requests (read thread)
I/O thread 30 state: waiting for completed aio requests (read thread)
I/O thread 31 state: waiting for completed aio requests (read thread)
I/O thread 32 state: waiting for completed aio requests (read thread)
I/O thread 33 state: waiting for completed aio requests (read thread)
I/O thread 34 state: waiting for completed aio requests (read thread)
I/O thread 35 state: waiting for completed aio requests (read thread)
I/O thread 36 state: waiting for completed aio requests (read thread)
I/O thread 37 state: waiting for completed aio requests (read thread)
I/O thread 38 state: waiting for completed aio requests (read thread)
I/O thread 39 state: waiting for completed aio requests (read thread)
I/O thread 40 state: waiting for completed aio requests (read thread)
I/O thread 41 state: waiting for completed aio requests (read thread)
I/O thread 42 state: waiting for completed aio requests (read thread)
I/O thread 43 state: waiting for completed aio requests (read thread)
I/O thread 44 state: waiting for completed aio requests (read thread)
I/O thread 45 state: waiting for completed aio requests (read thread)
I/O thread 46 state: waiting for completed aio requests (read thread)
I/O thread 47 state: waiting for completed aio requests (read thread)
I/O thread 48 state: waiting for completed aio requests (read thread)
I/O thread 49 state: waiting for completed aio requests (read thread)
I/O thread 50 state: waiting for completed aio requests (read thread)
I/O thread 51 state: waiting for completed aio requests (read thread)
I/O thread 52 state: waiting for completed aio requests (read thread)
I/O thread 53 state: waiting for completed aio requests (read thread)
I/O thread 54 state: waiting for completed aio requests (read thread)
I/O thread 55 state: waiting for completed aio requests (read thread)
I/O thread 56 state: waiting for completed aio requests (read thread)
I/O thread 57 state: waiting for completed aio requests (read thread)
I/O thread 58 state: waiting for completed aio requests (read thread)
I/O thread 59 state: waiting for completed aio requests (read thread)
I/O thread 60 state: waiting for completed aio requests (read thread)
I/O thread 61 state: waiting for completed aio requests (read thread)
I/O thread 62 state: waiting for completed aio requests (read thread)
I/O thread 63 state: waiting for completed aio requests (read thread)
I/O thread 64 state: waiting for completed aio requests (read thread)
I/O thread 65 state: waiting for completed aio requests (read thread)
I/O thread 66 state: waiting for completed aio requests (write thread)
I/O thread 67 state: waiting for completed aio requests (write thread)
I/O thread 68 state: waiting for completed aio requests (write thread)
I/O thread 69 state: waiting for completed aio requests (write thread)
I/O thread 70 state: waiting for completed aio requests (write thread)
I/O thread 71 state: waiting for completed aio requests (write thread)
I/O thread 72 state: waiting for completed aio requests (write thread)
I/O thread 73 state: waiting for completed aio requests (write thread)
I/O thread 74 state: waiting for completed aio requests (write thread)
I/O thread 75 state: waiting for completed aio requests (write thread)
I/O thread 76 state: waiting for completed aio requests (write thread)
I/O thread 77 state: waiting for completed aio requests (write thread)
I/O thread 78 state: waiting for completed aio requests (write thread)
I/O thread 79 state: waiting for completed aio requests (write thread)
I/O thread 80 state: waiting for completed aio requests (write thread)
I/O thread 81 state: waiting for completed aio requests (write thread)
I/O thread 82 state: waiting for completed aio requests (write thread)
I/O thread 83 state: waiting for completed aio requests (write thread)
I/O thread 84 state: waiting for completed aio requests (write thread)
I/O thread 85 state: waiting for completed aio requests (write thread)
I/O thread 86 state: waiting for completed aio requests (write thread)
I/O thread 87 state: waiting for completed aio requests (write thread)
I/O thread 88 state: waiting for completed aio requests (write thread)
I/O thread 89 state: waiting for completed aio requests (write thread)
I/O thread 90 state: waiting for completed aio requests (write thread)
I/O thread 91 state: waiting for completed aio requests (write thread)
I/O thread 92 state: waiting for completed aio requests (write thread)
I/O thread 93 state: waiting for completed aio requests (write thread)
I/O thread 94 state: waiting for completed aio requests (write thread)
I/O thread 95 state: waiting for completed aio requests (write thread)
I/O thread 96 state: waiting for completed aio requests (write thread)
I/O thread 97 state: waiting for completed aio requests (write thread)
I/O thread 98 state: waiting for completed aio requests (write thread)
I/O thread 99 state: waiting for completed aio requests (write thread)
I/O thread 100 state: waiting for completed aio requests (write thread)
I/O thread 101 state: waiting for completed aio requests (write thread)
I/O thread 102 state: waiting for completed aio requests (write thread)
I/O thread 103 state: waiting for completed aio requests (write thread)
I/O thread 104 state: waiting for completed aio requests (write thread)
I/O thread 105 state: waiting for completed aio requests (write thread)
I/O thread 106 state: waiting for completed aio requests (write thread)
I/O thread 107 state: waiting for completed aio requests (write thread)
I/O thread 108 state: waiting for completed aio requests (write thread)
I/O thread 109 state: waiting for completed aio requests (write thread)
I/O thread 110 state: waiting for completed aio requests (write thread)
I/O thread 111 state: waiting for completed aio requests (write thread)
I/O thread 112 state: waiting for completed aio requests (write thread)
I/O thread 113 state: waiting for completed aio requests (write thread)
I/O thread 114 state: waiting for completed aio requests (write thread)
I/O thread 115 state: waiting for completed aio requests (write thread)
I/O thread 116 state: waiting for completed aio requests (write thread)
I/O thread 117 state: waiting for completed aio requests (write thread)
I/O thread 118 state: waiting for completed aio requests (write thread)
I/O thread 119 state: waiting for completed aio requests (write thread)
I/O thread 120 state: waiting for completed aio requests (write thread)
I/O thread 121 state: waiting for completed aio requests (write thread)
I/O thread 122 state: waiting for completed aio requests (write thread)
I/O thread 123 state: waiting for completed aio requests (write thread)
I/O thread 124 state: waiting for completed aio requests (write thread)
I/O thread 125 state: waiting for completed aio requests (write thread)
I/O thread 126 state: waiting for completed aio requests (write thread)
I/O thread 127 state: waiting for completed aio requests (write thread)
I/O thread 128 state: waiting for completed aio requests (write thread)
I/O thread 129 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
8353 OS file reads, 2256885 OS file writes, 649203 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 6.37 writes/s, 1.75 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 108 merges
merged operations:
insert 1, delete mark 1, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 796871, node heap has 46 buffer(s)
Hash table size 796871, node heap has 8 buffer(s)
Hash table size 796871, node heap has 7 buffer(s)
Hash table size 796871, node heap has 14 buffer(s)
Hash table size 796871, node heap has 23 buffer(s)
Hash table size 796871, node heap has 16 buffer(s)
Hash table size 796871, node heap has 15 buffer(s)
Hash table size 796871, node heap has 94 buffer(s)
234.22 hash searches/s, 8.87 non-hash searches/s
---
LOG
---
Log sequence number 1427669147
Log flushed up to 1427669147
Pages flushed up to 1427669147
Last checkpoint at 1427669138
Max checkpoint age 434154333
Checkpoint age target 420587011
Modified age 0
Checkpoint age 9
0 pending log flushes, 0 pending chkp writes
452361 log i/o's done, 1.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 3353346048
Dictionary memory allocated 11634313
Internal hash tables (constant factor + variable factor)
Adaptive hash index 54687040 (50999744 + 3687296)
Page hash 1107112 (buffer pool 0 only)
Dictionary cache 24384249 (12749936 + 11634313)
File system 1676640 (812272 + 864368)
Lock system 8004712 (7969496 + 35216)
Recovery system 0 (0 + 0)
Buffer pool size 196584
Buffer pool size, bytes 3220832256
Free buffers 146566
Database pages 49795
Old database pages 18321
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 10000, not young 35358
0.00 youngs/s, 0.00 non-youngs/s
Pages read 7697, created 42280, written 1645380
0.00 reads/s, 0.00 creates/s, 5.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 49795, unzip_LRU len: 0
I/O sum[807]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48863
Database pages 16588
Old database pages 6103
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3655, not young 13239
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2611, created 14049, written 334207
0.00 reads/s, 0.00 creates/s, 0.50 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16588, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48627
Database pages 16823
Old database pages 6190
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3253, not young 12647
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2476, created 14408, written 1147163
0.00 reads/s, 0.00 creates/s, 3.87 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16823, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 49076
Database pages 16384
Old database pages 6028
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3092, not young 9472
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2610, created 13823, written 164010
0.00 reads/s, 0.00 creates/s, 0.62 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16384, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
0 RW transactions active inside InnoDB
Process ID=1574, Main thread ID=140097892615936, state: sleeping
Number of rows inserted 25413524, updated 63914, deleted 6172, read 1035018804
65.87 inserts/s, 0.12 updates/s, 0.00 deletes/s, 97.36 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT


Are there any tell tell signs from the above info causing these timeouts and deadlocks? How can i find out the percentage of utilized InnoDB buffer pool against total RAM?



Ping Results



64 bytes from 10.1.5.100: icmp_seq=1 ttl=64 time=0.958 ms
64 bytes from 10.1.5.100: icmp_seq=2 ttl=64 time=1.09 ms
64 bytes from 10.1.5.100: icmp_seq=4 ttl=64 time=1.22 ms
64 bytes from 10.1.5.100: icmp_seq=5 ttl=64 time=2.24 ms


DEADLOCK INFO



*** Priority TRANSACTION:
TRANSACTION 165015546, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
MySQL thread id 14, OS thread handle 140101363758848, query id 11358891 System lock

*** Victim TRANSACTION:
TRANSACTION 165015100, ACTIVE 1 sec
, undo log entries 1
MySQL thread id 1027074, OS thread handle 140096133596928, query id 11358888 10.168.103.11 membership wsrep: initiating replication for write set (-1)
COMMIT
*** WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2481 page no 17 n bits 80 index PRIMARY of table `membership`.`member_token` trx id 165015100 lock_mode X locks rec but not gap
2018-12-06T03:12:23.732058-00:00 14 [Note] WSREP: --------- CONFLICT DETECTED --------
2018-12-06T03:12:23.732119-00:00 14 [Note] WSREP: cluster conflict due to high priority abort for threads:

2018-12-06T03:12:23.732331-00:00 14 [Note] WSREP: Winning thread:
THD: 14, mode: applier, state: executing, conflict: no conflict, seqno: 152121
SQL: (null)

2018-12-06T03:12:23.732392-00:00 14 [Note] WSREP: Victim thread:
THD: 1027074, mode: local, state: committing, conflict: no conflict, seqno: -1
SQL: COMMIT









share|improve this question
















bumped to the homepage by Community 34 mins ago


This question has answers that may be good or bad; the system has marked it active so that they can be reviewed.
















  • These values indicate usage : Buffer pool size 196584 -- total number of pages Free buffers 146566 -- number of free pages Repeated in individual buffer pool info.

    – percona-lorraine
    Nov 20 '18 at 14:00













  • So it means only a small percentage of allocated innodb buffer pool is being used, and hence the timeout and deadlock issues we are experiencing as not caused by memory issues? From the log files, we are pretty much getting 90% of these kind of mesages 2018-11-21T01:54:14.034573-00:00 190701 [Note] Aborted connection 190701 to db: 'event' user: 'eventdb' host: '10.1.0.100' (Got timeout reading communication packets)

    – The Georgia
    Nov 21 '18 at 2:07











  • I have also added CPU info for more info.

    – The Georgia
    Nov 21 '18 at 2:38
















0















I have a PXC cluster (5.7) with three nodes running on CentOS 7 VMs, each with the following system info:



mysql_db# free 
total used free shared buff/cache available
Mem: 8009248 2591576 358504 146040 5059168 4875716
Swap: 5242876 3592 5239284
mysql_db# free -g
total used free shared buff/cache available
Mem: 7 2 0 0 4 4
Swap: 4 0 4
mysql_db# nproc
8

mysql_db# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/cl-root 44G 20G 25G 46% /
devtmpfs 3.9G 0 3.9G 0% /dev
tmpfs 3.9G 0 3.9G 0% /dev/shm
tmpfs 3.9G 146M 3.7G 4% /run
tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup
/dev/sda1 1014M 272M 743M 27% /boot
tmpfs 783M 0 783M 0% /run/user/1318214225
tmpfs 783M 0 783M 0% /run/user/0

mysql_db# top
top - 07:39:38 up 50 days, 4:54, 2 users, load average: 0.46, 0.61, 0.61
Tasks: 227 total, 1 running, 226 sleeping, 0 stopped, 0 zombie
%Cpu(s): 20.3 us, 4.0 sy, 0.0 ni, 75.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 8009248 total, 357176 free, 2592348 used, 5059724 buff/cache
KiB Swap: 5242876 total, 5239284 free, 3592 used. 4874700 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1574 mysql 20 0 9241472 2.3g 238932 S 104.8 30.1 6343:02 mysqld
3988 root 20 0 172268 2348 1580 R 19.0 0.0 0:00.12 top
13164 root 20 0 177264 94680 4676 S 19.0 1.2 2693:42 mysqld_exporter
1 root 20 0 191404 4420 2612 S 0.0 0.1 187:50.00 systemd

mysql_db# iostat
Linux 3.10.0-862.14.4.el7.x86_64 (dev_mysql_02.pd.local) 11/20/2018 _x86_64_ (8 CPU)

avg-cpu: %user %nice %system %iowait %steal %idle
2.35 0.00 0.36 0.05 0.00 97.24

Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn
sda 3.83 153.19 153.17 664744979 664666279
dm-0 3.74 139.26 153.17 604320443 664647691
dm-1 0.00 0.00 0.00 2236 2460

mysql_db#lscpu
Architecture: x86_64
CPU op-mode(s): 32-bit, 64-bit
Byte Order: Little Endian
CPU(s): 8
On-line CPU(s) list: 0-7
Thread(s) per core: 1
Core(s) per socket: 1
Socket(s): 8
NUMA node(s): 1
Vendor ID: AuthenticAMD
CPU family: 21
Model: 1
Model name: AMD Opteron(TM) Processor 6276
Stepping: 2
CPU MHz: 2300.028
BogoMIPS: 4600.05
Hypervisor vendor: VMware
Virtualization type: full
L1d cache: 16K
L1i cache: 64K
L2 cache: 2048K
L3 cache: 12288K
NUMA node0 CPU(s): 0-7


Below is some important InnoDB variables in the my.cnf config file:



...
back_log = 65535
binlog_format = ROW
character_set_server = utf8
collation_server = utf8_general_ci
default_storage_engine = InnoDB
enforce-gtid-consistency = 1
expand_fast_index_creation = 1
gtid_mode = ON
innodb_autoinc_lock_mode = 2
innodb_buffer_pool_instances = 3
innodb_buffer_pool_size = 3G
innodb_data_file_path = ibdata1:64M;ibdata2:64M:autoextend
innodb_file_format = Barracuda
innodb_file_per_table
innodb_flush_log_at_trx_commit = 2
innodb_flush_method = O_DIRECT
innodb_io_capacity = 1600
innodb_large_prefix
innodb_log_file_size = 256M
innodb_print_all_deadlocks = 1
innodb_read_io_threads = 64
innodb_stats_on_metadata = FALSE
innodb_write_io_threads = 64
long_query_time = 1
log_bin_trust_function_creators = 1
master_info_repository = TABLE
max_allowed_packet = 64M
max_connect_errors = 4294967295
max_connections = 2600
max_user_connections = 2500
min_examined_row_limit = 1000
relay_log_info_repository = TABLE
relay-log-recovery = TRUE
skip-name-resolve
slave_parallel_workers = 8
slow_query_log = 1
#slow_query_log_timestamp_always = 1
#thread_cache = 1024
tmpdir = /srv/tmp
transaction_isolation = READ-COMMITTED
updatable_views_with_limit = 0
user = mysql
wait_timeout = 60
userstat
table_open_cache = 4096
innodb_open_files = 10240
open_files_limit = 10240
connect_timeout=60
thread_cache_size = 4096
sql_mode = NO_ENGINE_SUBSTITUTION
query_cache_size = 0
slave_pending_jobs_size_max=32M
range_optimizer_max_mem_size=8M
log_timestamps=SYSTEM
server-id= 172162 #use IP
userstat=1
...


As seen above, i have set innodb_buffer_pool_size to 3GB, but not sure if this is a good value given the system info provided above, especially that Total RAM is 7.6GB, with about 5GB allocated to SWAP. We have noticed in the mysql error logs a lot of timeouts and deadlocks frequently happening, and running SHOW ENGINE INNODB STATUS shows this:



    Status: 
=====================================
2018-11-20 07:46:14 0x7f6acc0f9700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 8 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 201141 srv_active, 0 srv_shutdown, 2836117 srv_idle
srv_master_thread log flush and writes: 3037214
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 32658
OS WAIT ARRAY INFO: signal count 33393
RW-shared spins 0, rounds 156414, OS waits 27395
RW-excl spins 0, rounds 222081, OS waits 1171
RW-sx spins 11313, rounds 167795, OS waits 1583
Spin rounds per wait: 156414.00 RW-shared, 222081.00 RW-excl, 14.83 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2018-11-20 07:06:51 0x7f6aad2eb700 Transaction:
TRANSACTION 25842563, ACTIVE 1 sec updating or deleting
mysql tables in use 1, locked 1
12 lock struct(s), heap size 1136, 6 row lock(s), undo log entries 3
MySQL thread id 577793, OS thread handle 140096148780800, query id 3550710 10.168.103.11 slashire_dev update
INSERT INTO member_bank_acct (`ba_member_id`,`ba_create_user`,`ba_update_user`,`ba_country`,`ba_name`,`ba_currency`,`ba_bank_name`,`ba_bank_acct_num`,`ba_swift_code`,`ba_city`,`ba_branch`,`ba_iban`,`ba_beneficiary_bank`) VALUES ('00000000000000000252','SYSTEM','SYSTEM','','','','','','','','','','') ON DUPLICATE KEY UPDATE `ba_country` = '',`ba_name` = '',`ba_currency` = '',`ba_bank_name` = '',`ba_bank_acct_num` = '',`ba_swift_code` = '',`ba_city` = '',`ba_branch` = '',`ba_iban` = '',`ba_beneficiary_bank` = ''
Foreign key constraint fails for table `slashire_dev`.`member_bank_acct`:
,
CONSTRAINT `member_bank_acct_fk02` FOREIGN KEY (`ba_country`) REFERENCES `country` (`c_code`)
Trying to add in child table, in index member_bank_acct_fk02 tuple:
DATA TUPLE: 2 fields;
0: len 0; hex ; asc ;;
1: len 20; hex 3030303030303030303030303030303030323532; asc 00000000000000000252;;

But in parent table `slashire_dev`.`country`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 2; hex 3030; asc 00;;
1: len 6; hex 00000000566c; asc Vl;;
2: len 7; hex b0000001eb0110; asc ;;
3: len 3; hex 416c6c; asc All;;
4: len 2; hex 8000; asc ;;
5: len 5; hex 999f0c0000; asc ;;
6: len 6; hex 53595354454d; asc SYSTEM;;
7: len 5; hex 999f0c0000; asc ;;
8: len 6; hex 53595354454d; asc SYSTEM;;

------------
TRANSACTIONS
------------
Trx id counter 25989367
Purge done for trx's n:o < 25989079 undo n:o < 0 state: running but idle
History list length 27
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421576625901616, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625897008, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625900464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625899312, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625895856, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625898160, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625890096, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625893552, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625888944, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625867056, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625894704, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625892400, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625891248, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625886640, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625887792, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625885488, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625884336, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625883184, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625882032, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625880880, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625879728, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625878576, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625877424, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625876272, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625875120, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625873968, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625872816, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625871664, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625870512, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625869360, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625868208, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (read thread)
I/O thread 7 state: waiting for completed aio requests (read thread)
I/O thread 8 state: waiting for completed aio requests (read thread)
I/O thread 9 state: waiting for completed aio requests (read thread)
I/O thread 10 state: waiting for completed aio requests (read thread)
I/O thread 11 state: waiting for completed aio requests (read thread)
I/O thread 12 state: waiting for completed aio requests (read thread)
I/O thread 13 state: waiting for completed aio requests (read thread)
I/O thread 14 state: waiting for completed aio requests (read thread)
I/O thread 15 state: waiting for completed aio requests (read thread)
I/O thread 16 state: waiting for completed aio requests (read thread)
I/O thread 17 state: waiting for completed aio requests (read thread)
I/O thread 18 state: waiting for completed aio requests (read thread)
I/O thread 19 state: waiting for completed aio requests (read thread)
I/O thread 20 state: waiting for completed aio requests (read thread)
I/O thread 21 state: waiting for completed aio requests (read thread)
I/O thread 22 state: waiting for completed aio requests (read thread)
I/O thread 23 state: waiting for completed aio requests (read thread)
I/O thread 24 state: waiting for completed aio requests (read thread)
I/O thread 25 state: waiting for completed aio requests (read thread)
I/O thread 26 state: waiting for completed aio requests (read thread)
I/O thread 27 state: waiting for completed aio requests (read thread)
I/O thread 28 state: waiting for completed aio requests (read thread)
I/O thread 29 state: waiting for completed aio requests (read thread)
I/O thread 30 state: waiting for completed aio requests (read thread)
I/O thread 31 state: waiting for completed aio requests (read thread)
I/O thread 32 state: waiting for completed aio requests (read thread)
I/O thread 33 state: waiting for completed aio requests (read thread)
I/O thread 34 state: waiting for completed aio requests (read thread)
I/O thread 35 state: waiting for completed aio requests (read thread)
I/O thread 36 state: waiting for completed aio requests (read thread)
I/O thread 37 state: waiting for completed aio requests (read thread)
I/O thread 38 state: waiting for completed aio requests (read thread)
I/O thread 39 state: waiting for completed aio requests (read thread)
I/O thread 40 state: waiting for completed aio requests (read thread)
I/O thread 41 state: waiting for completed aio requests (read thread)
I/O thread 42 state: waiting for completed aio requests (read thread)
I/O thread 43 state: waiting for completed aio requests (read thread)
I/O thread 44 state: waiting for completed aio requests (read thread)
I/O thread 45 state: waiting for completed aio requests (read thread)
I/O thread 46 state: waiting for completed aio requests (read thread)
I/O thread 47 state: waiting for completed aio requests (read thread)
I/O thread 48 state: waiting for completed aio requests (read thread)
I/O thread 49 state: waiting for completed aio requests (read thread)
I/O thread 50 state: waiting for completed aio requests (read thread)
I/O thread 51 state: waiting for completed aio requests (read thread)
I/O thread 52 state: waiting for completed aio requests (read thread)
I/O thread 53 state: waiting for completed aio requests (read thread)
I/O thread 54 state: waiting for completed aio requests (read thread)
I/O thread 55 state: waiting for completed aio requests (read thread)
I/O thread 56 state: waiting for completed aio requests (read thread)
I/O thread 57 state: waiting for completed aio requests (read thread)
I/O thread 58 state: waiting for completed aio requests (read thread)
I/O thread 59 state: waiting for completed aio requests (read thread)
I/O thread 60 state: waiting for completed aio requests (read thread)
I/O thread 61 state: waiting for completed aio requests (read thread)
I/O thread 62 state: waiting for completed aio requests (read thread)
I/O thread 63 state: waiting for completed aio requests (read thread)
I/O thread 64 state: waiting for completed aio requests (read thread)
I/O thread 65 state: waiting for completed aio requests (read thread)
I/O thread 66 state: waiting for completed aio requests (write thread)
I/O thread 67 state: waiting for completed aio requests (write thread)
I/O thread 68 state: waiting for completed aio requests (write thread)
I/O thread 69 state: waiting for completed aio requests (write thread)
I/O thread 70 state: waiting for completed aio requests (write thread)
I/O thread 71 state: waiting for completed aio requests (write thread)
I/O thread 72 state: waiting for completed aio requests (write thread)
I/O thread 73 state: waiting for completed aio requests (write thread)
I/O thread 74 state: waiting for completed aio requests (write thread)
I/O thread 75 state: waiting for completed aio requests (write thread)
I/O thread 76 state: waiting for completed aio requests (write thread)
I/O thread 77 state: waiting for completed aio requests (write thread)
I/O thread 78 state: waiting for completed aio requests (write thread)
I/O thread 79 state: waiting for completed aio requests (write thread)
I/O thread 80 state: waiting for completed aio requests (write thread)
I/O thread 81 state: waiting for completed aio requests (write thread)
I/O thread 82 state: waiting for completed aio requests (write thread)
I/O thread 83 state: waiting for completed aio requests (write thread)
I/O thread 84 state: waiting for completed aio requests (write thread)
I/O thread 85 state: waiting for completed aio requests (write thread)
I/O thread 86 state: waiting for completed aio requests (write thread)
I/O thread 87 state: waiting for completed aio requests (write thread)
I/O thread 88 state: waiting for completed aio requests (write thread)
I/O thread 89 state: waiting for completed aio requests (write thread)
I/O thread 90 state: waiting for completed aio requests (write thread)
I/O thread 91 state: waiting for completed aio requests (write thread)
I/O thread 92 state: waiting for completed aio requests (write thread)
I/O thread 93 state: waiting for completed aio requests (write thread)
I/O thread 94 state: waiting for completed aio requests (write thread)
I/O thread 95 state: waiting for completed aio requests (write thread)
I/O thread 96 state: waiting for completed aio requests (write thread)
I/O thread 97 state: waiting for completed aio requests (write thread)
I/O thread 98 state: waiting for completed aio requests (write thread)
I/O thread 99 state: waiting for completed aio requests (write thread)
I/O thread 100 state: waiting for completed aio requests (write thread)
I/O thread 101 state: waiting for completed aio requests (write thread)
I/O thread 102 state: waiting for completed aio requests (write thread)
I/O thread 103 state: waiting for completed aio requests (write thread)
I/O thread 104 state: waiting for completed aio requests (write thread)
I/O thread 105 state: waiting for completed aio requests (write thread)
I/O thread 106 state: waiting for completed aio requests (write thread)
I/O thread 107 state: waiting for completed aio requests (write thread)
I/O thread 108 state: waiting for completed aio requests (write thread)
I/O thread 109 state: waiting for completed aio requests (write thread)
I/O thread 110 state: waiting for completed aio requests (write thread)
I/O thread 111 state: waiting for completed aio requests (write thread)
I/O thread 112 state: waiting for completed aio requests (write thread)
I/O thread 113 state: waiting for completed aio requests (write thread)
I/O thread 114 state: waiting for completed aio requests (write thread)
I/O thread 115 state: waiting for completed aio requests (write thread)
I/O thread 116 state: waiting for completed aio requests (write thread)
I/O thread 117 state: waiting for completed aio requests (write thread)
I/O thread 118 state: waiting for completed aio requests (write thread)
I/O thread 119 state: waiting for completed aio requests (write thread)
I/O thread 120 state: waiting for completed aio requests (write thread)
I/O thread 121 state: waiting for completed aio requests (write thread)
I/O thread 122 state: waiting for completed aio requests (write thread)
I/O thread 123 state: waiting for completed aio requests (write thread)
I/O thread 124 state: waiting for completed aio requests (write thread)
I/O thread 125 state: waiting for completed aio requests (write thread)
I/O thread 126 state: waiting for completed aio requests (write thread)
I/O thread 127 state: waiting for completed aio requests (write thread)
I/O thread 128 state: waiting for completed aio requests (write thread)
I/O thread 129 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
8353 OS file reads, 2256885 OS file writes, 649203 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 6.37 writes/s, 1.75 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 108 merges
merged operations:
insert 1, delete mark 1, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 796871, node heap has 46 buffer(s)
Hash table size 796871, node heap has 8 buffer(s)
Hash table size 796871, node heap has 7 buffer(s)
Hash table size 796871, node heap has 14 buffer(s)
Hash table size 796871, node heap has 23 buffer(s)
Hash table size 796871, node heap has 16 buffer(s)
Hash table size 796871, node heap has 15 buffer(s)
Hash table size 796871, node heap has 94 buffer(s)
234.22 hash searches/s, 8.87 non-hash searches/s
---
LOG
---
Log sequence number 1427669147
Log flushed up to 1427669147
Pages flushed up to 1427669147
Last checkpoint at 1427669138
Max checkpoint age 434154333
Checkpoint age target 420587011
Modified age 0
Checkpoint age 9
0 pending log flushes, 0 pending chkp writes
452361 log i/o's done, 1.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 3353346048
Dictionary memory allocated 11634313
Internal hash tables (constant factor + variable factor)
Adaptive hash index 54687040 (50999744 + 3687296)
Page hash 1107112 (buffer pool 0 only)
Dictionary cache 24384249 (12749936 + 11634313)
File system 1676640 (812272 + 864368)
Lock system 8004712 (7969496 + 35216)
Recovery system 0 (0 + 0)
Buffer pool size 196584
Buffer pool size, bytes 3220832256
Free buffers 146566
Database pages 49795
Old database pages 18321
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 10000, not young 35358
0.00 youngs/s, 0.00 non-youngs/s
Pages read 7697, created 42280, written 1645380
0.00 reads/s, 0.00 creates/s, 5.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 49795, unzip_LRU len: 0
I/O sum[807]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48863
Database pages 16588
Old database pages 6103
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3655, not young 13239
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2611, created 14049, written 334207
0.00 reads/s, 0.00 creates/s, 0.50 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16588, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48627
Database pages 16823
Old database pages 6190
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3253, not young 12647
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2476, created 14408, written 1147163
0.00 reads/s, 0.00 creates/s, 3.87 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16823, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 49076
Database pages 16384
Old database pages 6028
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3092, not young 9472
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2610, created 13823, written 164010
0.00 reads/s, 0.00 creates/s, 0.62 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16384, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
0 RW transactions active inside InnoDB
Process ID=1574, Main thread ID=140097892615936, state: sleeping
Number of rows inserted 25413524, updated 63914, deleted 6172, read 1035018804
65.87 inserts/s, 0.12 updates/s, 0.00 deletes/s, 97.36 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT


Are there any tell tell signs from the above info causing these timeouts and deadlocks? How can i find out the percentage of utilized InnoDB buffer pool against total RAM?



Ping Results



64 bytes from 10.1.5.100: icmp_seq=1 ttl=64 time=0.958 ms
64 bytes from 10.1.5.100: icmp_seq=2 ttl=64 time=1.09 ms
64 bytes from 10.1.5.100: icmp_seq=4 ttl=64 time=1.22 ms
64 bytes from 10.1.5.100: icmp_seq=5 ttl=64 time=2.24 ms


DEADLOCK INFO



*** Priority TRANSACTION:
TRANSACTION 165015546, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
MySQL thread id 14, OS thread handle 140101363758848, query id 11358891 System lock

*** Victim TRANSACTION:
TRANSACTION 165015100, ACTIVE 1 sec
, undo log entries 1
MySQL thread id 1027074, OS thread handle 140096133596928, query id 11358888 10.168.103.11 membership wsrep: initiating replication for write set (-1)
COMMIT
*** WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2481 page no 17 n bits 80 index PRIMARY of table `membership`.`member_token` trx id 165015100 lock_mode X locks rec but not gap
2018-12-06T03:12:23.732058-00:00 14 [Note] WSREP: --------- CONFLICT DETECTED --------
2018-12-06T03:12:23.732119-00:00 14 [Note] WSREP: cluster conflict due to high priority abort for threads:

2018-12-06T03:12:23.732331-00:00 14 [Note] WSREP: Winning thread:
THD: 14, mode: applier, state: executing, conflict: no conflict, seqno: 152121
SQL: (null)

2018-12-06T03:12:23.732392-00:00 14 [Note] WSREP: Victim thread:
THD: 1027074, mode: local, state: committing, conflict: no conflict, seqno: -1
SQL: COMMIT









share|improve this question
















bumped to the homepage by Community 34 mins ago


This question has answers that may be good or bad; the system has marked it active so that they can be reviewed.
















  • These values indicate usage : Buffer pool size 196584 -- total number of pages Free buffers 146566 -- number of free pages Repeated in individual buffer pool info.

    – percona-lorraine
    Nov 20 '18 at 14:00













  • So it means only a small percentage of allocated innodb buffer pool is being used, and hence the timeout and deadlock issues we are experiencing as not caused by memory issues? From the log files, we are pretty much getting 90% of these kind of mesages 2018-11-21T01:54:14.034573-00:00 190701 [Note] Aborted connection 190701 to db: 'event' user: 'eventdb' host: '10.1.0.100' (Got timeout reading communication packets)

    – The Georgia
    Nov 21 '18 at 2:07











  • I have also added CPU info for more info.

    – The Georgia
    Nov 21 '18 at 2:38














0












0








0








I have a PXC cluster (5.7) with three nodes running on CentOS 7 VMs, each with the following system info:



mysql_db# free 
total used free shared buff/cache available
Mem: 8009248 2591576 358504 146040 5059168 4875716
Swap: 5242876 3592 5239284
mysql_db# free -g
total used free shared buff/cache available
Mem: 7 2 0 0 4 4
Swap: 4 0 4
mysql_db# nproc
8

mysql_db# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/cl-root 44G 20G 25G 46% /
devtmpfs 3.9G 0 3.9G 0% /dev
tmpfs 3.9G 0 3.9G 0% /dev/shm
tmpfs 3.9G 146M 3.7G 4% /run
tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup
/dev/sda1 1014M 272M 743M 27% /boot
tmpfs 783M 0 783M 0% /run/user/1318214225
tmpfs 783M 0 783M 0% /run/user/0

mysql_db# top
top - 07:39:38 up 50 days, 4:54, 2 users, load average: 0.46, 0.61, 0.61
Tasks: 227 total, 1 running, 226 sleeping, 0 stopped, 0 zombie
%Cpu(s): 20.3 us, 4.0 sy, 0.0 ni, 75.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 8009248 total, 357176 free, 2592348 used, 5059724 buff/cache
KiB Swap: 5242876 total, 5239284 free, 3592 used. 4874700 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1574 mysql 20 0 9241472 2.3g 238932 S 104.8 30.1 6343:02 mysqld
3988 root 20 0 172268 2348 1580 R 19.0 0.0 0:00.12 top
13164 root 20 0 177264 94680 4676 S 19.0 1.2 2693:42 mysqld_exporter
1 root 20 0 191404 4420 2612 S 0.0 0.1 187:50.00 systemd

mysql_db# iostat
Linux 3.10.0-862.14.4.el7.x86_64 (dev_mysql_02.pd.local) 11/20/2018 _x86_64_ (8 CPU)

avg-cpu: %user %nice %system %iowait %steal %idle
2.35 0.00 0.36 0.05 0.00 97.24

Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn
sda 3.83 153.19 153.17 664744979 664666279
dm-0 3.74 139.26 153.17 604320443 664647691
dm-1 0.00 0.00 0.00 2236 2460

mysql_db#lscpu
Architecture: x86_64
CPU op-mode(s): 32-bit, 64-bit
Byte Order: Little Endian
CPU(s): 8
On-line CPU(s) list: 0-7
Thread(s) per core: 1
Core(s) per socket: 1
Socket(s): 8
NUMA node(s): 1
Vendor ID: AuthenticAMD
CPU family: 21
Model: 1
Model name: AMD Opteron(TM) Processor 6276
Stepping: 2
CPU MHz: 2300.028
BogoMIPS: 4600.05
Hypervisor vendor: VMware
Virtualization type: full
L1d cache: 16K
L1i cache: 64K
L2 cache: 2048K
L3 cache: 12288K
NUMA node0 CPU(s): 0-7


Below is some important InnoDB variables in the my.cnf config file:



...
back_log = 65535
binlog_format = ROW
character_set_server = utf8
collation_server = utf8_general_ci
default_storage_engine = InnoDB
enforce-gtid-consistency = 1
expand_fast_index_creation = 1
gtid_mode = ON
innodb_autoinc_lock_mode = 2
innodb_buffer_pool_instances = 3
innodb_buffer_pool_size = 3G
innodb_data_file_path = ibdata1:64M;ibdata2:64M:autoextend
innodb_file_format = Barracuda
innodb_file_per_table
innodb_flush_log_at_trx_commit = 2
innodb_flush_method = O_DIRECT
innodb_io_capacity = 1600
innodb_large_prefix
innodb_log_file_size = 256M
innodb_print_all_deadlocks = 1
innodb_read_io_threads = 64
innodb_stats_on_metadata = FALSE
innodb_write_io_threads = 64
long_query_time = 1
log_bin_trust_function_creators = 1
master_info_repository = TABLE
max_allowed_packet = 64M
max_connect_errors = 4294967295
max_connections = 2600
max_user_connections = 2500
min_examined_row_limit = 1000
relay_log_info_repository = TABLE
relay-log-recovery = TRUE
skip-name-resolve
slave_parallel_workers = 8
slow_query_log = 1
#slow_query_log_timestamp_always = 1
#thread_cache = 1024
tmpdir = /srv/tmp
transaction_isolation = READ-COMMITTED
updatable_views_with_limit = 0
user = mysql
wait_timeout = 60
userstat
table_open_cache = 4096
innodb_open_files = 10240
open_files_limit = 10240
connect_timeout=60
thread_cache_size = 4096
sql_mode = NO_ENGINE_SUBSTITUTION
query_cache_size = 0
slave_pending_jobs_size_max=32M
range_optimizer_max_mem_size=8M
log_timestamps=SYSTEM
server-id= 172162 #use IP
userstat=1
...


As seen above, i have set innodb_buffer_pool_size to 3GB, but not sure if this is a good value given the system info provided above, especially that Total RAM is 7.6GB, with about 5GB allocated to SWAP. We have noticed in the mysql error logs a lot of timeouts and deadlocks frequently happening, and running SHOW ENGINE INNODB STATUS shows this:



    Status: 
=====================================
2018-11-20 07:46:14 0x7f6acc0f9700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 8 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 201141 srv_active, 0 srv_shutdown, 2836117 srv_idle
srv_master_thread log flush and writes: 3037214
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 32658
OS WAIT ARRAY INFO: signal count 33393
RW-shared spins 0, rounds 156414, OS waits 27395
RW-excl spins 0, rounds 222081, OS waits 1171
RW-sx spins 11313, rounds 167795, OS waits 1583
Spin rounds per wait: 156414.00 RW-shared, 222081.00 RW-excl, 14.83 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2018-11-20 07:06:51 0x7f6aad2eb700 Transaction:
TRANSACTION 25842563, ACTIVE 1 sec updating or deleting
mysql tables in use 1, locked 1
12 lock struct(s), heap size 1136, 6 row lock(s), undo log entries 3
MySQL thread id 577793, OS thread handle 140096148780800, query id 3550710 10.168.103.11 slashire_dev update
INSERT INTO member_bank_acct (`ba_member_id`,`ba_create_user`,`ba_update_user`,`ba_country`,`ba_name`,`ba_currency`,`ba_bank_name`,`ba_bank_acct_num`,`ba_swift_code`,`ba_city`,`ba_branch`,`ba_iban`,`ba_beneficiary_bank`) VALUES ('00000000000000000252','SYSTEM','SYSTEM','','','','','','','','','','') ON DUPLICATE KEY UPDATE `ba_country` = '',`ba_name` = '',`ba_currency` = '',`ba_bank_name` = '',`ba_bank_acct_num` = '',`ba_swift_code` = '',`ba_city` = '',`ba_branch` = '',`ba_iban` = '',`ba_beneficiary_bank` = ''
Foreign key constraint fails for table `slashire_dev`.`member_bank_acct`:
,
CONSTRAINT `member_bank_acct_fk02` FOREIGN KEY (`ba_country`) REFERENCES `country` (`c_code`)
Trying to add in child table, in index member_bank_acct_fk02 tuple:
DATA TUPLE: 2 fields;
0: len 0; hex ; asc ;;
1: len 20; hex 3030303030303030303030303030303030323532; asc 00000000000000000252;;

But in parent table `slashire_dev`.`country`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 2; hex 3030; asc 00;;
1: len 6; hex 00000000566c; asc Vl;;
2: len 7; hex b0000001eb0110; asc ;;
3: len 3; hex 416c6c; asc All;;
4: len 2; hex 8000; asc ;;
5: len 5; hex 999f0c0000; asc ;;
6: len 6; hex 53595354454d; asc SYSTEM;;
7: len 5; hex 999f0c0000; asc ;;
8: len 6; hex 53595354454d; asc SYSTEM;;

------------
TRANSACTIONS
------------
Trx id counter 25989367
Purge done for trx's n:o < 25989079 undo n:o < 0 state: running but idle
History list length 27
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421576625901616, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625897008, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625900464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625899312, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625895856, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625898160, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625890096, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625893552, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625888944, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625867056, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625894704, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625892400, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625891248, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625886640, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625887792, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625885488, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625884336, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625883184, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625882032, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625880880, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625879728, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625878576, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625877424, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625876272, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625875120, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625873968, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625872816, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625871664, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625870512, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625869360, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625868208, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (read thread)
I/O thread 7 state: waiting for completed aio requests (read thread)
I/O thread 8 state: waiting for completed aio requests (read thread)
I/O thread 9 state: waiting for completed aio requests (read thread)
I/O thread 10 state: waiting for completed aio requests (read thread)
I/O thread 11 state: waiting for completed aio requests (read thread)
I/O thread 12 state: waiting for completed aio requests (read thread)
I/O thread 13 state: waiting for completed aio requests (read thread)
I/O thread 14 state: waiting for completed aio requests (read thread)
I/O thread 15 state: waiting for completed aio requests (read thread)
I/O thread 16 state: waiting for completed aio requests (read thread)
I/O thread 17 state: waiting for completed aio requests (read thread)
I/O thread 18 state: waiting for completed aio requests (read thread)
I/O thread 19 state: waiting for completed aio requests (read thread)
I/O thread 20 state: waiting for completed aio requests (read thread)
I/O thread 21 state: waiting for completed aio requests (read thread)
I/O thread 22 state: waiting for completed aio requests (read thread)
I/O thread 23 state: waiting for completed aio requests (read thread)
I/O thread 24 state: waiting for completed aio requests (read thread)
I/O thread 25 state: waiting for completed aio requests (read thread)
I/O thread 26 state: waiting for completed aio requests (read thread)
I/O thread 27 state: waiting for completed aio requests (read thread)
I/O thread 28 state: waiting for completed aio requests (read thread)
I/O thread 29 state: waiting for completed aio requests (read thread)
I/O thread 30 state: waiting for completed aio requests (read thread)
I/O thread 31 state: waiting for completed aio requests (read thread)
I/O thread 32 state: waiting for completed aio requests (read thread)
I/O thread 33 state: waiting for completed aio requests (read thread)
I/O thread 34 state: waiting for completed aio requests (read thread)
I/O thread 35 state: waiting for completed aio requests (read thread)
I/O thread 36 state: waiting for completed aio requests (read thread)
I/O thread 37 state: waiting for completed aio requests (read thread)
I/O thread 38 state: waiting for completed aio requests (read thread)
I/O thread 39 state: waiting for completed aio requests (read thread)
I/O thread 40 state: waiting for completed aio requests (read thread)
I/O thread 41 state: waiting for completed aio requests (read thread)
I/O thread 42 state: waiting for completed aio requests (read thread)
I/O thread 43 state: waiting for completed aio requests (read thread)
I/O thread 44 state: waiting for completed aio requests (read thread)
I/O thread 45 state: waiting for completed aio requests (read thread)
I/O thread 46 state: waiting for completed aio requests (read thread)
I/O thread 47 state: waiting for completed aio requests (read thread)
I/O thread 48 state: waiting for completed aio requests (read thread)
I/O thread 49 state: waiting for completed aio requests (read thread)
I/O thread 50 state: waiting for completed aio requests (read thread)
I/O thread 51 state: waiting for completed aio requests (read thread)
I/O thread 52 state: waiting for completed aio requests (read thread)
I/O thread 53 state: waiting for completed aio requests (read thread)
I/O thread 54 state: waiting for completed aio requests (read thread)
I/O thread 55 state: waiting for completed aio requests (read thread)
I/O thread 56 state: waiting for completed aio requests (read thread)
I/O thread 57 state: waiting for completed aio requests (read thread)
I/O thread 58 state: waiting for completed aio requests (read thread)
I/O thread 59 state: waiting for completed aio requests (read thread)
I/O thread 60 state: waiting for completed aio requests (read thread)
I/O thread 61 state: waiting for completed aio requests (read thread)
I/O thread 62 state: waiting for completed aio requests (read thread)
I/O thread 63 state: waiting for completed aio requests (read thread)
I/O thread 64 state: waiting for completed aio requests (read thread)
I/O thread 65 state: waiting for completed aio requests (read thread)
I/O thread 66 state: waiting for completed aio requests (write thread)
I/O thread 67 state: waiting for completed aio requests (write thread)
I/O thread 68 state: waiting for completed aio requests (write thread)
I/O thread 69 state: waiting for completed aio requests (write thread)
I/O thread 70 state: waiting for completed aio requests (write thread)
I/O thread 71 state: waiting for completed aio requests (write thread)
I/O thread 72 state: waiting for completed aio requests (write thread)
I/O thread 73 state: waiting for completed aio requests (write thread)
I/O thread 74 state: waiting for completed aio requests (write thread)
I/O thread 75 state: waiting for completed aio requests (write thread)
I/O thread 76 state: waiting for completed aio requests (write thread)
I/O thread 77 state: waiting for completed aio requests (write thread)
I/O thread 78 state: waiting for completed aio requests (write thread)
I/O thread 79 state: waiting for completed aio requests (write thread)
I/O thread 80 state: waiting for completed aio requests (write thread)
I/O thread 81 state: waiting for completed aio requests (write thread)
I/O thread 82 state: waiting for completed aio requests (write thread)
I/O thread 83 state: waiting for completed aio requests (write thread)
I/O thread 84 state: waiting for completed aio requests (write thread)
I/O thread 85 state: waiting for completed aio requests (write thread)
I/O thread 86 state: waiting for completed aio requests (write thread)
I/O thread 87 state: waiting for completed aio requests (write thread)
I/O thread 88 state: waiting for completed aio requests (write thread)
I/O thread 89 state: waiting for completed aio requests (write thread)
I/O thread 90 state: waiting for completed aio requests (write thread)
I/O thread 91 state: waiting for completed aio requests (write thread)
I/O thread 92 state: waiting for completed aio requests (write thread)
I/O thread 93 state: waiting for completed aio requests (write thread)
I/O thread 94 state: waiting for completed aio requests (write thread)
I/O thread 95 state: waiting for completed aio requests (write thread)
I/O thread 96 state: waiting for completed aio requests (write thread)
I/O thread 97 state: waiting for completed aio requests (write thread)
I/O thread 98 state: waiting for completed aio requests (write thread)
I/O thread 99 state: waiting for completed aio requests (write thread)
I/O thread 100 state: waiting for completed aio requests (write thread)
I/O thread 101 state: waiting for completed aio requests (write thread)
I/O thread 102 state: waiting for completed aio requests (write thread)
I/O thread 103 state: waiting for completed aio requests (write thread)
I/O thread 104 state: waiting for completed aio requests (write thread)
I/O thread 105 state: waiting for completed aio requests (write thread)
I/O thread 106 state: waiting for completed aio requests (write thread)
I/O thread 107 state: waiting for completed aio requests (write thread)
I/O thread 108 state: waiting for completed aio requests (write thread)
I/O thread 109 state: waiting for completed aio requests (write thread)
I/O thread 110 state: waiting for completed aio requests (write thread)
I/O thread 111 state: waiting for completed aio requests (write thread)
I/O thread 112 state: waiting for completed aio requests (write thread)
I/O thread 113 state: waiting for completed aio requests (write thread)
I/O thread 114 state: waiting for completed aio requests (write thread)
I/O thread 115 state: waiting for completed aio requests (write thread)
I/O thread 116 state: waiting for completed aio requests (write thread)
I/O thread 117 state: waiting for completed aio requests (write thread)
I/O thread 118 state: waiting for completed aio requests (write thread)
I/O thread 119 state: waiting for completed aio requests (write thread)
I/O thread 120 state: waiting for completed aio requests (write thread)
I/O thread 121 state: waiting for completed aio requests (write thread)
I/O thread 122 state: waiting for completed aio requests (write thread)
I/O thread 123 state: waiting for completed aio requests (write thread)
I/O thread 124 state: waiting for completed aio requests (write thread)
I/O thread 125 state: waiting for completed aio requests (write thread)
I/O thread 126 state: waiting for completed aio requests (write thread)
I/O thread 127 state: waiting for completed aio requests (write thread)
I/O thread 128 state: waiting for completed aio requests (write thread)
I/O thread 129 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
8353 OS file reads, 2256885 OS file writes, 649203 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 6.37 writes/s, 1.75 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 108 merges
merged operations:
insert 1, delete mark 1, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 796871, node heap has 46 buffer(s)
Hash table size 796871, node heap has 8 buffer(s)
Hash table size 796871, node heap has 7 buffer(s)
Hash table size 796871, node heap has 14 buffer(s)
Hash table size 796871, node heap has 23 buffer(s)
Hash table size 796871, node heap has 16 buffer(s)
Hash table size 796871, node heap has 15 buffer(s)
Hash table size 796871, node heap has 94 buffer(s)
234.22 hash searches/s, 8.87 non-hash searches/s
---
LOG
---
Log sequence number 1427669147
Log flushed up to 1427669147
Pages flushed up to 1427669147
Last checkpoint at 1427669138
Max checkpoint age 434154333
Checkpoint age target 420587011
Modified age 0
Checkpoint age 9
0 pending log flushes, 0 pending chkp writes
452361 log i/o's done, 1.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 3353346048
Dictionary memory allocated 11634313
Internal hash tables (constant factor + variable factor)
Adaptive hash index 54687040 (50999744 + 3687296)
Page hash 1107112 (buffer pool 0 only)
Dictionary cache 24384249 (12749936 + 11634313)
File system 1676640 (812272 + 864368)
Lock system 8004712 (7969496 + 35216)
Recovery system 0 (0 + 0)
Buffer pool size 196584
Buffer pool size, bytes 3220832256
Free buffers 146566
Database pages 49795
Old database pages 18321
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 10000, not young 35358
0.00 youngs/s, 0.00 non-youngs/s
Pages read 7697, created 42280, written 1645380
0.00 reads/s, 0.00 creates/s, 5.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 49795, unzip_LRU len: 0
I/O sum[807]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48863
Database pages 16588
Old database pages 6103
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3655, not young 13239
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2611, created 14049, written 334207
0.00 reads/s, 0.00 creates/s, 0.50 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16588, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48627
Database pages 16823
Old database pages 6190
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3253, not young 12647
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2476, created 14408, written 1147163
0.00 reads/s, 0.00 creates/s, 3.87 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16823, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 49076
Database pages 16384
Old database pages 6028
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3092, not young 9472
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2610, created 13823, written 164010
0.00 reads/s, 0.00 creates/s, 0.62 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16384, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
0 RW transactions active inside InnoDB
Process ID=1574, Main thread ID=140097892615936, state: sleeping
Number of rows inserted 25413524, updated 63914, deleted 6172, read 1035018804
65.87 inserts/s, 0.12 updates/s, 0.00 deletes/s, 97.36 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT


Are there any tell tell signs from the above info causing these timeouts and deadlocks? How can i find out the percentage of utilized InnoDB buffer pool against total RAM?



Ping Results



64 bytes from 10.1.5.100: icmp_seq=1 ttl=64 time=0.958 ms
64 bytes from 10.1.5.100: icmp_seq=2 ttl=64 time=1.09 ms
64 bytes from 10.1.5.100: icmp_seq=4 ttl=64 time=1.22 ms
64 bytes from 10.1.5.100: icmp_seq=5 ttl=64 time=2.24 ms


DEADLOCK INFO



*** Priority TRANSACTION:
TRANSACTION 165015546, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
MySQL thread id 14, OS thread handle 140101363758848, query id 11358891 System lock

*** Victim TRANSACTION:
TRANSACTION 165015100, ACTIVE 1 sec
, undo log entries 1
MySQL thread id 1027074, OS thread handle 140096133596928, query id 11358888 10.168.103.11 membership wsrep: initiating replication for write set (-1)
COMMIT
*** WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2481 page no 17 n bits 80 index PRIMARY of table `membership`.`member_token` trx id 165015100 lock_mode X locks rec but not gap
2018-12-06T03:12:23.732058-00:00 14 [Note] WSREP: --------- CONFLICT DETECTED --------
2018-12-06T03:12:23.732119-00:00 14 [Note] WSREP: cluster conflict due to high priority abort for threads:

2018-12-06T03:12:23.732331-00:00 14 [Note] WSREP: Winning thread:
THD: 14, mode: applier, state: executing, conflict: no conflict, seqno: 152121
SQL: (null)

2018-12-06T03:12:23.732392-00:00 14 [Note] WSREP: Victim thread:
THD: 1027074, mode: local, state: committing, conflict: no conflict, seqno: -1
SQL: COMMIT









share|improve this question
















I have a PXC cluster (5.7) with three nodes running on CentOS 7 VMs, each with the following system info:



mysql_db# free 
total used free shared buff/cache available
Mem: 8009248 2591576 358504 146040 5059168 4875716
Swap: 5242876 3592 5239284
mysql_db# free -g
total used free shared buff/cache available
Mem: 7 2 0 0 4 4
Swap: 4 0 4
mysql_db# nproc
8

mysql_db# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/cl-root 44G 20G 25G 46% /
devtmpfs 3.9G 0 3.9G 0% /dev
tmpfs 3.9G 0 3.9G 0% /dev/shm
tmpfs 3.9G 146M 3.7G 4% /run
tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup
/dev/sda1 1014M 272M 743M 27% /boot
tmpfs 783M 0 783M 0% /run/user/1318214225
tmpfs 783M 0 783M 0% /run/user/0

mysql_db# top
top - 07:39:38 up 50 days, 4:54, 2 users, load average: 0.46, 0.61, 0.61
Tasks: 227 total, 1 running, 226 sleeping, 0 stopped, 0 zombie
%Cpu(s): 20.3 us, 4.0 sy, 0.0 ni, 75.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 8009248 total, 357176 free, 2592348 used, 5059724 buff/cache
KiB Swap: 5242876 total, 5239284 free, 3592 used. 4874700 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1574 mysql 20 0 9241472 2.3g 238932 S 104.8 30.1 6343:02 mysqld
3988 root 20 0 172268 2348 1580 R 19.0 0.0 0:00.12 top
13164 root 20 0 177264 94680 4676 S 19.0 1.2 2693:42 mysqld_exporter
1 root 20 0 191404 4420 2612 S 0.0 0.1 187:50.00 systemd

mysql_db# iostat
Linux 3.10.0-862.14.4.el7.x86_64 (dev_mysql_02.pd.local) 11/20/2018 _x86_64_ (8 CPU)

avg-cpu: %user %nice %system %iowait %steal %idle
2.35 0.00 0.36 0.05 0.00 97.24

Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn
sda 3.83 153.19 153.17 664744979 664666279
dm-0 3.74 139.26 153.17 604320443 664647691
dm-1 0.00 0.00 0.00 2236 2460

mysql_db#lscpu
Architecture: x86_64
CPU op-mode(s): 32-bit, 64-bit
Byte Order: Little Endian
CPU(s): 8
On-line CPU(s) list: 0-7
Thread(s) per core: 1
Core(s) per socket: 1
Socket(s): 8
NUMA node(s): 1
Vendor ID: AuthenticAMD
CPU family: 21
Model: 1
Model name: AMD Opteron(TM) Processor 6276
Stepping: 2
CPU MHz: 2300.028
BogoMIPS: 4600.05
Hypervisor vendor: VMware
Virtualization type: full
L1d cache: 16K
L1i cache: 64K
L2 cache: 2048K
L3 cache: 12288K
NUMA node0 CPU(s): 0-7


Below is some important InnoDB variables in the my.cnf config file:



...
back_log = 65535
binlog_format = ROW
character_set_server = utf8
collation_server = utf8_general_ci
default_storage_engine = InnoDB
enforce-gtid-consistency = 1
expand_fast_index_creation = 1
gtid_mode = ON
innodb_autoinc_lock_mode = 2
innodb_buffer_pool_instances = 3
innodb_buffer_pool_size = 3G
innodb_data_file_path = ibdata1:64M;ibdata2:64M:autoextend
innodb_file_format = Barracuda
innodb_file_per_table
innodb_flush_log_at_trx_commit = 2
innodb_flush_method = O_DIRECT
innodb_io_capacity = 1600
innodb_large_prefix
innodb_log_file_size = 256M
innodb_print_all_deadlocks = 1
innodb_read_io_threads = 64
innodb_stats_on_metadata = FALSE
innodb_write_io_threads = 64
long_query_time = 1
log_bin_trust_function_creators = 1
master_info_repository = TABLE
max_allowed_packet = 64M
max_connect_errors = 4294967295
max_connections = 2600
max_user_connections = 2500
min_examined_row_limit = 1000
relay_log_info_repository = TABLE
relay-log-recovery = TRUE
skip-name-resolve
slave_parallel_workers = 8
slow_query_log = 1
#slow_query_log_timestamp_always = 1
#thread_cache = 1024
tmpdir = /srv/tmp
transaction_isolation = READ-COMMITTED
updatable_views_with_limit = 0
user = mysql
wait_timeout = 60
userstat
table_open_cache = 4096
innodb_open_files = 10240
open_files_limit = 10240
connect_timeout=60
thread_cache_size = 4096
sql_mode = NO_ENGINE_SUBSTITUTION
query_cache_size = 0
slave_pending_jobs_size_max=32M
range_optimizer_max_mem_size=8M
log_timestamps=SYSTEM
server-id= 172162 #use IP
userstat=1
...


As seen above, i have set innodb_buffer_pool_size to 3GB, but not sure if this is a good value given the system info provided above, especially that Total RAM is 7.6GB, with about 5GB allocated to SWAP. We have noticed in the mysql error logs a lot of timeouts and deadlocks frequently happening, and running SHOW ENGINE INNODB STATUS shows this:



    Status: 
=====================================
2018-11-20 07:46:14 0x7f6acc0f9700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 8 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 201141 srv_active, 0 srv_shutdown, 2836117 srv_idle
srv_master_thread log flush and writes: 3037214
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 32658
OS WAIT ARRAY INFO: signal count 33393
RW-shared spins 0, rounds 156414, OS waits 27395
RW-excl spins 0, rounds 222081, OS waits 1171
RW-sx spins 11313, rounds 167795, OS waits 1583
Spin rounds per wait: 156414.00 RW-shared, 222081.00 RW-excl, 14.83 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2018-11-20 07:06:51 0x7f6aad2eb700 Transaction:
TRANSACTION 25842563, ACTIVE 1 sec updating or deleting
mysql tables in use 1, locked 1
12 lock struct(s), heap size 1136, 6 row lock(s), undo log entries 3
MySQL thread id 577793, OS thread handle 140096148780800, query id 3550710 10.168.103.11 slashire_dev update
INSERT INTO member_bank_acct (`ba_member_id`,`ba_create_user`,`ba_update_user`,`ba_country`,`ba_name`,`ba_currency`,`ba_bank_name`,`ba_bank_acct_num`,`ba_swift_code`,`ba_city`,`ba_branch`,`ba_iban`,`ba_beneficiary_bank`) VALUES ('00000000000000000252','SYSTEM','SYSTEM','','','','','','','','','','') ON DUPLICATE KEY UPDATE `ba_country` = '',`ba_name` = '',`ba_currency` = '',`ba_bank_name` = '',`ba_bank_acct_num` = '',`ba_swift_code` = '',`ba_city` = '',`ba_branch` = '',`ba_iban` = '',`ba_beneficiary_bank` = ''
Foreign key constraint fails for table `slashire_dev`.`member_bank_acct`:
,
CONSTRAINT `member_bank_acct_fk02` FOREIGN KEY (`ba_country`) REFERENCES `country` (`c_code`)
Trying to add in child table, in index member_bank_acct_fk02 tuple:
DATA TUPLE: 2 fields;
0: len 0; hex ; asc ;;
1: len 20; hex 3030303030303030303030303030303030323532; asc 00000000000000000252;;

But in parent table `slashire_dev`.`country`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 2; hex 3030; asc 00;;
1: len 6; hex 00000000566c; asc Vl;;
2: len 7; hex b0000001eb0110; asc ;;
3: len 3; hex 416c6c; asc All;;
4: len 2; hex 8000; asc ;;
5: len 5; hex 999f0c0000; asc ;;
6: len 6; hex 53595354454d; asc SYSTEM;;
7: len 5; hex 999f0c0000; asc ;;
8: len 6; hex 53595354454d; asc SYSTEM;;

------------
TRANSACTIONS
------------
Trx id counter 25989367
Purge done for trx's n:o < 25989079 undo n:o < 0 state: running but idle
History list length 27
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421576625901616, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625897008, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625900464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625899312, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625895856, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625898160, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625890096, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625893552, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625888944, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625867056, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625894704, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625892400, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625891248, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625886640, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625887792, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625885488, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625884336, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625883184, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625882032, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625880880, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625879728, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625878576, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625877424, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625876272, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625875120, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625873968, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625872816, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625871664, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625870512, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625869360, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421576625868208, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (read thread)
I/O thread 7 state: waiting for completed aio requests (read thread)
I/O thread 8 state: waiting for completed aio requests (read thread)
I/O thread 9 state: waiting for completed aio requests (read thread)
I/O thread 10 state: waiting for completed aio requests (read thread)
I/O thread 11 state: waiting for completed aio requests (read thread)
I/O thread 12 state: waiting for completed aio requests (read thread)
I/O thread 13 state: waiting for completed aio requests (read thread)
I/O thread 14 state: waiting for completed aio requests (read thread)
I/O thread 15 state: waiting for completed aio requests (read thread)
I/O thread 16 state: waiting for completed aio requests (read thread)
I/O thread 17 state: waiting for completed aio requests (read thread)
I/O thread 18 state: waiting for completed aio requests (read thread)
I/O thread 19 state: waiting for completed aio requests (read thread)
I/O thread 20 state: waiting for completed aio requests (read thread)
I/O thread 21 state: waiting for completed aio requests (read thread)
I/O thread 22 state: waiting for completed aio requests (read thread)
I/O thread 23 state: waiting for completed aio requests (read thread)
I/O thread 24 state: waiting for completed aio requests (read thread)
I/O thread 25 state: waiting for completed aio requests (read thread)
I/O thread 26 state: waiting for completed aio requests (read thread)
I/O thread 27 state: waiting for completed aio requests (read thread)
I/O thread 28 state: waiting for completed aio requests (read thread)
I/O thread 29 state: waiting for completed aio requests (read thread)
I/O thread 30 state: waiting for completed aio requests (read thread)
I/O thread 31 state: waiting for completed aio requests (read thread)
I/O thread 32 state: waiting for completed aio requests (read thread)
I/O thread 33 state: waiting for completed aio requests (read thread)
I/O thread 34 state: waiting for completed aio requests (read thread)
I/O thread 35 state: waiting for completed aio requests (read thread)
I/O thread 36 state: waiting for completed aio requests (read thread)
I/O thread 37 state: waiting for completed aio requests (read thread)
I/O thread 38 state: waiting for completed aio requests (read thread)
I/O thread 39 state: waiting for completed aio requests (read thread)
I/O thread 40 state: waiting for completed aio requests (read thread)
I/O thread 41 state: waiting for completed aio requests (read thread)
I/O thread 42 state: waiting for completed aio requests (read thread)
I/O thread 43 state: waiting for completed aio requests (read thread)
I/O thread 44 state: waiting for completed aio requests (read thread)
I/O thread 45 state: waiting for completed aio requests (read thread)
I/O thread 46 state: waiting for completed aio requests (read thread)
I/O thread 47 state: waiting for completed aio requests (read thread)
I/O thread 48 state: waiting for completed aio requests (read thread)
I/O thread 49 state: waiting for completed aio requests (read thread)
I/O thread 50 state: waiting for completed aio requests (read thread)
I/O thread 51 state: waiting for completed aio requests (read thread)
I/O thread 52 state: waiting for completed aio requests (read thread)
I/O thread 53 state: waiting for completed aio requests (read thread)
I/O thread 54 state: waiting for completed aio requests (read thread)
I/O thread 55 state: waiting for completed aio requests (read thread)
I/O thread 56 state: waiting for completed aio requests (read thread)
I/O thread 57 state: waiting for completed aio requests (read thread)
I/O thread 58 state: waiting for completed aio requests (read thread)
I/O thread 59 state: waiting for completed aio requests (read thread)
I/O thread 60 state: waiting for completed aio requests (read thread)
I/O thread 61 state: waiting for completed aio requests (read thread)
I/O thread 62 state: waiting for completed aio requests (read thread)
I/O thread 63 state: waiting for completed aio requests (read thread)
I/O thread 64 state: waiting for completed aio requests (read thread)
I/O thread 65 state: waiting for completed aio requests (read thread)
I/O thread 66 state: waiting for completed aio requests (write thread)
I/O thread 67 state: waiting for completed aio requests (write thread)
I/O thread 68 state: waiting for completed aio requests (write thread)
I/O thread 69 state: waiting for completed aio requests (write thread)
I/O thread 70 state: waiting for completed aio requests (write thread)
I/O thread 71 state: waiting for completed aio requests (write thread)
I/O thread 72 state: waiting for completed aio requests (write thread)
I/O thread 73 state: waiting for completed aio requests (write thread)
I/O thread 74 state: waiting for completed aio requests (write thread)
I/O thread 75 state: waiting for completed aio requests (write thread)
I/O thread 76 state: waiting for completed aio requests (write thread)
I/O thread 77 state: waiting for completed aio requests (write thread)
I/O thread 78 state: waiting for completed aio requests (write thread)
I/O thread 79 state: waiting for completed aio requests (write thread)
I/O thread 80 state: waiting for completed aio requests (write thread)
I/O thread 81 state: waiting for completed aio requests (write thread)
I/O thread 82 state: waiting for completed aio requests (write thread)
I/O thread 83 state: waiting for completed aio requests (write thread)
I/O thread 84 state: waiting for completed aio requests (write thread)
I/O thread 85 state: waiting for completed aio requests (write thread)
I/O thread 86 state: waiting for completed aio requests (write thread)
I/O thread 87 state: waiting for completed aio requests (write thread)
I/O thread 88 state: waiting for completed aio requests (write thread)
I/O thread 89 state: waiting for completed aio requests (write thread)
I/O thread 90 state: waiting for completed aio requests (write thread)
I/O thread 91 state: waiting for completed aio requests (write thread)
I/O thread 92 state: waiting for completed aio requests (write thread)
I/O thread 93 state: waiting for completed aio requests (write thread)
I/O thread 94 state: waiting for completed aio requests (write thread)
I/O thread 95 state: waiting for completed aio requests (write thread)
I/O thread 96 state: waiting for completed aio requests (write thread)
I/O thread 97 state: waiting for completed aio requests (write thread)
I/O thread 98 state: waiting for completed aio requests (write thread)
I/O thread 99 state: waiting for completed aio requests (write thread)
I/O thread 100 state: waiting for completed aio requests (write thread)
I/O thread 101 state: waiting for completed aio requests (write thread)
I/O thread 102 state: waiting for completed aio requests (write thread)
I/O thread 103 state: waiting for completed aio requests (write thread)
I/O thread 104 state: waiting for completed aio requests (write thread)
I/O thread 105 state: waiting for completed aio requests (write thread)
I/O thread 106 state: waiting for completed aio requests (write thread)
I/O thread 107 state: waiting for completed aio requests (write thread)
I/O thread 108 state: waiting for completed aio requests (write thread)
I/O thread 109 state: waiting for completed aio requests (write thread)
I/O thread 110 state: waiting for completed aio requests (write thread)
I/O thread 111 state: waiting for completed aio requests (write thread)
I/O thread 112 state: waiting for completed aio requests (write thread)
I/O thread 113 state: waiting for completed aio requests (write thread)
I/O thread 114 state: waiting for completed aio requests (write thread)
I/O thread 115 state: waiting for completed aio requests (write thread)
I/O thread 116 state: waiting for completed aio requests (write thread)
I/O thread 117 state: waiting for completed aio requests (write thread)
I/O thread 118 state: waiting for completed aio requests (write thread)
I/O thread 119 state: waiting for completed aio requests (write thread)
I/O thread 120 state: waiting for completed aio requests (write thread)
I/O thread 121 state: waiting for completed aio requests (write thread)
I/O thread 122 state: waiting for completed aio requests (write thread)
I/O thread 123 state: waiting for completed aio requests (write thread)
I/O thread 124 state: waiting for completed aio requests (write thread)
I/O thread 125 state: waiting for completed aio requests (write thread)
I/O thread 126 state: waiting for completed aio requests (write thread)
I/O thread 127 state: waiting for completed aio requests (write thread)
I/O thread 128 state: waiting for completed aio requests (write thread)
I/O thread 129 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
8353 OS file reads, 2256885 OS file writes, 649203 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 6.37 writes/s, 1.75 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 108 merges
merged operations:
insert 1, delete mark 1, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 796871, node heap has 46 buffer(s)
Hash table size 796871, node heap has 8 buffer(s)
Hash table size 796871, node heap has 7 buffer(s)
Hash table size 796871, node heap has 14 buffer(s)
Hash table size 796871, node heap has 23 buffer(s)
Hash table size 796871, node heap has 16 buffer(s)
Hash table size 796871, node heap has 15 buffer(s)
Hash table size 796871, node heap has 94 buffer(s)
234.22 hash searches/s, 8.87 non-hash searches/s
---
LOG
---
Log sequence number 1427669147
Log flushed up to 1427669147
Pages flushed up to 1427669147
Last checkpoint at 1427669138
Max checkpoint age 434154333
Checkpoint age target 420587011
Modified age 0
Checkpoint age 9
0 pending log flushes, 0 pending chkp writes
452361 log i/o's done, 1.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 3353346048
Dictionary memory allocated 11634313
Internal hash tables (constant factor + variable factor)
Adaptive hash index 54687040 (50999744 + 3687296)
Page hash 1107112 (buffer pool 0 only)
Dictionary cache 24384249 (12749936 + 11634313)
File system 1676640 (812272 + 864368)
Lock system 8004712 (7969496 + 35216)
Recovery system 0 (0 + 0)
Buffer pool size 196584
Buffer pool size, bytes 3220832256
Free buffers 146566
Database pages 49795
Old database pages 18321
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 10000, not young 35358
0.00 youngs/s, 0.00 non-youngs/s
Pages read 7697, created 42280, written 1645380
0.00 reads/s, 0.00 creates/s, 5.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 49795, unzip_LRU len: 0
I/O sum[807]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48863
Database pages 16588
Old database pages 6103
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3655, not young 13239
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2611, created 14049, written 334207
0.00 reads/s, 0.00 creates/s, 0.50 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16588, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 48627
Database pages 16823
Old database pages 6190
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3253, not young 12647
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2476, created 14408, written 1147163
0.00 reads/s, 0.00 creates/s, 3.87 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16823, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 65528
Buffer pool size, bytes 1073610752
Free buffers 49076
Database pages 16384
Old database pages 6028
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3092, not young 9472
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2610, created 13823, written 164010
0.00 reads/s, 0.00 creates/s, 0.62 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 16384, unzip_LRU len: 0
I/O sum[269]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
0 RW transactions active inside InnoDB
Process ID=1574, Main thread ID=140097892615936, state: sleeping
Number of rows inserted 25413524, updated 63914, deleted 6172, read 1035018804
65.87 inserts/s, 0.12 updates/s, 0.00 deletes/s, 97.36 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT


Are there any tell tell signs from the above info causing these timeouts and deadlocks? How can i find out the percentage of utilized InnoDB buffer pool against total RAM?



Ping Results



64 bytes from 10.1.5.100: icmp_seq=1 ttl=64 time=0.958 ms
64 bytes from 10.1.5.100: icmp_seq=2 ttl=64 time=1.09 ms
64 bytes from 10.1.5.100: icmp_seq=4 ttl=64 time=1.22 ms
64 bytes from 10.1.5.100: icmp_seq=5 ttl=64 time=2.24 ms


DEADLOCK INFO



*** Priority TRANSACTION:
TRANSACTION 165015546, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
MySQL thread id 14, OS thread handle 140101363758848, query id 11358891 System lock

*** Victim TRANSACTION:
TRANSACTION 165015100, ACTIVE 1 sec
, undo log entries 1
MySQL thread id 1027074, OS thread handle 140096133596928, query id 11358888 10.168.103.11 membership wsrep: initiating replication for write set (-1)
COMMIT
*** WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2481 page no 17 n bits 80 index PRIMARY of table `membership`.`member_token` trx id 165015100 lock_mode X locks rec but not gap
2018-12-06T03:12:23.732058-00:00 14 [Note] WSREP: --------- CONFLICT DETECTED --------
2018-12-06T03:12:23.732119-00:00 14 [Note] WSREP: cluster conflict due to high priority abort for threads:

2018-12-06T03:12:23.732331-00:00 14 [Note] WSREP: Winning thread:
THD: 14, mode: applier, state: executing, conflict: no conflict, seqno: 152121
SQL: (null)

2018-12-06T03:12:23.732392-00:00 14 [Note] WSREP: Victim thread:
THD: 1027074, mode: local, state: committing, conflict: no conflict, seqno: -1
SQL: COMMIT






innodb mysql-5.7 percona galera xtradb-cluster






share|improve this question















share|improve this question













share|improve this question




share|improve this question








edited Dec 12 '18 at 1:55







The Georgia

















asked Nov 20 '18 at 7:49









The GeorgiaThe Georgia

203314




203314





bumped to the homepage by Community 34 mins ago


This question has answers that may be good or bad; the system has marked it active so that they can be reviewed.







bumped to the homepage by Community 34 mins ago


This question has answers that may be good or bad; the system has marked it active so that they can be reviewed.















  • These values indicate usage : Buffer pool size 196584 -- total number of pages Free buffers 146566 -- number of free pages Repeated in individual buffer pool info.

    – percona-lorraine
    Nov 20 '18 at 14:00













  • So it means only a small percentage of allocated innodb buffer pool is being used, and hence the timeout and deadlock issues we are experiencing as not caused by memory issues? From the log files, we are pretty much getting 90% of these kind of mesages 2018-11-21T01:54:14.034573-00:00 190701 [Note] Aborted connection 190701 to db: 'event' user: 'eventdb' host: '10.1.0.100' (Got timeout reading communication packets)

    – The Georgia
    Nov 21 '18 at 2:07











  • I have also added CPU info for more info.

    – The Georgia
    Nov 21 '18 at 2:38



















  • These values indicate usage : Buffer pool size 196584 -- total number of pages Free buffers 146566 -- number of free pages Repeated in individual buffer pool info.

    – percona-lorraine
    Nov 20 '18 at 14:00













  • So it means only a small percentage of allocated innodb buffer pool is being used, and hence the timeout and deadlock issues we are experiencing as not caused by memory issues? From the log files, we are pretty much getting 90% of these kind of mesages 2018-11-21T01:54:14.034573-00:00 190701 [Note] Aborted connection 190701 to db: 'event' user: 'eventdb' host: '10.1.0.100' (Got timeout reading communication packets)

    – The Georgia
    Nov 21 '18 at 2:07











  • I have also added CPU info for more info.

    – The Georgia
    Nov 21 '18 at 2:38

















These values indicate usage : Buffer pool size 196584 -- total number of pages Free buffers 146566 -- number of free pages Repeated in individual buffer pool info.

– percona-lorraine
Nov 20 '18 at 14:00







These values indicate usage : Buffer pool size 196584 -- total number of pages Free buffers 146566 -- number of free pages Repeated in individual buffer pool info.

– percona-lorraine
Nov 20 '18 at 14:00















So it means only a small percentage of allocated innodb buffer pool is being used, and hence the timeout and deadlock issues we are experiencing as not caused by memory issues? From the log files, we are pretty much getting 90% of these kind of mesages 2018-11-21T01:54:14.034573-00:00 190701 [Note] Aborted connection 190701 to db: 'event' user: 'eventdb' host: '10.1.0.100' (Got timeout reading communication packets)

– The Georgia
Nov 21 '18 at 2:07





So it means only a small percentage of allocated innodb buffer pool is being used, and hence the timeout and deadlock issues we are experiencing as not caused by memory issues? From the log files, we are pretty much getting 90% of these kind of mesages 2018-11-21T01:54:14.034573-00:00 190701 [Note] Aborted connection 190701 to db: 'event' user: 'eventdb' host: '10.1.0.100' (Got timeout reading communication packets)

– The Georgia
Nov 21 '18 at 2:07













I have also added CPU info for more info.

– The Georgia
Nov 21 '18 at 2:38





I have also added CPU info for more info.

– The Georgia
Nov 21 '18 at 2:38










1 Answer
1






active

oldest

votes


















0














SHOW ENGINE INNODB STATUS; is transient. It looks like you waited too long before running that. Try again. See below.



3G on a 7.5GB server is fine. If you had a bigger dataset, 5G would be slightly better.



back_log = 65535 -- drop this to 50

innodb_print_all_deadlocks = 1 -- look in the log file

max_user_connections = 2500 -- do you really expect to hit this?

slow_query_log = 1 -- what good stuff is in the slowlog (use pt-query-digest)


What is the ping time between the nodes? How many nodes?






share|improve this answer
























  • Hi James, what are these variables have to do with timeouts and deadlocks? I honestly do not thing making adjustments to these variables would effect the current timeout and deadlock situation can it?

    – The Georgia
    Dec 11 '18 at 9:45











  • I have added ping results to the original post.

    – The Georgia
    Dec 11 '18 at 9:46











  • @TheGeorgia - 1ms -- no problem. I was afraid it was a cross-country hop.

    – Rick James
    Dec 11 '18 at 16:46











  • @TheGeorgia - OK, none of the variables apply directly. But, having lots of connections can lead to related problems. Print_all_deadlocks and the slowlog are a debugging tools.

    – Rick James
    Dec 11 '18 at 16:47











  • Ah i see. Actually if you look at my my.cnf config, i have enabled innodb_print_all_deadlocks and slowlog. And the results from error log is how i knew i am experiencing deadlocks. The deadlocks do not give much info, except the table causing them. Please see added info about deadlocks in the original post. FYI, i am using a 3 node PXC.

    – The Georgia
    Dec 12 '18 at 1:49











Your Answer








StackExchange.ready(function() {
var channelOptions = {
tags: "".split(" "),
id: "182"
};
initTagRenderer("".split(" "), "".split(" "), channelOptions);

StackExchange.using("externalEditor", function() {
// Have to fire editor after snippets, if snippets enabled
if (StackExchange.settings.snippets.snippetsEnabled) {
StackExchange.using("snippets", function() {
createEditor();
});
}
else {
createEditor();
}
});

function createEditor() {
StackExchange.prepareEditor({
heartbeatType: 'answer',
autoActivateHeartbeat: false,
convertImagesToLinks: false,
noModals: true,
showLowRepImageUploadWarning: true,
reputationToPostImages: null,
bindNavPrevention: true,
postfix: "",
imageUploader: {
brandingHtml: "Powered by u003ca class="icon-imgur-white" href="https://imgur.com/"u003eu003c/au003e",
contentPolicyHtml: "User contributions licensed under u003ca href="https://creativecommons.org/licenses/by-sa/3.0/"u003ecc by-sa 3.0 with attribution requiredu003c/au003e u003ca href="https://stackoverflow.com/legal/content-policy"u003e(content policy)u003c/au003e",
allowUrls: true
},
onDemand: true,
discardSelector: ".discard-answer"
,immediatelyShowMarkdownHelp:true
});


}
});














draft saved

draft discarded


















StackExchange.ready(
function () {
StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fdba.stackexchange.com%2fquestions%2f222948%2finnodb-buffer-causing-a-lot-of-deadlocks-and-connection-client-timeouts%23new-answer', 'question_page');
}
);

Post as a guest















Required, but never shown

























1 Answer
1






active

oldest

votes








1 Answer
1






active

oldest

votes









active

oldest

votes






active

oldest

votes









0














SHOW ENGINE INNODB STATUS; is transient. It looks like you waited too long before running that. Try again. See below.



3G on a 7.5GB server is fine. If you had a bigger dataset, 5G would be slightly better.



back_log = 65535 -- drop this to 50

innodb_print_all_deadlocks = 1 -- look in the log file

max_user_connections = 2500 -- do you really expect to hit this?

slow_query_log = 1 -- what good stuff is in the slowlog (use pt-query-digest)


What is the ping time between the nodes? How many nodes?






share|improve this answer
























  • Hi James, what are these variables have to do with timeouts and deadlocks? I honestly do not thing making adjustments to these variables would effect the current timeout and deadlock situation can it?

    – The Georgia
    Dec 11 '18 at 9:45











  • I have added ping results to the original post.

    – The Georgia
    Dec 11 '18 at 9:46











  • @TheGeorgia - 1ms -- no problem. I was afraid it was a cross-country hop.

    – Rick James
    Dec 11 '18 at 16:46











  • @TheGeorgia - OK, none of the variables apply directly. But, having lots of connections can lead to related problems. Print_all_deadlocks and the slowlog are a debugging tools.

    – Rick James
    Dec 11 '18 at 16:47











  • Ah i see. Actually if you look at my my.cnf config, i have enabled innodb_print_all_deadlocks and slowlog. And the results from error log is how i knew i am experiencing deadlocks. The deadlocks do not give much info, except the table causing them. Please see added info about deadlocks in the original post. FYI, i am using a 3 node PXC.

    – The Georgia
    Dec 12 '18 at 1:49
















0














SHOW ENGINE INNODB STATUS; is transient. It looks like you waited too long before running that. Try again. See below.



3G on a 7.5GB server is fine. If you had a bigger dataset, 5G would be slightly better.



back_log = 65535 -- drop this to 50

innodb_print_all_deadlocks = 1 -- look in the log file

max_user_connections = 2500 -- do you really expect to hit this?

slow_query_log = 1 -- what good stuff is in the slowlog (use pt-query-digest)


What is the ping time between the nodes? How many nodes?






share|improve this answer
























  • Hi James, what are these variables have to do with timeouts and deadlocks? I honestly do not thing making adjustments to these variables would effect the current timeout and deadlock situation can it?

    – The Georgia
    Dec 11 '18 at 9:45











  • I have added ping results to the original post.

    – The Georgia
    Dec 11 '18 at 9:46











  • @TheGeorgia - 1ms -- no problem. I was afraid it was a cross-country hop.

    – Rick James
    Dec 11 '18 at 16:46











  • @TheGeorgia - OK, none of the variables apply directly. But, having lots of connections can lead to related problems. Print_all_deadlocks and the slowlog are a debugging tools.

    – Rick James
    Dec 11 '18 at 16:47











  • Ah i see. Actually if you look at my my.cnf config, i have enabled innodb_print_all_deadlocks and slowlog. And the results from error log is how i knew i am experiencing deadlocks. The deadlocks do not give much info, except the table causing them. Please see added info about deadlocks in the original post. FYI, i am using a 3 node PXC.

    – The Georgia
    Dec 12 '18 at 1:49














0












0








0







SHOW ENGINE INNODB STATUS; is transient. It looks like you waited too long before running that. Try again. See below.



3G on a 7.5GB server is fine. If you had a bigger dataset, 5G would be slightly better.



back_log = 65535 -- drop this to 50

innodb_print_all_deadlocks = 1 -- look in the log file

max_user_connections = 2500 -- do you really expect to hit this?

slow_query_log = 1 -- what good stuff is in the slowlog (use pt-query-digest)


What is the ping time between the nodes? How many nodes?






share|improve this answer













SHOW ENGINE INNODB STATUS; is transient. It looks like you waited too long before running that. Try again. See below.



3G on a 7.5GB server is fine. If you had a bigger dataset, 5G would be slightly better.



back_log = 65535 -- drop this to 50

innodb_print_all_deadlocks = 1 -- look in the log file

max_user_connections = 2500 -- do you really expect to hit this?

slow_query_log = 1 -- what good stuff is in the slowlog (use pt-query-digest)


What is the ping time between the nodes? How many nodes?







share|improve this answer












share|improve this answer



share|improve this answer










answered Dec 7 '18 at 6:07









Rick JamesRick James

43.4k22259




43.4k22259













  • Hi James, what are these variables have to do with timeouts and deadlocks? I honestly do not thing making adjustments to these variables would effect the current timeout and deadlock situation can it?

    – The Georgia
    Dec 11 '18 at 9:45











  • I have added ping results to the original post.

    – The Georgia
    Dec 11 '18 at 9:46











  • @TheGeorgia - 1ms -- no problem. I was afraid it was a cross-country hop.

    – Rick James
    Dec 11 '18 at 16:46











  • @TheGeorgia - OK, none of the variables apply directly. But, having lots of connections can lead to related problems. Print_all_deadlocks and the slowlog are a debugging tools.

    – Rick James
    Dec 11 '18 at 16:47











  • Ah i see. Actually if you look at my my.cnf config, i have enabled innodb_print_all_deadlocks and slowlog. And the results from error log is how i knew i am experiencing deadlocks. The deadlocks do not give much info, except the table causing them. Please see added info about deadlocks in the original post. FYI, i am using a 3 node PXC.

    – The Georgia
    Dec 12 '18 at 1:49



















  • Hi James, what are these variables have to do with timeouts and deadlocks? I honestly do not thing making adjustments to these variables would effect the current timeout and deadlock situation can it?

    – The Georgia
    Dec 11 '18 at 9:45











  • I have added ping results to the original post.

    – The Georgia
    Dec 11 '18 at 9:46











  • @TheGeorgia - 1ms -- no problem. I was afraid it was a cross-country hop.

    – Rick James
    Dec 11 '18 at 16:46











  • @TheGeorgia - OK, none of the variables apply directly. But, having lots of connections can lead to related problems. Print_all_deadlocks and the slowlog are a debugging tools.

    – Rick James
    Dec 11 '18 at 16:47











  • Ah i see. Actually if you look at my my.cnf config, i have enabled innodb_print_all_deadlocks and slowlog. And the results from error log is how i knew i am experiencing deadlocks. The deadlocks do not give much info, except the table causing them. Please see added info about deadlocks in the original post. FYI, i am using a 3 node PXC.

    – The Georgia
    Dec 12 '18 at 1:49

















Hi James, what are these variables have to do with timeouts and deadlocks? I honestly do not thing making adjustments to these variables would effect the current timeout and deadlock situation can it?

– The Georgia
Dec 11 '18 at 9:45





Hi James, what are these variables have to do with timeouts and deadlocks? I honestly do not thing making adjustments to these variables would effect the current timeout and deadlock situation can it?

– The Georgia
Dec 11 '18 at 9:45













I have added ping results to the original post.

– The Georgia
Dec 11 '18 at 9:46





I have added ping results to the original post.

– The Georgia
Dec 11 '18 at 9:46













@TheGeorgia - 1ms -- no problem. I was afraid it was a cross-country hop.

– Rick James
Dec 11 '18 at 16:46





@TheGeorgia - 1ms -- no problem. I was afraid it was a cross-country hop.

– Rick James
Dec 11 '18 at 16:46













@TheGeorgia - OK, none of the variables apply directly. But, having lots of connections can lead to related problems. Print_all_deadlocks and the slowlog are a debugging tools.

– Rick James
Dec 11 '18 at 16:47





@TheGeorgia - OK, none of the variables apply directly. But, having lots of connections can lead to related problems. Print_all_deadlocks and the slowlog are a debugging tools.

– Rick James
Dec 11 '18 at 16:47













Ah i see. Actually if you look at my my.cnf config, i have enabled innodb_print_all_deadlocks and slowlog. And the results from error log is how i knew i am experiencing deadlocks. The deadlocks do not give much info, except the table causing them. Please see added info about deadlocks in the original post. FYI, i am using a 3 node PXC.

– The Georgia
Dec 12 '18 at 1:49





Ah i see. Actually if you look at my my.cnf config, i have enabled innodb_print_all_deadlocks and slowlog. And the results from error log is how i knew i am experiencing deadlocks. The deadlocks do not give much info, except the table causing them. Please see added info about deadlocks in the original post. FYI, i am using a 3 node PXC.

– The Georgia
Dec 12 '18 at 1:49


















draft saved

draft discarded




















































Thanks for contributing an answer to Database Administrators Stack Exchange!


  • Please be sure to answer the question. Provide details and share your research!

But avoid



  • Asking for help, clarification, or responding to other answers.

  • Making statements based on opinion; back them up with references or personal experience.


To learn more, see our tips on writing great answers.




draft saved


draft discarded














StackExchange.ready(
function () {
StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fdba.stackexchange.com%2fquestions%2f222948%2finnodb-buffer-causing-a-lot-of-deadlocks-and-connection-client-timeouts%23new-answer', 'question_page');
}
);

Post as a guest















Required, but never shown





















































Required, but never shown














Required, but never shown












Required, but never shown







Required, but never shown

































Required, but never shown














Required, but never shown












Required, but never shown







Required, but never shown







Popular posts from this blog

SQL Server 17 - Attemping to backup to remote NAS but Access is denied

Always On Availability groups resolving state after failover - Remote harden of transaction...

Restoring from pg_dump with foreign key constraints