0

I have recently provisioned two new servers:

  • Server 1: AMD EPYC 7320P, 128GB DDR4, 7.68TB Micron 5300 SSD
  • Server 2: Intel E2388G, 128GB DDR4, 2x 6TB SATA HDD in software RAID1

Both are running CentOS 7. Both are using MySQL 8.0.28-19 from Percona.

The customer here has an application with one extremely large database table (about 850GB), and it's quite poorly optimised for their use case. They sometimes run queries like "SELECT * FROM hugetable WHERE field LIKE '%value%'". Of course, the wildcard at the start of the string means that indexes are useless on that field.

We expect Server 1 to outperform (or at least match) Server 2 for our use case, due to the SSD.

On Server 1, we find the inefficient query takes 1.83 seconds:

mysql> select count(*) from hugetable where field like '%value%';
+----------+
| count(*) |
+----------+
|    31178 |
+----------+
1 row in set (1.83 sec)

On Server 2 it takes 0.5 seconds:

mysql> select count(*) from hugetable where field like '%value%';
+----------+
| count(*) |
+----------+
|    31178 |
+----------+
1 row in set (0.50 sec)

We also find that other queries, even on indexed fields, seem to be faster on Server 2 usually by 2x.

I cannot explain this difference, and it's bugging me!


The relevant MySQL config on both boxes is as follows:

# CACHES AND LIMITS #
tmp-table-size                 = 32M
max-heap-table-size            = 32M
max-connections                = 500
thread-cache-size              = 50
open-files-limit               = 65535
table-definition-cache         = 4096
table-open-cache               = 1000
sort-buffer-size               = 32M
read_rnd_buffer_size           = 32M

# INNODB #
innodb-flush-method            = O_DIRECT
innodb-log-files-in-group      = 2
innodb-log-file-size           = 128M
innodb-flush-log-at-trx-commit = 2
innodb-file-per-table          = 1
innodb-buffer-pool-size        = 64G

Using fio on Server 1 and looking at read performance we see:

## Sequential reads

[root@ers3 data]# fio --name TEST --eta-newline=5s --filename=fio-tempfile.dat --rw=read --size=500m --io_size=10g --blocksize=1024k --ioengine=libaio --fsync=10000 --iodepth=32 --direct=1 --numjobs=1 --runtime=60 --group_reporting
TEST: (g=0): rw=read, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=32
fio-3.7
Starting 1 process
TEST: Laying out IO file (1 file / 500MiB)
Jobs: 1 (f=1): [R(1)][36.4%][r=483MiB/s,w=0KiB/s][r=483,w=0 IOPS][eta 00m:14s]
Jobs: 1 (f=1): [R(1)][63.6%][r=484MiB/s,w=0KiB/s][r=484,w=0 IOPS][eta 00m:08s] 
Jobs: 1 (f=1): [R(1)][90.9%][r=485MiB/s,w=0KiB/s][r=485,w=0 IOPS][eta 00m:02s] 
Jobs: 1 (f=1): [R(1)][100.0%][r=484MiB/s,w=0KiB/s][r=484,w=0 IOPS][eta 00m:00s]
TEST: (groupid=0, jobs=1): err= 0: pid=4211: Wed Jun 15 10:39:47 2022
   read: IOPS=484, BW=484MiB/s (508MB/s)(10.0GiB/21146msec)
    slat (usec): min=10, max=555, avg=31.85, stdev=18.02
    clat (msec): min=2, max=156, avg=65.85, stdev=15.08
     lat (msec): min=2, max=156, avg=65.88, stdev=15.08
    clat percentiles (msec):
     |  1.00th=[   11],  5.00th=[   37], 10.00th=[   61], 20.00th=[   65],
     | 30.00th=[   66], 40.00th=[   66], 50.00th=[   67], 60.00th=[   67],
     | 70.00th=[   68], 80.00th=[   69], 90.00th=[   72], 95.00th=[   88],
     | 99.00th=[  120], 99.50th=[  125], 99.90th=[  144], 99.95th=[  153],
     | 99.99th=[  155]
   bw (  KiB/s): min=452608, max=540672, per=99.99%, avg=495811.05, stdev=12525.55, samples=42
   iops        : min=  442, max=  528, avg=484.19, stdev=12.23, samples=42
  lat (msec)   : 4=0.07%, 10=0.81%, 20=1.51%, 50=5.04%, 100=89.40%
  lat (msec)   : 250=3.16%
  cpu          : usr=0.45%, sys=2.00%, ctx=10443, majf=0, minf=539
  IO depths    : 1=0.2%, 2=0.4%, 4=0.8%, 8=1.6%, 16=3.3%, 32=93.6%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=99.8%, 8=0.0%, 16=0.0%, 32=0.2%, 64=0.0%, >=64=0.0%
     issued rwts: total=10240,0,0,0 short=0,0,0,0 dropped=0,0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
   READ: bw=484MiB/s (508MB/s), 484MiB/s-484MiB/s (508MB/s-508MB/s), io=10.0GiB (10.7GB), run=21146-21146msec

Disk stats (read/write):
  sdb: ios=10208/1271, merge=0/811, ticks=652563/43164, in_queue=695728, util=99.58%



## Random reads

[root@ers3 data]# fio --name TEST --eta-newline=5s --filename=fio-tempfile.dat --rw=randread --size=500m --io_size=10g --blocksize=4k --ioengine=libaio --fsync=1 --iodepth=1 --direct=1 --numjobs=1 --runtime=60 --group_reporting
TEST: (g=0): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.7
Starting 1 process
Jobs: 1 (f=1): [r(1)][11.7%][r=25.6MiB/s,w=0KiB/s][r=6560,w=0 IOPS][eta 00m:53s]
Jobs: 1 (f=1): [r(1)][21.7%][r=24.9MiB/s,w=0KiB/s][r=6381,w=0 IOPS][eta 00m:47s] 
Jobs: 1 (f=1): [r(1)][31.7%][r=26.9MiB/s,w=0KiB/s][r=6889,w=0 IOPS][eta 00m:41s] 
Jobs: 1 (f=1): [r(1)][41.7%][r=26.1MiB/s,w=0KiB/s][r=6674,w=0 IOPS][eta 00m:35s] 
Jobs: 1 (f=1): [r(1)][51.7%][r=26.3MiB/s,w=0KiB/s][r=6731,w=0 IOPS][eta 00m:29s] 
Jobs: 1 (f=1): [r(1)][61.7%][r=26.8MiB/s,w=0KiB/s][r=6869,w=0 IOPS][eta 00m:23s] 
Jobs: 1 (f=1): [r(1)][71.7%][r=25.4MiB/s,w=0KiB/s][r=6506,w=0 IOPS][eta 00m:17s] 
Jobs: 1 (f=1): [r(1)][81.7%][r=25.7MiB/s,w=0KiB/s][r=6581,w=0 IOPS][eta 00m:11s] 
Jobs: 1 (f=1): [r(1)][91.7%][r=25.8MiB/s,w=0KiB/s][r=6604,w=0 IOPS][eta 00m:05s] 
Jobs: 1 (f=1): [r(1)][100.0%][r=25.6MiB/s,w=0KiB/s][r=6565,w=0 IOPS][eta 00m:00s]
TEST: (groupid=0, jobs=1): err= 0: pid=4294: Wed Jun 15 10:42:08 2022
   read: IOPS=6628, BW=25.9MiB/s (27.1MB/s)(1554MiB/60001msec)
    slat (nsec): min=3887, max=56424, avg=5981.42, stdev=2034.34
    clat (usec): min=53, max=1775, avg=143.80, stdev=20.20
     lat (usec): min=68, max=1780, avg=149.94, stdev=20.51
    clat percentiles (usec):
     |  1.00th=[   75],  5.00th=[  119], 10.00th=[  122], 20.00th=[  125],
     | 30.00th=[  133], 40.00th=[  141], 50.00th=[  147], 60.00th=[  153],
     | 70.00th=[  157], 80.00th=[  161], 90.00th=[  165], 95.00th=[  169],
     | 99.00th=[  176], 99.50th=[  188], 99.90th=[  293], 99.95th=[  334],
     | 99.99th=[  400]
   bw (  KiB/s): min=25424, max=28632, per=100.00%, avg=26516.17, stdev=676.62, samples=119
   iops        : min= 6356, max= 7158, avg=6629.04, stdev=169.16, samples=119
  lat (usec)   : 100=1.24%, 250=98.59%, 500=0.17%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.01%
  cpu          : usr=1.62%, sys=6.03%, ctx=398427, majf=0, minf=12
  IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwts: total=397719,0,0,0 short=0,0,0,0 dropped=0,0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=1

Run status group 0 (all jobs):
   READ: bw=25.9MiB/s (27.1MB/s), 25.9MiB/s-25.9MiB/s (27.1MB/s-27.1MB/s), io=1554MiB (1629MB), run=60001-60001msec

Disk stats (read/write):
  sdb: ios=397028/58, merge=0/13, ticks=57429/6, in_queue=57436, util=99.87%

MySQL's query profiling on Server 1 shows the whole time is spent in executing:

mysql> SHOW PROFILE FOR QUERY 10;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000098 |
| Executing hook on transaction  | 0.000003 |
| starting                       | 0.000011 |
| checking permissions           | 0.000008 |
| Opening tables                 | 0.000099 |
| init                           | 0.000008 |
| System lock                    | 0.000030 |
| optimizing                     | 0.000015 |
| statistics                     | 0.000253 |
| preparing                      | 0.000069 |
| executing                      | 1.833219 |
| end                            | 0.000012 |
| query end                      | 0.000005 |
| waiting for handler commit     | 0.000013 |
| closing tables                 | 0.000019 |
| freeing items                  | 0.000035 |
| cleaning up                    | 0.000015 |
+--------------------------------+----------+

Looking at the InnoDB status immediately after the query has run on Server 1 shows the following:

mysql> SHOW ENGINE INNODB STATUS\G
*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
2022-06-15 11:01:31 140417905456896 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 31 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 42329 srv_active, 0 srv_shutdown, 117149 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 97137
OS WAIT ARRAY INFO: signal count 102342
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 3111454050
Purge done for trx's n:o < 3111454050 undo n:o < 0 state: running but idle
History list length 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421892595862056, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421892595867992, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421892595866296, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421892595861208, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------
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: 7198
113960412 OS file reads, 281858511 OS file writes, 48192480 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 3.73 writes/s, 0.94 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 9423 merges
merged operations:
 insert 10116, delete mark 165, delete 46
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 17700857, node heap has 4 buffer(s)
Hash table size 17700857, node heap has 5 buffer(s)
Hash table size 17700857, node heap has 4 buffer(s)
Hash table size 17700857, node heap has 327 buffer(s)
Hash table size 17700857, node heap has 49 buffer(s)
Hash table size 17700857, node heap has 2 buffer(s)
Hash table size 17700857, node heap has 4 buffer(s)
Hash table size 17700857, node heap has 2 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number          4086847075871
Log buffer assigned up to    4086847075871
Log buffer completed up to   4086847075871
Log written up to            4086847075871
Log flushed up to            4086847075871
Added dirty pages up to      4086847075871
Pages flushed up to          4086847075871
Last checkpoint at           4086847075871
Checkpoint age target        231601152
Modified age no less than    4086847075871
Checkpoint age               0
Max checkpoint age           225271296
Number of logs               2
Log size                     134217728
Log total size               268435456
128548218 log i/o's done, 0.06 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 0
Dictionary memory allocated 40548382
Buffer pool size   4193792
Buffer pool size, bytes 68711088128
Free buffers       8192
Database pages     6972427
Old database pages 2573642
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1412476, not young 145332772
0.00 youngs/s, 0.00 non-youngs/s
Pages read 113960309, created 115237184, written 121222520
0.00 reads/s, 0.00 creates/s, 2.82 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: 6972427, unzip_LRU len: 697268
I/O sum[4824]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871453
Old database pages 321668
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 167665, not young 17893680
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14244911, created 14403994, written 15083407
0.00 reads/s, 0.00 creates/s, 0.41 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: 871453, unzip_LRU len: 87146
I/O sum[603]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871685
Old database pages 321754
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 178928, not young 17739401
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14243204, created 14404097, written 15115375
0.00 reads/s, 0.00 creates/s, 0.00 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: 871685, unzip_LRU len: 87170
I/O sum[603]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871472
Old database pages 321675
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 179001, not young 17817892
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14244707, created 14404740, written 15260065
0.00 reads/s, 0.00 creates/s, 0.03 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: 871472, unzip_LRU len: 87151
I/O sum[603]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871481
Old database pages 321679
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 170115, not young 17721837
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14241364, created 14404230, written 15089483
0.00 reads/s, 0.00 creates/s, 0.09 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: 871481, unzip_LRU len: 87150
I/O sum[603]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871613
Old database pages 321727
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 193949, not young 21358292
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14260791, created 14404745, written 15055611
0.00 reads/s, 0.00 creates/s, 0.00 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: 871613, unzip_LRU len: 87162
I/O sum[603]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871555
Old database pages 321706
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 171721, not young 17705587
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14242265, created 14405077, written 15099333
0.00 reads/s, 0.00 creates/s, 0.41 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: 871555, unzip_LRU len: 87163
I/O sum[603]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871570
Old database pages 321711
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 175767, not young 17391792
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14240311, created 14406448, written 15344250
0.00 reads/s, 0.00 creates/s, 1.13 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: 871570, unzip_LRU len: 87162
I/O sum[603]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size   524224
Buffer pool size, bytes 8588886016
Free buffers       1024
Database pages     871598
Old database pages 321722
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 175330, not young 17704291
0.00 youngs/s, 0.00 non-youngs/s
Pages read 14242756, created 14403853, written 15174996
0.00 reads/s, 0.00 creates/s, 0.75 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: 871598, unzip_LRU len: 87164
I/O sum[603]: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
Process ID=2015, Main thread ID=140393649698560 , state=sleeping
Number of rows inserted 1196755, updated 818998, deleted 11, read 6507776
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 24662.75 reads/s
Number of system rows inserted 13555, updated 888214, deleted 1511, read 914289
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

Can anyone suggest why Server 1 appears to be slower than Server 2, and whether there's anything more I can do to investigate?

8
  • Percona 8.0.28 (2022-05-12) is like the new baby. Maybe you have found a reportable problem - no one else discovered. Many people will not install versions less than 90 days on the street to conserve their time, rather than provide bug report and hope for corrective action in a few days. For future reference, wait 90 days before jumping in to recent release. Jun 15 at 20:16
  • From Server 1 and Server 2 - Additional information request, please. Post on pastebin.com and share the links. From your SSH login root, Text results of: A) SELECT COUNT(*) FROM information_schema.tables; B) SHOW GLOBAL STATUS; after minimum 24 hours UPTIME C) SHOW GLOBAL VARIABLES; D) SHOW FULL PROCESSLIST; AND very helpful OS information, includes - htop OR top for most active apps, ulimit -a for list of limits, iostat -xm 5 3 for IOPS by device & core/cpu count, for server workload tuning analysis to find server differences. Jun 15 at 20:19
  • From Server 1 and Server 2 - A) SHOW CREATE TABLE hugetable; and B) SHOW TABLE STATUS WHERE name LIKE 'hugetable'; please to check a few details. Jun 15 at 20:22
  • Thanks @WilsonHauck! Server 1 - pastebin.com/t8W1KGxL . Server 2 - pastebin.com/JeY1qiAc Both servers are fairly idle (just replicating from a production database, and no queries are hitting them). Note that when I ran my original tests they were completely idle - not even replication running. Jun 16 at 9:32
  • Pastebin postings are no longer available. View profile for contact info and get in touch, please. Jun 16 at 17:45

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.