| Bug #116504 | Insert into punch hole compression table drop of zero randomly | ||
|---|---|---|---|
| Submitted: | 30 Oct 12:52 | Modified: | 7 Nov 15:14 |
| Reporter: | zkong kong | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S3 (Non-critical) |
| Version: | 8.0 | OS: | Linux |
| Assigned to: | CPU Architecture: | Any | |
[30 Oct 12:52]
zkong kong
[30 Oct 14:53]
MySQL Verification Team
HI Mr. kong, First of all, thank you for the patch that you provided, but we cannot know whether this is a proper patch. Hence, we first have to verify bug #116501 and then ask our Development for the validity of that patch. Only after our Development confirms the patch, can we proceed to test this bug report. Meanwhile, can you run some profiling software that might show up the cause of this drop in the performance. A drop can be due to filesystem marking the patch holes or due to the inadequate CPU for the task ahead. We are waiting on your feedback.
[31 Oct 3:00]
zkong kong
Hi: top - 10:57:32 up 9 days, 20:37, 9 users, load average: 0.56, 3.28, 3.78 Tasks: 1 total, 0 running, 1 sleeping, 0 stopped, 0 zombie %Cpu(s): 0.4 us, 0.6 sy, 0.0 ni, 99.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st KiB Mem : 52723532+total, 43595308+free, 16191848 used, 75090392 buff/cache KiB Swap: 0 total, 0 free, 0 used. 50741033+avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 47112 tdsql 20 0 16.9g 12.9g 44868 S 0.3 2.6 1052:16 mysqld mysql> show processlist; +-----+-----------------+-------------------+----------+---------+-------+----------------------------+------------------------------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +-----+-----------------+-------------------+----------+---------+-------+----------------------------+------------------------------------------------------------------------------------------------------+ | 5 | event_scheduler | localhost | NULL | Daemon | 54770 | Waiting on empty queue | NULL | | 397 | tdsqlsys_agent | localhost | NULL | Query | 0 | init | show processlist | | 526 | test1234 | 9.30.17.135:40124 | sysbench | Query | 181 | waiting for handler commit | INSERT INTO sbtest72 (id, k, c, pad) VALUES (0, 2358, '43954627712-41753091291-62232849451-857949267 | | 527 | test1234 | 9.30.17.135:40128 | sysbench | Query | 181 | waiting for handler commit | INSERT INTO sbtest13 (id, k, c, pad) VALUES (0, 6622, '69443182065-82589449222-04348112936-940531681 | | 528 | test1234 | 9.30.17.135:40136 | sysbench | Query | 181 | waiting for handler commit | INSERT INTO sbtest51 (id, k, c, pad) VALUES (0, 4178, '63676682373-09364614543-84358472056-816641077 | | 529 | test1234 | 9.30.17.135:40134 | sysbench | Query | 181 | waiting for handler commit | INSERT INTO sbtest11 (id, k, c, pad) VALUES (0, 7765, '97673673793-04619867116-67935944631-791213777 | | 530 | test1234 | 9.30.17.135:40126 | sysbench | Query | 181 | waiting for handler commit | INSERT INTO sbtest68 (id, k, c, pad) VALUES (0, 6665, '52916858941-47309246954-34853296044-871112443 | | 531 | test1234 | 9.30.17.135:40132 | sysbench | Query | 181 | waiting for handler commit | INSERT INTO sbtest32 (id, k, c, pad) VALUES (0, 2240, '87502478956-52870056959-16168407819-328762630 | .... 130 rows in set, 1 warning (0.00 sec) [root@TENCENT64 ~]# df -h Filesystem Size Used Avail Use% Mounted on devtmpfs 252G 0 252G 0% /dev tmpfs 252G 20M 252G 1% /dev/shm tmpfs 252G 260M 252G 1% /run tmpfs 252G 0 252G 0% /sys/fs/cgroup /dev/sda1 20G 17G 1.7G 92% / /dev/sda2 511M 7.0M 505M 2% /boot/efi /dev/sda3 20G 2.2G 17G 12% /usr/local /dev/sda4 4.9T 549G 4.1T 12% /data tmpfs 51G 0 51G 0% /run/user/6666 tmpfs 51G 0 51G 0% /run/user/6667 tmpfs 51G 0 51G 0% /run/user/0 /dev/md0p1 50G 28G 23G 55% /data1 /dev/md0p2 50G 33M 50G 1% /data2 /dev/md0p3 100G 100G 24K 100% /data3 /dev/md0p4 6.4T 7.1G 6.4T 1% /data4 [root@TENCENT64 ~]# du -s -h /data1 28G /data1
[31 Oct 3:36]
zkong kong
The perf data
Samples: 693K of event 'cpu-clock', Event count (approx.): 173415500000
Overhead Command Shared Object Symbol ◆
+ 4.43% connection [kernel.vmlinux] [k] _raw_spin_lock ▒
+ 2.65% connection [kernel.vmlinux] [k] _raw_spin_unlock_irqrestore ▒
- 2.56% connection [xfs] [k] xfs_alloc_get_rec ▒
- xfs_alloc_get_rec ▒
- 2.35% xfs_alloc_ag_vextent_size ▒
xfs_alloc_ag_vextent ▒
xfs_alloc_vextent ▒
xfs_bmap_btalloc ▒
xfs_bmap_alloc ▒
xfs_bmapi_write ▒
xfs_alloc_file_space ▒
xfs_file_fallocate ▒
vfs_fallocate ▒
sys_fallocate ▒
do_syscall_64 ▒
entry_SYSCALL_64 ▒
posix_fallocate64 ▒
fsp_try_extend_data_file ▒
fsp_reserve_free_extents ▒
+ btr_cur_pessimistic_insert
[31 Oct 3:43]
zkong kong
Hi:
It's only occur when the xfs fragment is very high
[root@TENCENT64 /data3/log/4306/dblogs/bin]# xfs_db -r -c "freesp" /dev/md0p1
Metadata CRC error detected at xfs_allocbt block 0x1efe698/0x1000
Metadata CRC error detected at xfs_allocbt block 0x44bd440/0x1000
Metadata CRC error detected at xfs_allocbt block 0x4b34d58/0x1000
from to extents blocks pct
1 1 951858 951858 99.96
2 3 177 413 0.04
[31 Oct 11:10]
MySQL Verification Team
Hi Mr. kong, Waiting on the Linux box to be prepared for this bug ......
[7 Nov 15:14]
MySQL Verification Team
Hi Mr. kong, This bug is now verified, since but 116501 turned out to be true. This is now a verified bug for versions 8.0, 8.4, 9.0 and 9.1. Thank you.
