我遇到了我非常确定是 MariaDB 中的低级(OS?)资源争用问题。
我在一台具有两个核心和 8GB RAM 的机器上使用 MariaDB 10.0.29。
情况如下 - 我有一个用 Java 编写的应用程序,它使用 JDBC 访问 MariaDB 数据库。该应用程序启动两个单独的线程,每个线程都有自己的与不同模式的连接(称为Schema_1
和Schema_2
)。我已经验证了每个线程确实只访问自己的连接和自己的模式。我还仔细检查了没有跨模式的外键。据我所知,两个线程之间不应该存在数据库级资源争用。
当运行一个这样的线程时,我发现 Java 进程占用了约 65% 的 CPU,而 MariaDB 线程占用了约 35% 的 CPU。但是,当同时运行两个线程时,每个 MariaDB 线程仅占用了 25% 的 CPU,而 Java 线程占用了约 55% 的 CPU,对我来说,这意味着每个 MariaDB 线程依次锁定了一些资源,因此一次只能运行一个线程。
在另一台装有 MariaDB 5.5.50 的机器上运行完全相同的代码,确认可能存在问题,因为它几乎完美地扩展到 2 个线程,并且始终使用 ~100% 的 CPU。
为了弄清这个问题的根源,我进行了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)
如果我理解正确的话,这意味着没有表或行锁等待,但有大量的操作系统等待。但它们是什么?我如何知道哪个资源被锁定,以及被谁锁定?
InnoDB 缓冲池设置为 6GB,线程并发设置为 10(设置为 0 似乎没有任何明显的影响),并且为了 100% 确定这与 I/O 无关,日志文件保存到 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 |
+-------------------------+-------+