诊断数据库资源争用

诊断数据库资源争用

我遇到了我非常确定是 MariaDB 中的低级(OS?)资源争用问题。

我在一台具有两个核心和 8GB RAM 的机器上使用 MariaDB 10.0.29。

情况如下 - 我有一个用 Java 编写的应用程序,它使用 JDBC 访问 MariaDB 数据库。该应用程序启动两个单独的线程,每个线程都有自己的与不同模式的连接(称为Schema_1Schema_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     |
+-------------------------+-------+

相关内容