SQLinfo.ru - Все о MySQL

Форум пользователей MySQL

Задавайте вопросы, мы ответим

Вы не зашли.

#1 14.09.2017 14:25:05

Dimashu
Участник
Зарегистрирован: 04.07.2016
Сообщений: 24

Lock cluster при dedlock

Добрый день. 
После того как я обновился с mariadb 10.1.18 до 10.2 а далее до 10.2.8 , начались страшные глюки ( 10.2.8 обновил в надежде на то что баги пофиксят) 
Когда я включаю на запись/чтение сразу 2 ноды то происходит какая-то дичь. Как я понимаю при дедлоке лочит весь кластер.
Буду благодарен за любую подсказку, хоть в какую сторону копать.
Вот кусок лога где начинается кластер собирать запросы:


SREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long
WSREP: BF lock wait long

=====================================
2017-09-14 17:05:05 0x7fc540fdb700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 13 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 4954 srv_active, 0 srv_shutdown, 65 srv_idle
srv_master_thread log flush and writes: 5019
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 63641
OS WAIT ARRAY INFO: signal count 2894478
RW-shared spins 0, rounds 1453378, OS waits 665
RW-excl spins 0, rounds 2047589, OS waits 496
RW-sx spins 3517, rounds 19470, OS waits 47
Spin rounds per wait: 1453378.00 RW-shared, 2047589.00 RW-excl, 5.54 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 129314164
Purge done for trx's nyikes < 129314142 undo nyikes < 0 state: running but idle
History list length 3
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421994534028440, not started sleeping before entering InnoDB
mysql tables in use 35, locked 35
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421994534026648, not started sleeping before entering InnoDB
mysql tables in use 1, locked 0
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421994534025752, not started sleeping before entering InnoDB
mysql tables in use 1, locked 1
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421994533962136, not started sleeping before entering InnoDB
mysql tables in use 1, locked 1
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421994533940632, not started sleeping before entering InnoDB
mysql tables in use 1, locked 1

......

1 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 1
MySQL thread id 41082, OS thread handle 0x7fcd41f70700, query id 2303387 х.х.х.х myDB query end
INSERT INTO `table` (`id`, `data`, `expire`) VALUES ('qkafar0r1hqd2js30258pnst46', '', '1520949846')
TABLE LOCK table `myDB`.`table` trx id 129314163 lock mode IX
---TRANSACTION 129314162, ACTIVE 59 sec, thread declared inside InnoDB 5000
mysql tables in use 1, locked 1
1 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 1
MySQL thread id 41081, OS thread handle 0x7fcd42332700, query id 2303320 х.х.х.х myDB query end
INSERT INTO `table` (`id`, `data`, `expire`) VALUES ('as6espu1dp8n3ute4mocmbk677', '', '1520949846')
TABLE LOCK table `myDB`.`table` trx id 129314162 lock mode IX
---TRANSACTION 129314161, ACTIVE 59 sec, thread declared inside InnoDB 4999
mysql tables in use 6, locked 4
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
....
TABLE LOCK table `myDB`.`table1` trx id 129314161 lock mode IX
RECORD LOCKS space id 175 page no 18 n bits 88 index PRIMARY of table `myDB`.`table1` trx id 129314161 lock_mode X locks rec but not gap
Record lock, heap no 15 PHYSICAL RECORD: n_fields 40; compact format; info bits 0
0: len 4; hex 800000eb; asc     ;;
1: len 6; hex 000007b52d71; asc     -q;;
2: len 7; hex 63000001391b00; asc c   9  ;;
3: len 4; hex 80000000; asc     ;;
4: len 16; hex 416e6e6120426172646574736b617961; asc Anna Bardetskaya;;
5: SQL NULL;
6: len 3; hex 800000; asc    ;;
7: len 29; hex 616e6e612e626172646574736b61796140732e70616d70696b2e636f6d; asc anna.bardetskaya@s.pampik.com;;
8: len 0; hex ; asc ;;
9: len 0; hex ; asc ;;
10: SQL NULL;
11: len 30; hex 333865343364656131653036613336303437333537373062383561633033; asc 38e43dea1e06a3604735770b85ac03; (total 32 bytes);
12: len 0; hex ; asc ;;
13: len 0; hex ; asc ;;
14: SQL NULL;
15: len 30; hex 2432792431332437527172474e48466739725a4a4348776d415742697575; asc $2y$13$7RqrGNHFg9rZJCHwmAWBiuu; (total 60 bytes);
16: len 1; hex 81; asc  ;;
17: len 1; hex 83; asc  ;;
18: len 5; hex 999d9ca20d; asc      ;;
19: len 5; hex 999d9d10f2; asc      ;;
20: len 1; hex 81; asc  ;;
21: SQL NULL;
22: len 4; hex 8000005a; asc    Z;;
23: len 4; hex 800000eb; asc     ;;
24: len 5; hex 999c2ae9f2; asc   *  ;;
25: len 5; hex 999d9d1106; asc      ;;
26: len 1; hex 80; asc  ;;
27: SQL NULL;
28: SQL NULL;
29: SQL NULL;
30: SQL NULL;
31: SQL NULL;
32: SQL NULL;
33: SQL NULL;
34: SQL NULL;
35: SQL NULL;
36: SQL NULL;
37: len 4; hex 80000000; asc     ;;
38: len 3; hex 303238; asc 028;;
39: len 30; hex 7b226f72646572735c2f64656661756c745c2f7570646174652d63757374; asc {"orders\/default\/update-cust; (total 3118 bytes);

---TRANSACTION 129314160, ACTIVE 60 sec, thread declared inside InnoDB 4999
mysql tables in use 1, locked 1

и так далее


--------
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] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
1163411 OS file reads, 162705 OS file writes, 8487 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 197.29 writes/s, 45.38 fsyncs/s


-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 3354, seg size 3356, 3094 merges
merged operations:
insert 5514, delete mark 1144, delete 412
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 7968313, node heap has 1379 buffer(s)
Hash table size 7968313, node heap has 977 buffer(s)
Hash table size 7968313, node heap has 1428 buffer(s)
Hash table size 7968313, node heap has 643 buffer(s)
Hash table size 7968313, node heap has 1002 buffer(s)
Hash table size 7968313, node heap has 1367 buffer(s)
Hash table size 7968313, node heap has 793 buffer(s)
Hash table size 7968313, node heap has 6036 buffer(s)
0.00 hash searches/s, 0.38 non-hash searches/s
---
LOG
---
Log sequence number 274279615532
Log flushed up to   274279615532
Pages flushed up to 274183642959
Last checkpoint at  274183642959
0 pending log flushes, 0 pending chkp writes
147510 log i/o's done, 1.85 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 33014415360
Dictionary memory allocated 2879346
Buffer pool size   1965968
Free buffers       787360
Database pages     1164983
Old database pages 430306
Modified db pages  25417
Percent of dirty pages(LRU & free pages): 1.302
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 225, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1162944, created 2039, written 15189
0.00 reads/s, 0.00 creates/s, 195.45 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: 1164983, unzip_LRU len: 0
I/O sum[0]:cur[3180], unzip sum[0]:cur[0]

----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size   131072
Free buffers       51288
Database pages     78874
Old database pages 29134
Modified db pages  1482
Percent of dirty pages(LRU & free pages): 1.139
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 11, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 78838, created 36, written 1002
0.00 reads/s, 0.00 creates/s, 13.08 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: 78874, unzip_LRU len: 0
I/O sum[0]:cur[212], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size   131056
Free buffers       51333
Database pages     78809
Old database pages 29102
Modified db pages  1708
Percent of dirty pages(LRU & free pages): 1.312
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 13, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 78672, created 137, written 1019
0.00 reads/s, 0.00 creates/s, 12.92 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: 78809, unzip_LRU len: 0
I/O sum[0]:cur[212], unzip sum[0]:cur[0]
---BUFFER POOL 2

......

Неактивен

 

#2 18.09.2017 13:53:34

paulus
Администратор
MySQL Authorized Developer and DBA
Зарегистрирован: 21.01.2007
Сообщений: 6641

Re: Lock cluster при dedlock

Кажется, вот это Ваша проблема — https://jira.mariadb.org/browse/MDEV-12837

Предлагаю пока сдаунгрейдиться до стабильной версии и подождать, когда проблему решат.

Неактивен

 

#3 19.09.2017 07:20:55

Dimashu
Участник
Зарегистрирован: 04.07.2016
Сообщений: 24

Re: Lock cluster при dedlock

Видел этот баг , думал и надеялся что не ко мне относится...
Спасибо большое.

Неактивен

 

#4 16.10.2017 10:12:38

Stanislav
Участник
Зарегистрирован: 29.08.2017
Сообщений: 11

Re: Lock cluster при dedlock

По своему опыту, могу сказать, что одновременная запись на две ноды в galera - Не работает. Просто выставляйте в haproxy одну ноду активной, а остальные backup.

Неактивен

 

Board footer

Работает на PunBB
© Copyright 2002–2008 Rickard Andersson