Я сталкиваюсь с тем, что, я уверен, является конфликтом ресурсов низкого уровня (ОС?) В MariaDB.
Я использую MariaDB 10.0.29 на машине с двумя ядрами и 8 ГБ ОЗУ.
Ситуация следующая - у меня есть приложение, написанное на Java, которое использует JDBC для доступа к базе данных MariaDB. Приложение запускает два отдельных потока, каждый со своим собственным подключением к другой схеме (назовите их Schema_1 и Schema_2). Я убедился, что каждый поток действительно имеет доступ только к своему собственному соединению и своей собственной схеме. Я также дважды проверил, нет ли внешних ключей кросс-схемы. Насколько я могу судить, между двумя потоками не должно быть конкуренции за ресурсы на уровне БД.
При запуске одного такого потока я вижу, что мой процесс Java использует ~ 65% ЦП, а поток MariaDB использует ~ 35% ЦП. Однако при запуске обоих потоков каждый поток MariaDB использует только 25% ЦП, а потоки Java используют ~ 55% ЦП, что для меня означает, что некоторые ресурсы блокируются каждым из потоков MariaDB по очереди, поэтому только один может запускаться вовремя.
Запуск того же самого кода на другом компьютере с MariaDB 5.5.50 подтверждает, что что-то не так, поскольку он почти идеально масштабируется до 2 потоков, постоянно используя ~ 100% ЦП.
Пытаясь разобраться в этом, я побежал show status like '%wait%' что дает:
show status like '%wait%';
+---------------------------------------+----------+
| Variable_name | Value |
+---------------------------------------+----------+
| Binlog_group_commit_trigger_lock_wait | 0 |
| Innodb_buffer_pool_wait_free | 0 |
| Innodb_log_waits | 0 |
| Innodb_mutex_os_waits | 38108364 |
| Innodb_mutex_spin_waits | 46717276 |
| Innodb_row_lock_current_waits | 0 |
| Innodb_row_lock_waits | 0 |
| Innodb_s_lock_os_waits | 1527996 |
| Innodb_s_lock_spin_waits | 2079031 |
| Innodb_x_lock_os_waits | 710738 |
| Innodb_x_lock_spin_waits | 1211905 |
| Table_locks_waited | 0 |
| Tc_log_page_waits | 0 |
+---------------------------------------+----------+
13 rows in set (0.00 sec)
что, если я правильно понимаю, означает, что не было ожидания блокировки таблицы или строки, но было очень много ожиданий os. Но какие они? Как я могу узнать, какой ресурс заблокирован и кем?
Буферный пул InnoDB установлен на 6 ГБ, параллелизм потоков установлен на 10 (установка на 0, похоже, не имеет заметного эффекта), и просто для 100% уверенности, что это не связано с вводом-выводом, файлы журнала сохраняются на RAM-диск.
Что еще я могу сделать, чтобы найти источник блокировки? Это разумное число для блокировок ОС? Почему в этом отношении MariaDB 5.5 работает намного лучше, чем 10.0.29?
Ниже приводится результат работы show engine innodb status. Если есть другие полезные диагностические результаты, дайте мне знать, и я их опубликую:
| InnoDB | |
=====================================
2017-03-27 13:11:44 7f8c55020700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 39 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 98077 srv_active, 0 srv_shutdown, 682949 srv_idle
srv_master_thread log flush and writes: 780936
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 40364775
OS WAIT ARRAY INFO: signal count 42775103
Mutex spin waits 46717276, rounds 1174586500, OS waits 38108364
RW-shared spins 2079031, rounds 47480157, OS waits 1527996
RW-excl spins 1211905, rounds 25553878, OS waits 710738
Spin rounds per wait: 25.14 mutex, 22.84 RW-shared, 21.09 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 886179328
Purge done for trx's n:o < 886179327 undo n:o < 0 state: running but idle
History list length 3404
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 93, OS thread handle 0x7f8c55020700, query id 366742871 localhost root 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 (read thread)
I/O thread 7 state: waiting for completed aio requests (read 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)
I/O thread 10 state: waiting for completed aio requests (write thread)
I/O thread 11 state: waiting for completed aio requests (write thread)
I/O thread 12 state: waiting for completed aio requests (write thread)
I/O thread 13 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0, 0, 0] , aio writes: 0 [0, 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
5124 OS file reads, 187867510 OS file writes, 480141 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 18411, seg size 18413, 874 merges
merged operations:
insert 0, delete mark 789821, delete 754
discarded operations:
insert 0, delete mark 0, delete 0
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 104106175746
Log flushed up to 104106175746
Pages flushed up to 104106175746
Last checkpoint at 104106175746
Max checkpoint age 169158206
Checkpoint age target 163872013
Modified age 0
Checkpoint age 0
0 pending log writes, 0 pending chkp writes
181317888 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 6706692096; in additional pool allocated 0
Total memory allocated by read views 216
Internal hash tables (constant factor + variable factor)
Adaptive hash index 137096336 (101997608 + 35098728)
Page hash 797656 (buffer pool 0 only)
Dictionary cache 25944722 (25501136 + 443586)
File system 965152 (812272 + 152880)
Lock system 15938512 (15938152 + 360)
Recovery system 0 (0 + 0)
Dictionary memory allocated 443586
Buffer pool size 393208
Buffer pool size, bytes 6442319872
Free buffers 325107
Database pages 65959
Old database pages 24185
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 11425, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 5078, created 60881, written 6549515
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: 65959, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40785
Database pages 8117
Old database pages 2976
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1271, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 970, created 7147, written 917449
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: 8117, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40909
Database pages 7972
Old database pages 2922
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2025, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 632, created 7340, written 533992
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: 7972, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40569
Database pages 8318
Old database pages 3050
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1066, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 604, created 7714, written 464495
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: 8318, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40359
Database pages 8508
Old database pages 3120
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1417, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 643, created 7865, written 1655991
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: 8508, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40784
Database pages 8084
Old database pages 2964
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1243, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 660, created 7424, written 1061540
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: 8084, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40612
Database pages 8268
Old database pages 3032
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1579, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 646, created 7622, written 776527
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: 8268, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40457
Database pages 8429
Old database pages 3091
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1554, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 291, created 8138, written 585268
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: 8429, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size 49151
Buffer pool size, bytes 805289984
Free buffers 40632
Database pages 8263
Old database pages 3030
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1270, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 632, created 7631, written 554253
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: 8263, 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. 12006, id 140233249109760, state: sleeping
Number of rows inserted 25540074, updated 163314856, deleted 23278039, read 11939702187
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
Выход show status like '%tmp%':
+-------------------------+-------+
| Variable_name | Value |
+-------------------------+-------+
| Created_tmp_disk_tables | 0 |
| Created_tmp_files | 6 |
| Created_tmp_tables | 0 |
| Handler_tmp_update | 0 |
| Handler_tmp_write | 0 |
| Rows_tmp_read | 0 |
+-------------------------+-------+