Percona Server 5.6 write performance slow GTID on

We were running our application of a windows mysql 5.6 server with standard default settings. The application is performing as expected with circular replication on. On the exact same machine (spec wise) I am running Vmware sphere 5.5 and loaded up centos6.5 with percona server with 3 cores and 8 gig of ram. The application worked well on multiple clients on our network however when we circular enabled replication using GTID to our branch we noticed the application lagging. After persona restart and turning off the replication everything was fine. When we turn on the replication, the app slows down, however I can reproduce the same outcome (this could be a coincidence ). After talking to the developers, we put in database execution times to see were the problem could be. On the most part all reads are fine, the writes are the problem. It is taking several seconds to write to the db. We do random testing, at times everything is working full speed, but most of the time there is a lag due to the writes from the application logs We do not have this problem at all on a windows mysql 5.6 server, however we are not using GTID on that. Any help to solve this problem will be appreciated thanks now for stats:

Update: we tested using circular replication without GTID, and we are having the same problem.

TOP shows percona only using 0.3% CPU and 18% of memory

free shows
total used free shared buffers cached
Mem: 8061500 2127884 5933616 0 117600 559844
-/+ buffers/cache: 1450440 6611060
Swap: 2097144 0 2097144



SHOW INNODB STATUS

| InnoDB | |
=====================================
2014-07-08 14:17:41 7fdc583d1700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 41 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2294 srv_active, 0 srv_shutdown, 260644 srv_idle
srv_master_thread log flush and writes: 262938
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 656
OS WAIT ARRAY INFO: signal count 643
Mutex spin waits 8188, rounds 68767, OS waits 298
RW-shared spins 295, rounds 8739, OS waits 287
RW-excl spins 0, rounds 121, OS waits 4
Spin rounds per wait: 8.40 mutex, 29.62 RW-shared, 121.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 7736510
Purge done for trx's n:o < 7736485 undo n:o < 0 state: running but idle
History list length 2519
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 7281, OS thread handle 0x7fdc583d1700, query id 17762 localhost admin init
SHOW ENGINE INNODB STATUS
--------
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 (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
22820 OS file reads, 9274 OS file writes, 2579 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 9, seg size 11, 34 merges
merged operations:
insert 34, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 16164704746
Log flushed up to 16164704746
Pages flushed up to 16164704746
Last checkpoint at 16164704746
Max checkpoint age 2172672369
Checkpoint age target 2104776358
Modified age 0
Checkpoint age 0
0 pending log writes, 0 pending chkp writes
1259 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 6000001024; in additional pool allocated 0
Total memory allocated by read views 200
Internal hash tables (constant factor + variable factor)
Adaptive hash index 140107312 (92818888 + 47288424)
Page hash 5802184 (buffer pool 0 only)
Dictionary cache 25115007 (23206256 + 1908751)
File system 919432 (812272 + 107160)
Lock system 14504032 (14503672 + 360)
Recovery system 0 (0 + 0)
Dictionary memory allocated 1908751
Buffer pool size 357823
Buffer pool size, bytes 5862572032
Free buffers 332548
Database pages 22389
Old database pages 8284
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 22373, created 16, written 7745
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 22389, unzip_LRU len: 0
I/O sum[0]: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
0 RO transactions active inside InnoDB
0 out of 1000 descriptors used
Main thread process no. 1997, id 140577082447616, state: sleeping
Number of rows inserted 493, updated 336, deleted 79, read 139994198
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
------------
TRANSACTIONS
------------
Trx id counter 7736510
Purge done for trx's n:o < 7736485 undo n:o < 0 state: running but idle
History list length 2519
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 7281, OS thread handle 0x7fdc583d1700, query id 17762 localhost admin init
SHOW ENGINE INNODB STATUS
----------------------------
END OF INNODB MONITOR OUTPUT
============================


percona my.cnf file


[MYSQLD]
#sql-mode = ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
sql-mode = STRICT_TRANS_TABLES,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
user=mysql
basedir=/usr/
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
pid-file=mysqld.pid
port=3306
log-error=/var/log/mysqld.log
log-warnings=2
#log-output=FILE
symbolic-links=1
lower-case-table-names=1


## THREAD POOLS OPTIONS
thread_handling=pool-of-threads
thread_pool_size=2


### INNODB OPTIONS SETTINGS FOR 8GIG RAM and 2 CORE CPU #####
innodb-buffer-pool-size=5591M
innodb-flush-log-at-trx-commit=1
innodb-file-per-table=1
innodb_data_file_path = ibdata1:10M:autoextend
innodb-log-file-size=1280M

## You may want to tune the below depending on number of cores and disk sub
innodb-read-io-threads=4
innodb-write-io-threads=4
innodb-doublewrite=1
innodb-log-buffer-size=8M
innodb-flush-method = O_DIRECT
innodb-buffer-pool-instances=1 # default 8
innodb-log-files-in-group=2
innodb-thread-concurrency=0 #docs say leave it at 0, windows machine got it at 16
innodb-file-format=barracuda
#### Above settings verified ###


### STILL TO VERIFY ########
innodb-locks-unsafe-for-binlog=1
innodb-autoinc-lock-mode=2 # using default 1
## avoid statistics update when doing e.g show tables
#innodb-stats-on-metadata=0
default-storage-engine=innodb

# REPLICATION SPECIFIC - GENERAL
#server-id must be unique across all mysql servers participating in replication.
server-id=1

# REPLICATION SPECIFIC
#binlog_format=ROW
#log-bin=binlog
#relay-log=relay-bin
##expire_logs_days=7
#log-slave-updates=1
#gtid_mode=ON
#enforce-gtid-consistency=1
#master-info-repository=TABLE
#relay-log-info-repository=TABLE

auto_increment_increment=10
auto_increment_offset=1

# OTHER THINGS, BUFFERS ETC
max-connections=800

thread_cache_size=10
key_buffer_size = 64M
table_open_cache=500
sort_buffer_size=4M
read_buffer_size=1M
read-rnd-buffer-size = 4M
max-allowed-packet = 512M
table-open_cache=1024
open_files_limit=3072 # open file limit must be 2X or 3X table open cache


query-cache-type = 1
query-cache-size = 1M #from docs
#query-cache-size = 350M #from win ini

tmp_table_size = 125M
max_heap_table_size = 64M
##myisam-sort-buffer_size = 8M
#skip-name-resolve
#memlock=0
#sysdate-is-now=1
## 5.6 backwards compatibility
#explicit_defaults_for_timestamp=1

[client]
user=admin
password="pass"

[mysqldump]
max-allowed-packet = 512M
#default-character-set=utf8

[MYSQLD_SAFE]
pid-file=mysqld.pid
log-error=/var/log/mysqld.log
basedir=/usr/
datadir=/var/lib/mysql



Hi,

I got no solution but perhaps one hint:
virtual machines are not so easy to manage in relation of the clock. The drift is not comparable to real hw!
So while your circular replication (I really wonder how you managed this via 3 nodes - stable… or your write load is low?) is asynchronous it doesn’t matter what time you have on you machine. I must say I’m not really sure but I would think there’s a difference to a synchronous cluster! I know that you get into trouble on a mongodb system if the machines doesn’t got the exact time.