MySQL Bugs: #100760: MySQL 8.0.21 empty running instance, but the CPU load is abnormally high

Bug #100760	MySQL 8.0.21 empty running instance, but the CPU load is abnormally high
Submitted:	7 Sep 2020 13:05	Modified:	8 Sep 2020 8:53
Reporter:	Ye Jinrong	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server	Severity:	S2 (Serious)
Version:	8.0.21	OS:	CentOS (CentOS Linux release 7.8.2003 (Core))
Assigned to:	MySQL Verification Team	CPU Architecture:	x86 (Intel(R) Xeon(R) Platinum 8255C CPU @ 2.50GHz)

Description:
1. host summary
tencent cloud cvm host
CPU: Intel(R) Xeon(R) Platinum 8255C CPU @ 2.50GHz * 4
Mem: 16G
Disk: 500G SSD mount with xfs
```
/dev/vdb       xfs       500G  144G  357G  29% /data

```

2. mysqld process cpu load is very very high
```
top - 20:53:37 up 114 days, 23:23,  1 user,  load average: 2.22, 2.17, 2.22
Tasks: 123 total,   1 running, 118 sleeping,   4 stopped,   0 zombie
%Cpu0  : 24.5 us, 29.1 sy,  0.0 ni, 46.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  : 23.6 us, 31.0 sy,  0.0 ni, 45.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu2  : 24.0 us, 25.8 sy,  0.0 ni, 50.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu3  : 22.3 us, 28.4 sy,  0.0 ni, 49.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 16266224 total,   502588 free,  2389812 used, 13373824 buff/cache
KiB Swap: 33554428 total, 33546492 free,     7936 used. 13537580 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
31458 mysql     20   0   10.7g   1.3g  17932 S 267.8  8.4  31780:33 mysqld
```

we can see mysqld process's cpu high upto 267.8%

3. the mysqld instant is an empty running instance

```
[root@yejr-mgr1 ~]# mysqladmin pr
+----+------+-----------+----+---------+------+----------+------------------+
| Id | User | Host      | db | Command | Time | State    | Info             |
+----+------+-----------+----+---------+------+----------+------------------+
| 51 | root | localhost |    | Query   | 0    | starting | show processlist |
+----+------+-----------+----+---------+------+----------+------------------+
```

4. take a look in innodb status
in attachment file.

5. take a look in perf top
```
Samples: 1M of event 'cpu-clock', 4000 Hz, Event count (approx.): 36249292209 lost: 0/0 drop: 0/0
Overhead  Shared Object                            Symbol
  17.09%  [kernel]                                 [k] _raw_spin_unlock_irqrestore
  14.77%  libc-2.17.so;5f4f0425 (deleted)          [.] 0x00000000000f8ba9
   8.16%  [kernel]                                 [k] system_call_after_swapgs
   6.73%  [kernel]                                 [k] finish_task_switch
   3.97%  mysqld                                   [.] buf_flush_do_batch
   3.82%  mysqld                                   [.] pc_flush_slot
   2.85%  mysqld                                   [.] ut_delay
   2.07%  [kernel]                                 [k] pvclock_clocksource_read
   2.02%  mysqld                                   [.] dblwr::force_flush
   1.81%  [kernel]                                 [k] tick_nohz_idle_enter
   1.62%  libpthread-2.17.so;5f4f0425 (deleted)    [.] 0x000000000000e5aa
   1.62%  [kernel]                                 [k] tick_nohz_idle_exit
   1.49%  libpthread-2.17.so;5f4f0425 (deleted)    [.] 0x0000000000009d22
   1.49%  [kernel]                                 [k] sys_clock_gettime
   1.44%  libpthread-2.17.so;5f4f0425 (deleted)    [.] 0x000000000000b9f5
   1.43%  [kernel]                                 [k] copy_user_enhanced_fast_string
   1.25%  [kernel]                                 [k] __audit_syscall_exit
```

6. get the pstack result
```
[root@yejr-mgr1 data01]# pstack 31458 > /tmp/pstack-31458.log

[root@yejr-mgr1 data01]# cat /tmp/pstack-31458.log
Thread 1 (process 31458):
#0  0x00007f739cca3bed in fts_children () from /lib64/libc.so.6
#1  0x0000000000000000 in ?? ()

```

How to repeat:
as above

Suggested fix:
i have no idea, sorry

show engine innodb status output

Attachment: innodb-status-31458.log (application/octet-stream, text), 9.11 KiB.

find which threads cause the cpu so hight
```
[root@yejr-mgr1 data01]# pidstat -t -p 31458
...
09:49:05 PM  1000         -     31481    3.53    3.47    0.00    7.00     1  |__mysqld
09:49:05 PM  1000         -     31482    1.79    2.30    0.00    4.09     2  |__mysqld
09:49:05 PM  1000         -     31483    1.79    2.29    0.00    4.08     3  |__mysqld
09:49:05 PM  1000         -     31484    1.79    2.29    0.00    4.09     2  |__mysqld
...
```

and find which mysql internal threads
```
root@yejr.run [performance_schema]>select thread_id, name ,type from threads where THREAD_OS_ID in (31481, 31482, 31483, 31484);
+-----------+---------------------------------------------+------------+
| thread_id | name                                        | type       |
+-----------+---------------------------------------------+------------+
|        13 | thread/innodb/page_flush_coordinator_thread | BACKGROUND |
|        14 | thread/innodb/page_flush_thread             | BACKGROUND |
|        15 | thread/innodb/page_flush_thread             | BACKGROUND |
|        16 | thread/innodb/page_flush_thread             | BACKGROUND |
+-----------+---------------------------------------------+------------+
```

but it is an empty running instance, and there are no write or update, and no dirty pages to be flushed
```
...
Buffer pool size   524288
Free buffers       506946
Database pages     17336
Old database pages 6253
Modified db pages  0
Pending reads      0
...
```

and some variables about page cleaner
```
| innodb_page_cleaners               | 4     |
| innodb_adaptive_flushing           | ON    |
| innodb_adaptive_flushing_lwm       | 10    |
| innodb_flush_log_at_timeout        | 1     |
| innodb_flush_log_at_trx_commit     | 1     |
| innodb_flush_method                | fsync |
| innodb_flush_neighbors             | 0     |
| innodb_flush_sync                  | ON    |
| innodb_flushing_avg_loops          | 30    |
```

I am very sorry, this may be caused by an abnormality in the host of the cloud server, now it back to normal, do i need to close this bug?

Hi,

I'm still analyzing it. Will let you know later today.

all best
Bogdan

Hi,

Closed as not a bug as this does look like vm abnormality. Let us know if this can be observed again, especially if you can look at the host stats too.

thanks
Bogdan