Description:
information_schema.innodb_buffer_pages doesn't show correct information after loading ib_buffer_pool.
See "How to repeat"
How to repeat:
# Setting up 5.7-latest
$ sudo yum install -y https://dev.mysql.com/get/mysql80-community-release-el7-3.noarch.rpm
$ sudo yum install -y --disablerepo=mysql80-community --enablerepo=mysql57-community mysql-community-server
$ sudo mysqld --initialize-insecure --user=mysql
$ sudo systemctl start mysqld
# Fill test-data
mysql> CREATE DATABASE d1;
Query OK, 1 row affected (0.00 sec)
mysql> CREATE TABLE d1.t1 (uuid varchar(36) NOT NULL PRIMARY KEY);
Query OK, 0 rows affected (0.01 sec)
mysql> INSERT INTO d1.t1 SELECT uuid();
Query OK, 1 row affected (0.01 sec)
Records: 1 Duplicates: 0 Warnings: 0
mysql> INSERT INTO d1.t1 SELECT uuid() FROM d1.t1;
Query OK, 1 row affected (0.00 sec)
Records: 1 Duplicates: 0 Warnings: 0
mysql> INSERT INTO d1.t1 SELECT uuid() FROM d1.t1;
Query OK, 2 rows affected (0.00 sec)
Records: 2 Duplicates: 0 Warnings: 0
mysql> INSERT INTO d1.t1 SELECT uuid() FROM d1.t1;
Query OK, 4 rows affected (0.00 sec)
Records: 4 Duplicates: 0 Warnings: 0
...
mysql> INSERT INTO d1.t1 SELECT uuid() FROM d1.t1;
Query OK, 2097152 rows affected (16.21 sec)
Records: 2097152 Duplicates: 0 Warnings: 0
mysql> SELECT COUNT(*) FROM d1.t1;
+----------+
| COUNT(*) |
+----------+
| 4194304 |
+----------+
1 row in set (1.25 sec)
mysql> SELECT table_name, index_name, COUNT(*) AS pages, SUM(number_records) AS records, SUM(data_size) AS data FROM information_schema.innodb_buffer_page GROUP BY table_name, index_name;
+------------------------------+------------+-------+---------+----------+
| table_name | index_name | pages | records | data |
+------------------------------+------------+-------+---------+----------+
| NULL | NULL | 1985 | 0 | 0 |
| `d1`.`t1` | PRIMARY | 6202 | 1699186 | 93423838 |
| `mysql`.`innodb_index_stats` | PRIMARY | 1 | 10 | 913 |
| `mysql`.`innodb_table_stats` | PRIMARY | 1 | 3 | 179 |
| `SYS_TABLES` | CLUST_IND | 2 | 20 | 334 |
+------------------------------+------------+-------+---------+----------+
5 rows in set (0.04 sec)
# Dump ib_buffer_pool
mysql> SET GLOBAL innodb_buffer_pool_dump_pct= 100;
Query OK, 0 rows affected (0.02 sec)
mysql> SET GLOBAL innodb_buffer_pool_dump_now= 1;
Query OK, 0 rows affected (0.00 sec)
$ sudo less /var/log/mysqld.log
..
2019-09-18T10:39:11.758874Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2019-09-18T10:39:11.769541Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 190918 10:39:11
$ sudo ls -l /var/lib/mysql/ib_buffer_pool
-rw-r-----. 1 mysql mysql 59176 Sep 18 10:39 /var/lib/mysql/ib_buffer_pool
# Restart mysqld and start to load ib_buffer_pool
$ sudo systemctl restart mysqld
$ sudo ls -l /var/lib/mysql/ib_buffer_pool
-rw-r-----. 1 mysql mysql 59176 Sep 18 10:40 /var/lib/mysql/ib_buffer_pool
$ sudo less /var/log/mysqld.log
..
2019-09-18T10:40:20.633619Z 0 [Note] InnoDB: Buffer pool(s) load completed at 190918 10:40:20
..
# Checking after restart mysqld.
1. `innodb_buffer_pool_load_at_startup = ON` by default.
mysql> SELECT @@innodb_buffer_pool_load_at_startup;
+--------------------------------------+
| @@innodb_buffer_pool_load_at_startup |
+--------------------------------------+
| 1 |
+--------------------------------------+
1 row in set (0.00 sec)
2. But `information_schema.innodb_buffer_pool` shows me d1.t1 is not filled in Buffer Pool.
mysql> SELECT table_name, index_name, COUNT(*) AS pages, SUM(number_records) AS records, SUM(data_size) AS data FROM information_schema.innodb_buffer_page GROUP BY table_name, index_name;
+-------------------------------------+-----------------------+-------+---------+----------+
| table_name | index_name | pages | records | data |
+-------------------------------------+-----------------------+-------+---------+----------+
| NULL | NULL | 8173 | 1395594 | 76726278 |
| `mysql`.`engine_cost` | PRIMARY | 1 | 2 | 112 |
| `mysql`.`gtid_executed` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`innodb_index_stats` | PRIMARY | 1 | 10 | 913 |
| `mysql`.`innodb_table_stats` | PRIMARY | 1 | 3 | 179 |
| `mysql`.`plugin` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`servers` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`server_cost` | PRIMARY | 1 | 6 | 279 |
| `mysql`.`time_zone_leap_second` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone_name` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone_transition_type` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone_transition` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone` | PRIMARY | 1 | 0 | 0 |
| `SYS_COLUMNS` | CLUST_IND | 1 | 134 | 8918 |
| `SYS_DATAFILES` | SYS_DATAFILES_SPACE | 1 | 21 | 1101 |
| `SYS_FIELDS` | CLUST_IND | 1 | 45 | 2039 |
| `SYS_FOREIGN` | FOR_IND | 1 | 0 | 0 |
| `SYS_FOREIGN` | REF_IND | 1 | 0 | 0 |
| `SYS_TABLESPACES` | SYS_TABLESPACES_SPACE | 1 | 21 | 1080 |
| `SYS_TABLES` | CLUST_IND | 1 | 26 | 2060 |
+-------------------------------------+-----------------------+-------+---------+----------+
20 rows in set (0.05 sec)
3. Try again to worming up Buffer Pool manually.
mysql> SET GLOBAL innodb_buffer_pool_load_now = 1;
Query OK, 0 rows affected (0.00 sec)
$ sudo less /var/log/mysqld.log
2019-09-18T10:41:42.994056Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2019-09-18T10:41:42.998523Z 0 [Note] InnoDB: Buffer pool(s) load completed at 190918 10:41:42
5. But no effect to `information_schema.innodb_buffer_page`
mysql> SELECT table_name, index_name, COUNT(*) AS pages, SUM(number_records) AS records, SUM(data_size) AS data FROM information_schema.innodb_buffer_page GROUP BY table_name, index_name;
+-------------------------------------+------------+-------+---------+----------+
| table_name | index_name | pages | records | data |
+-------------------------------------+------------+-------+---------+----------+
| NULL | NULL | 8095 | 1395594 | 76726278 |
| `mysql`.`engine_cost` | PRIMARY | 1 | 2 | 112 |
| `mysql`.`gtid_executed` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`innodb_index_stats` | PRIMARY | 1 | 10 | 913 |
| `mysql`.`innodb_table_stats` | PRIMARY | 1 | 3 | 179 |
| `mysql`.`plugin` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`servers` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`server_cost` | PRIMARY | 1 | 6 | 279 |
| `mysql`.`time_zone_leap_second` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone_name` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone_transition_type` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone_transition` | PRIMARY | 1 | 0 | 0 |
| `mysql`.`time_zone` | PRIMARY | 1 | 0 | 0 |
| `SYS_TABLES` | CLUST_IND | 85 | 8276 | 1256851 |
+-------------------------------------+------------+-------+---------+----------+
14 rows in set (0.04 sec)
6. SHOW ENGINE INNODB STATUS shows me '7167' database pages, so something wrong is in `information_schema.innodb_buffer_page`.
mysql> SHOW ENGINE INNODB STATUS\G
..
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137428992
Dictionary memory allocated 102398
Buffer pool size 8191
Free buffers 1024
Database pages 7167
Old database pages 2625
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 7187, created 119, written 123
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: 7167, unzip_LRU len: 0
I/O sum[87]:cur[0], unzip sum[0]:cur[0]
..
Suggested fix:
Update `information_schema.innodb_buffer_page` when loading from ib_buffer_pool
