MySQL Bugs: #116418: innodb_cached_indexes no longer shows cached

Bug #116418	innodb_cached_indexes no longer shows cached_indexes but page reads
Submitted:	19 Oct 2024 13:14	Modified:	19 Oct 2024 17:15
Reporter:	Morgan Tocker	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S2 (Serious)
Version:		OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
In WL #7170 an API was added to show a summary of the contents of the buffer pool. In the low-level design it's clear that it is supposed to add/subtract from the count as pages are added or removed from the buffer pool.

However, this appears to be changed at some point and the documentation has been updated: https://dev.mysql.com/doc/refman/8.4/en/information-schema-innodb-cached-indexes-table.htm...

"The total number of index pages cached in the InnoDB buffer pool for a specific index since MySQL Server last started."

This is actually an important difference, since the optimizer uses these estimates  to adjust the memory_block_read_cost, per WL#7168.

How to repeat:
The difference between the original behavior and the new behavior becomes meaningful if there is a lot of buffer pool churn.

use test;
DROP TABLE IF EXISTS t1;
CREATE TABLE t1 (
  id INT PRIMARY KEY auto_increment,
  pad1 VARBINARY(255) NOT NULL,
  pad2 VARBINARY(255) NOT NULL,
  pad3 VARBINARY(255) NOT NULL,
  pad4 VARBINARY(255) NOT NULL,
  INDEX (pad1),
  INDEX (pad2),
  INDEX (pad3),
  INDEX (pad4),
  INDEX (pad2,pad3)
);

INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM dual;
INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 100000;
INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 100000;
INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 100000;
INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 100000;
INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 100000;
INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 100000;
INSERT INTO t1 SELECT NULL, RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255), RANDOM_BYTES(255) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 100000;

SELECT
  tables.NAME AS table_name,
  indexes.NAME AS index_name,
  cached.N_CACHED_PAGES AS n_cached_pages,
  FORMAT_BYTES(N_CACHED_PAGES * 16 * 1024) as cache_size_human
FROM
  INFORMATION_SCHEMA.INNODB_CACHED_INDEXES AS cached,
  INFORMATION_SCHEMA.INNODB_INDEXES AS indexes,
  INFORMATION_SCHEMA.INNODB_TABLES AS tables
WHERE
  cached.INDEX_ID = indexes.INDEX_ID
  AND indexes.TABLE_ID = tables.TABLE_ID
ORDER BY n_cached_pages DESC LIMIT 5;

--->

My buffer pool size is 12MiB. So this should not be possible:

table_name	index_name	n_cached_pages	cache_size_human
test/t1	PRIMARY	28646	447.59 MiB
test/t1	pad2_2	18817	294.02 MiB
test/t1	pad4	9621	150.33 MiB
test/t1	pad2	9608	150.12 MiB
test/t1	pad1	9601	150.02 MiB

Suggested fix:
Restore the previous behavior from the original worklog. I suspect this is causing the optimizer to bias indexes which have high churn and are not fitting in the cache, which is the opposite of what it should be picking.

Here is further proof the optimizer is assuming this table is in memory, when it's clearly not:

mysql> SELECT * FROM mysql.engine_cost;
+-------------+-------------+------------------------+------------+---------------------+---------+---------------+
| engine_name | device_type | cost_name              | cost_value | last_update         | comment | default_value |
+-------------+-------------+------------------------+------------+---------------------+---------+---------------+
| default     |           0 | io_block_read_cost     |       NULL | 2024-10-19 16:35:26 | NULL    |             1 |
| default     |           0 | memory_block_read_cost |       NULL | 2024-10-19 16:35:26 | NULL    |          0.25 |
+-------------+-------------+------------------------+------------+---------------------+---------+---------------+
2 rows in set (0.00 sec)

mysql> EXPLAIN FORMAT=JSON SELECT * FROM t1 WHERE pad1='aaa'\G
*************************** 1. row ***************************
EXPLAIN: {
  "query_block": {
    "select_id": 1,
    "cost_info": {
      "query_cost": "0.35"
    },
    "table": {
      "table_name": "t1",
      "access_type": "ref",
      "possible_keys": [
        "pad1"
      ],
      "key": "pad1",
      "used_key_parts": [
        "pad1"
      ],
      "key_length": "257",
      "ref": [
        "const"
      ],
      "rows_examined_per_scan": 1,
      "rows_produced_per_join": 1,
      "filtered": "100.00",
      "index_condition": "(`test`.`t1`.`pad1` = 'aaa')",
      "cost_info": {
        "read_cost": "0.25", <-- memory_block_read_cost
        "eval_cost": "0.10",
        "prefix_cost": "0.35",
        "data_read_per_join": "1K"
      },
      "used_columns": [
        "id",
        "pad1",
        "pad2",
        "pad3",
        "pad4"
      ]
    }
  }
}
1 row in set, 1 warning (0.00 sec)

mysql> update mysql.engine_cost set cost_value=5 WHERE cost_name='memory_block_read_cost';
Query OK, 1 row affected (0.01 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> flush optimizer_costs;
Query OK, 0 rows affected (0.00 sec)

# important! Create a new session first.

mysql>  EXPLAIN FORMAT=JSON SELECT * FROM t1 WHERE pad1='aaa'\G
*************************** 1. row ***************************
EXPLAIN: {
  "query_block": {
    "select_id": 1,
    "cost_info": {
      "query_cost": "5.10"
    },
    "table": {
      "table_name": "t1",
      "access_type": "ref",
      "possible_keys": [
        "pad1"
      ],
      "key": "pad1",
      "used_key_parts": [
        "pad1"
      ],
      "key_length": "257",
      "ref": [
        "const"
      ],
      "rows_examined_per_scan": 1,
      "rows_produced_per_join": 1,
      "filtered": "100.00",
      "index_condition": "(`test`.`t1`.`pad1` = 'aaa')",
      "cost_info": {
        "read_cost": "5.00", <-- uses the new value for memory_block_read_cost
        "eval_cost": "0.10",
        "prefix_cost": "5.10",
        "data_read_per_join": "1K"
      },
      "used_columns": [
        "id",
        "pad1",
        "pad2",
        "pad3",
        "pad4"
      ]
    }
  }
}
1 row in set, 1 warning (0.00 sec)

Sorry, this is a little embarrassing, but I tracked down the source of this issue.

The buffer pool was being set in a mysqld-auto.cnf, and was large enough to hold the indexes.

The behavior of the server is correct in all versions I tested (8.0.26, 28, 30-34, 40 + 8.40).

Thank you, Morgan.

regards,
Umesh