| Bug #81804 | Memory leak or bug in P_S instrumentation for InnoDB threads | ||
|---|---|---|---|
| Submitted: | 10 Jun 2016 12:35 | Modified: | 13 Jun 2016 11:50 |
| Reporter: | Sveta Smirnova (OCA) | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S2 (Serious) |
| Version: | 5.7.13 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[10 Jun 2016 12:58]
Sveta Smirnova
If run sysbench oltp test for some time situation becomes even worse: mysql> select * from memory_by_thread_by_current_bytes; +-----------+---------------------------------+--------------------+-------------------+-------------------+-------------------+-----------------+ | thread_id | user | current_count_used | current_allocated | current_avg_alloc | current_max_alloc | total_allocated | +-----------+---------------------------------+--------------------+-------------------+-------------------+-------------------+-----------------+ | 1 | sql/main | 11104 | 40.37 MiB | 3.72 KiB | 25.19 MiB | 66.13 MiB | | 9 | innodb/page_cleaner_thread | 58511 | 4.46 MiB | 80 bytes | 4.46 MiB | 22.74 MiB | | 23 | root@localhost | 564 | 1.45 MiB | 2.63 KiB | 805.47 KiB | 57.98 MiB | | 14 | innodb/srv_master_thread | 2687 | 209.92 KiB | 80 bytes | 209.92 KiB | 115.25 MiB | | 20 | innodb/dict_stats_thread | 47 | 7.72 KiB | 168 bytes | 6.88 KiB | 6.12 MiB | | 19 | innodb/buf_dump_thread | 1 | 32 bytes | 32 bytes | 32 bytes | 299.10 KiB | | 11 | innodb/srv_lock_timeout_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 12 | innodb/srv_error_monitor_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 13 | innodb/srv_monitor_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 15 | innodb/srv_purge_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 16 | innodb/srv_worker_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 17 | innodb/srv_worker_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 18 | innodb/srv_worker_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 21 | sql/signal_handler | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 22 | sql/compress_gtid_table | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 2 | sql/thread_timer_notifier | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 3 | innodb/io_ibuf_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 4 | innodb/io_log_thread | -95 | -7600 bytes | 80 bytes | 0 bytes | 0 bytes | | 6 | innodb/io_read_thread | -1109 | -88720 bytes | 80 bytes | 0 bytes | 238.06 MiB | | 5 | innodb/io_read_thread | -1502 | -120160 bytes | 80 bytes | 0 bytes | 296.04 MiB | | 7 | innodb/io_write_thread | -25533 | -2042640 bytes | 80 bytes | 0 bytes | 177.23 KiB | | 8 | innodb/io_write_thread | -32978 | -2638240 bytes | 80 bytes | 0 bytes | 189.45 KiB | +-----------+---------------------------------+--------------------+-------------------+-------------------+-------------------+-----------------+ 22 rows in set (0,10 sec)
[13 Jun 2016 11:50]
MySQL Verification Team
Hello Sveta, Thank you for the report and feedback. Thanks, Umesh
[2 Jul 2019 10:59]
minlei sun
I still found it in mysql-5.7.26-log.
mysql> select * from memory_summary_by_host_by_event_name where event_name='memory/innodb/mem0mem' and host='localhost'\G
*************************** 1. row ***************************
HOST: localhost
EVENT_NAME: memory/innodb/mem0mem
COUNT_ALLOC: 446
COUNT_FREE: 574
SUM_NUMBER_OF_BYTES_ALLOC: 530879
SUM_NUMBER_OF_BYTES_FREE: 1022464
LOW_COUNT_USED: -128
CURRENT_COUNT_USED: -128
HIGH_COUNT_USED: 38
LOW_NUMBER_OF_BYTES_USED: -491585
CURRENT_NUMBER_OF_BYTES_USED: -491585
HIGH_NUMBER_OF_BYTES_USED: 44639
1 row in set (0.01 sec)
mysql> select version();
+------------+
| version() |
+------------+
| 5.7.26-log |
+------------+
1 row in set (0.00 sec)
Description: Performance schema shows negative values of CURRENT_NUMBER_OF_BYTES_USED for internal InnoDB threads How to repeat: sveta@Thinkie:~/build/mysql-5.7/mysql-test$ Logging: ./mtr --start innodb 2016-06-10T12:33:21.123320Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000) 2016-06-10T12:33:21.123373Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000) MySQL Version 5.7.13 Checking supported features... - SSL connections supported - binaries are debug compiled Collecting tests... Checking leftover processes... Removing old var directory... Creating var directory '/home/sveta/build/mysql-5.7/mysql-test/var'... Installing system database... ============================================================================== TEST RESULT TIME (ms) or COMMENT -------------------------------------------------------------------------- worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 worker[1] Started [mysqld.1 - pid: 18757, winpid: 18757] worker[1] Using config for test innodb.innodb worker[1] Port and socket path for server(s): worker[1] mysqld.1 13000 /home/sveta/build/mysql-5.7/mysql-test/var/tmp/mysqld.1.sock worker[1] Waiting for server(s) to exit... sveta@Thinkie:~/build/mysql-5.7/mysql-test$ mysqlmtr sys Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 2 Server version: 5.7.13-debug-log Source distribution Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved. Oracle is a registered trademark of Oracle Corporation and/or its affiliates. Other names may be trademarks of their respective owners. Type 'help;' or '\h' for help. Type '\c' to clear the current input statement. mysql> select * from memory_by_thread_by_current_bytes; +-----------+---------------------------------+--------------------+-------------------+-------------------+-------------------+-----------------+ | thread_id | user | current_count_used | current_allocated | current_avg_alloc | current_max_alloc | total_allocated | +-----------+---------------------------------+--------------------+-------------------+-------------------+-------------------+-----------------+ | 1 | sql/main | 11104 | 40.37 MiB | 3.72 KiB | 25.19 MiB | 66.13 MiB | | 23 | root@localhost | 554 | 1.45 MiB | 2.67 KiB | 805.47 KiB | 9.33 MiB | | 9 | innodb/page_cleaner_thread | 41 | 3.20 KiB | 80 bytes | 3.20 KiB | 6.41 KiB | | 14 | innodb/srv_master_thread | 1 | 80 bytes | 80 bytes | 80 bytes | 9.91 KiB | | 19 | innodb/buf_dump_thread | 1 | 32 bytes | 32 bytes | 32 bytes | 299.10 KiB | | 8 | innodb/io_write_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 11 | innodb/srv_lock_timeout_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 12 | innodb/srv_error_monitor_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 13 | innodb/srv_monitor_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 15 | innodb/srv_purge_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 16 | innodb/srv_worker_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 17 | innodb/srv_worker_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 18 | innodb/srv_worker_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 20 | innodb/dict_stats_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 21 | sql/signal_handler | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 22 | sql/compress_gtid_table | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 2 | sql/thread_timer_notifier | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 3 | innodb/io_ibuf_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 5 | innodb/io_read_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 6 | innodb/io_read_thread | 0 | 0 bytes | 0 bytes | 0 bytes | 0 bytes | | 4 | innodb/io_log_thread | -2 | -160 bytes | 80 bytes | 0 bytes | 0 bytes | | 7 | innodb/io_write_thread | -41 | -3280 bytes | 80 bytes | 0 bytes | 40 bytes | +-----------+---------------------------------+--------------------+-------------------+-------------------+-------------------+-----------------+ 22 rows in set (0,10 sec) mysql> select *from performance_schema.memory_summary_by_thread_by_event_name where CURRENT_NUMBER_OF_BYTES_USED<0\G *************************** 1. row *************************** THREAD_ID: 4 EVENT_NAME: memory/innodb/sync0rw COUNT_ALLOC: 0 COUNT_FREE: 2 SUM_NUMBER_OF_BYTES_ALLOC: 0 SUM_NUMBER_OF_BYTES_FREE: 160 LOW_COUNT_USED: -2 CURRENT_COUNT_USED: -2 HIGH_COUNT_USED: 0 LOW_NUMBER_OF_BYTES_USED: -160 CURRENT_NUMBER_OF_BYTES_USED: -160 HIGH_NUMBER_OF_BYTES_USED: 0 *************************** 2. row *************************** THREAD_ID: 7 EVENT_NAME: memory/innodb/sync0rw COUNT_ALLOC: 0 COUNT_FREE: 44 SUM_NUMBER_OF_BYTES_ALLOC: 0 SUM_NUMBER_OF_BYTES_FREE: 3520 LOW_COUNT_USED: -44 CURRENT_COUNT_USED: -44 HIGH_COUNT_USED: 0 LOW_NUMBER_OF_BYTES_USED: -3520 CURRENT_NUMBER_OF_BYTES_USED: -3520 HIGH_NUMBER_OF_BYTES_USED: 0 2 rows in set (0,02 sec) Suggested fix: Check if this is real memory leak or if bug in Performance Schema memory instrumentation, then fix =)