2

I am experiencing an issue with MySQL memory usage increasing over time to a point where OOM Killer kills the MySQL process. I have 3 servers configured with Group Replication (1 Primary and 2 secondary).

The servers are running on AWS EC2: m5.2xlarge (32GB RAM, 8vCPU,500GB Amazon EBS Storage) Debian 11 MySQL 8.0.36

Link to additional requested information: https://justpaste.it/f0f4n

Updated additional information after 44 hours of server running: https://justpaste.it/6v4pl

The memory usage issue seems to occur faster on a server that is the PRIMARY server in the cluster but does affect all servers.

I have been trying, without success, to figure out what the cause of this could be.

The system memory usage for the MySQL process and the listed memory allocation in MySQL do not correspond.

The additional memory usage does seem to be related to HIGH_NUMBER_OF_BYTES_USED of "memory/innodb/ut0rbt". It seems that this memory accounts for the reported memory discrepancy. In all instances where the memory is growing, this reported information is growing as well.

Below is the output of top - As you can see, the current physical RAM in use is by MySQL is 27.0G

Tasks: 118 total, 1 running, 117 sleeping, 0 stopped, 0 zombie %Cpu(s): 13.4 us, 0.5 sy, 0.0 ni, 85.3 id, 0.5 wa, 0.0 hi, 0.2 si, 0.0 st MiB Mem : 31650.4 total, 263.6 free, 27895.9 used, 3490.9 buff/cache MiB Swap: 4096.0 total, 0.1 free, 4095.9 used. 3302.6 avail Mem

PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                        
757962 mysql     20   0   33.3g  27.0g      0 S  55.4  87.3   1104:36 mysqld 

Below is the memory usage reported by MySQL:

mysql> select event_name,current_alloc from sys.memory_global_by_current_bytes limit 10;

+---------------------------------------------------------------+---------------+
| event_name                                                    | current_alloc |
+---------------------------------------------------------------+---------------+
| memory/innodb/buf_buf_pool                                    | 8.18 GiB      |
| memory/group_rpl/GCS_XCom::xcom_cache                         | 1023.71 MiB   |
| memory/innodb/log_buffer_memory                               | 256.00 MiB    |
| memory/temptable/physical_ram                                 | 94.00 MiB     |
| memory/performance_schema/events_statements_summary_by_digest | 40.28 MiB     |
| memory/mysys/KEY_CACHE                                        | 32.00 MiB     |
| memory/innodb/ut0link_buf                                     | 24.00 MiB     |
| memory/sql/TABLE                                              | 23.30 MiB     |
| memory/innodb/lock0lock                                       | 22.22 MiB     |
| memory/innodb/memory                                          | 21.93 MiB     |
+---------------------------------------------------------------+---------------+
10 rows in set (0.01 sec)

mysql> select format_bytes(sum(current_alloc)) from sys.x$memory_global_by_current_bytes;

+----------------------------------+
| format_bytes(sum(current_alloc)) |
+----------------------------------+
| 9.95 GiB                         |
+----------------------------------+
1 row in set (0.00 sec)

Below is a report on what my expected memory usage would be based on the configuration of the server.

+------------------------------------------+--------------------+
|                          key_buffer_size |          32.000 MB |
|                         query_cache_size |           0.000 MB |
|                  innodb_buffer_pool_size |        8192.000 MB |
|          innodb_additional_mem_pool_size |           0.000 MB |
|                   innodb_log_buffer_size |         256.000 MB |
+------------------------------------------+--------------------+
|                              BASE MEMORY |        8480.000 MB |
+------------------------------------------+--------------------+
|                         sort_buffer_size |           0.250 MB |
|                         read_buffer_size |           0.125 MB |
|                     read_rnd_buffer_size |           0.250 MB |
|                         join_buffer_size |           0.250 MB |
|                             thread_stack |           1.000 MB |
|                        binlog_cache_size |           0.031 MB |
|                           tmp_table_size |          16.000 MB |
+------------------------------------------+--------------------+
|                    MEMORY PER CONNECTION |          17.906 MB |
+------------------------------------------+--------------------+
|                     Max_used_connections |                129 |
|                          max_connections |                300 |
+------------------------------------------+--------------------+
|                              TOTAL (MIN) |       10789.906 MB |
|                              TOTAL (MAX) |       13851.875 MB |
+------------------------------------------+--------------------+

I have a suspicion that the memory usage is somehow related to the memory/innodb/ut0rbt based on looking at the HIGH_NUMBER_OF_BYTES_USED being 16GB in the below report. I cannot find much information on memory/innodb/ut0rbt when searching and am not sure where to go to from here. Any guidance would be appreciated.

SELECT * FROM performance_schema.memory_summary_global_by_event_name where SUM_NUMBER_OF_BYTES_ALLOC !=0 ORDER BY HIGH_NUMBER_OF_BYTES_USED DESC;

+--------------------------------------------------------------------------------+-------------+-------------+---------------------------+--------------------------+----------------+--------------------+-----------------+--------------------------+------------------------------+---------------------------+
| EVENT_NAME                                                                     | COUNT_ALLOC | COUNT_FREE  | SUM_NUMBER_OF_BYTES_ALLOC | SUM_NUMBER_OF_BYTES_FREE | LOW_COUNT_USED | CURRENT_COUNT_USED | HIGH_COUNT_USED | LOW_NUMBER_OF_BYTES_USED | CURRENT_NUMBER_OF_BYTES_USED | HIGH_NUMBER_OF_BYTES_USED |
+--------------------------------------------------------------------------------+-------------+-------------+---------------------------+--------------------------+----------------+--------------------+-----------------+--------------------------+------------------------------+---------------------------+
| memory/innodb/ut0rbt                                                           | 12367972599 | 12367971756 |             1175789585128 |            1175789498761 |              0 |                843 |       168276872 |                        0 |                        86367 |               16869347952 |
| memory/innodb/buf_buf_pool                                                     |          64 |           0 |                8783134720 |                        0 |              0 |                 64 |              64 |                        0 |                   8783134720 |                8783134720 |
| memory/temptable/physical_ram                                                  |       18599 |       18501 |               26578851040 |              26476087456 |              0 |                 98 |             506 |                        0 |                    102763584 |                1634745920 |
| memory/mysys/TREE                                                              |       13933 |       13930 |                4655917920 |               4655878864 |              0 |                  3 |            1568 |                        0 |                        39056 |                1119816488 |
| memory/group_rpl/GCS_XCom::xcom_cache                                          |      767889 |      300297 |                1872249111 |                798535661 |              0 |             467592 |          495763 |                        0 |                   1073713450 |                1075974241 |
| memory/innodb/memory                                                           |   532219874 |   532207809 |            13596646725344 |           13596623477632 |              0 |              12065 |           87170 |                        0 |                     23247712 |                 889900184 |
| memory/sql/String::value                                                       |   179746709 |   179745073 |              186307408232 |             186301810472 |              0 |               1636 |            8326 |                        0 |                      5597760 |                 444524496 |
| memory/innodb/log_buffer_memory                                                |           1 |           0 |                 268436464 |                        0 |              0 |                  1 |               1 |                        0 |                    268436464 |                 268436464 |
| memory/sql/Unique::merge_buffer                                                |          36 |          36 |                 301991328 |                301991328 |              0 |                  0 |              26 |                        0 |                            0 |                 218104848 |
| memory/sql/THD::main_mem_root                                                  |   200742977 |   200742846 |             3390843376248 |            3390840251216 |              0 |                131 |            3117 |                        0 |                      3125032 |                  88720256 |
| memory/sql/Log_event                                                           |    43535365 |    43535358 |               20931402783 |              20931400073 |              0 |                  7 |          269641 |                        0 |                         2710 |                  49982659 |
| memory/sql/JSON                                                                |     9507512 |     9507456 |                 859590368 |                859587008 |              0 |                 56 |          549870 |                        0 |                         3360 |                  47863656 |
| memory/group_rpl/certification_info                                            |     1743130 |     1742155 |                 164631088 |                158843768 |              0 |                975 |          426208 |                        0 |                      5787320 |                  43207824 |
| memory/group_rpl/transaction_data                                              |     2931445 |     2931445 |                3611045127 |               3611045127 |              0 |                  0 |              15 |                        0 |                            0 |                  42283650 |
| memory/performance_schema/events_statements_summary_by_digest                  |           1 |           0 |                  42240000 |                        0 |              0 |                  1 |               1 |                        0 |                     42240000 |                  42240000 |
| memory/group_rpl/Gcs_message_data::m_buffer                                    |      711966 |      711966 |                3274265418 |               3274265418 |              0 |                  0 |               4 |                        0 |                            0 |                  38611767 |
| memory/mysys/KEY_CACHE                                                         |           3 |           0 |                  33556016 |                        0 |              0 |                  3 |               3 |                        0 |                     33556016 |                  33556016 |
| memory/sql/TABLE                                                               |     2498162 |     2490152 |                2662845439 |               2638261263 |              0 |               8010 |            9131 |                        0 |                     24584176 |                  28309707 |
| memory/sql/Filesort_buffer::sort_keys                                          |     3493367 |     3493366 |              115200850575 |             115200817775 |              0 |                  1 |             636 |                        0 |                        32800 |                  25885528 |
+--------------------------------------------------------------------------------+-------------+-------------+---------------------------+--------------------------+----------------+--------------------+-----------------+--------------------------+------------------------------+---------------------------+
9
  • Additional DB information request, please. OS, Version? # cores, any SSD or NVME devices on MySQL Host server? Post TEXT data on justpaste.it and share the links. From your SSH login root, Text results of: A) SELECT COUNT(*) FROM information_schema.tables; B) SHOW GLOBAL STATUS; after minimum 24 hours UPTIME C) SHOW GLOBAL VARIABLES; D) SHOW FULL PROCESSLIST; E) STATUS; not SHOW STATUS, just STATUS; G) SHOW ENGINE INNODB STATUS; for server workload tuning analysis to provide suggestions for reducing RAM usage. Feb 13 at 16:27
  • I had the same problem and sometimes memory increased unexpectedly. I realized that some deadlock caused the problem. I suggest checking them using SHOW ENGINE INNODB STATUS and taking care of them if any.
    – s.abbaasi
    Feb 13 at 19:05
  • Which version of MySQL? How much RAM (looks like 32GB)? Are other apps running on the same server?
    – Rick James
    Feb 14 at 0:36
  • 1
    @wilson-hauck I have had to restart the servers recently to avoid the memory issue becoming critical and will update with further requested information once they have been running for 24 hours. link
    – O Genthe
    Feb 14 at 5:44
  • 1
    I have updated information after the server has been running for about 44 hours: link
    – O Genthe
    Feb 15 at 14:41

2 Answers 2

0
Analysis of GLOBAL STATUS and VARIABLES:
 

Observations:

  • Version: 8.0.36
  • 32 GB of RAM
  • Uptime = 14:50:16; some GLOBAL STATUS values may not be meaningful yet.
  • 370 QPS

The More Important Issues:

Suggested setting changes:

innodb_io_capacity = 2000
innodb_io_capacity_max = 3000
log_slow_slave_statement = ON
long_query_time = 1

Try turning off the performance_schema (if the cloud allows such). Contrary to your goal of decreasing memory usage, increasing innodb_buffer_pool_size may help by cutting back on the thrashing in the buffer pool, thereby speeding up the queries.

Analyzing the slowlog may lead to queries to improve. Turn on the SlowLog

Details and other observations:

( Key_reads + Key_writes + Innodb_pages_read + Innodb_pages_written + Innodb_dblwr_writes + Innodb_buffer_pool_pages_flushed ) = (0 + 0 + 152828797 + 603530 + 201349 + 603530) / 53416 = 2887 /sec -- IOPs? -- If the hardware can handle it, set innodb_io_capacity (now 200) to about this value.

( ( Key_reads + Key_writes + Innodb_pages_read + Innodb_pages_written + Innodb_dblwr_writes + Innodb_buffer_pool_pages_flushed ) / innodb_io_capacity / Uptime ) = ( 0 + 0 + 152828797 + 603530 + 201349 + 603530 ) / 200 / 53416 = 1443.7% -- This may be a metric indicating what innodb_io_capacity is set reasonably. -- Increase innodb_io_capacity (now 200) if the hardware can handle it.

( table_open_cache ) = 4,000 -- Number of table descriptors to cache -- Several hundred is usually good.

( innodb_buffer_pool_size ) = 8,192M / 32768M = 25.0% -- % of RAM used for InnoDB buffer_pool -- Set to about 70% of available RAM. (To low is less efficient; too high risks swapping.)

( innodb_lru_scan_depth * innodb_page_cleaners ) = 1,024 * 4 = 4,096 -- Amount of work for page cleaners every second. -- "InnoDB: page_cleaner: 1000ms intended loop took ..." may be fixable by lowering lru_scan_depth: Consider 1000 / innodb_page_cleaners (now 4). Also check for swapping.

( innodb_lru_scan_depth ) = 1,024 -- innodb_lru_scan_depth is a very poorly named variable. A better name would be innodb_free_page_target_per_buffer_pool. It is a number of pages InnoDB tries to keep free in each buffer pool instance to speed up read and page creation operations. -- "InnoDB: page_cleaner: 1000ms intended loop took ..." may be fixed by lowering lru_scan_depth

( innodb_io_capacity ) = 200 -- When flushing, use this many IOPs. -- Reads could be slugghish or spiky. Use 2000 if using SSD drive.

( innodb_io_capacity_max / innodb_io_capacity ) = 2,000 / 200 = 10 -- Capacity: max/plain -- Recommend 2. Max should be about equal to the IOPs your I/O subsystem can handle. (If the drive type is unknown 2000/200 may be a reasonable pair.)

( Innodb_buffer_pool_reads ) = 141341347 / 53416 = 2646 /sec -- Cache misses in the buffer_pool. -- Increase innodb_buffer_pool_size (now 8589934592)? (~100 is limit for HDD, ~1000 is limit for SSDs.)

( (Innodb_buffer_pool_reads + Innodb_buffer_pool_pages_flushed) ) = ((141341347 + 603530) ) / 53416 = 2657 /sec -- InnoDB I/O -- Increase innodb_buffer_pool_size (now 8589934592)?

( innodb_log_buffer_size ) = 256M -- Suggest 2MB-64MB, and at least as big as biggest blob set in transactions. -- Adjust innodb_log_buffer_size (now 268435456).

( Innodb_os_log_written / (Uptime / 3600) / innodb_log_files_in_group / innodb_log_file_size ) = 565,523,968 / (53416 / 3600) / 2 / 1024M = 0.0177 -- Ratio -- (see minutes)

( Uptime / 60 * innodb_log_file_size / Innodb_os_log_written ) = 53,416 / 60 * 1024M / 565523968 = 1,690 -- Minutes between InnoDB log rotations Beginning with 5.6.8, innodb_log_file_size can be changed dynamically; I don't know about MariaDB. Be sure to also change my.cnf -- (The recommendation of 60 minutes between rotations is somewhat arbitrary.) Adjust innodb_log_file_size (now 1073741824). (Cannot change in AWS.)

( innodb_flush_method ) = innodb_flush_method = fsync -- How InnoDB should ask the OS to write blocks. Suggest O_DIRECT or O_ALL_DIRECT (Percona) to avoid double buffering. (At least for Unix.) See chrischandler for caveat about O_ALL_DIRECT

( Innodb_row_lock_time_avg ) = 6,703 -- Avg time to lock a row (millisec) -- Possibly conflicting queries; possibly table scans.

( Innodb_row_lock_time_max ) = 50,003 -- Max time to lock a row (millisec) -- Possibly conflicting queries; possibly table scans.

( ( Innodb_pages_read + Innodb_pages_written ) / Uptime / innodb_io_capacity ) = ( 152828797 + 603530 ) / 53416 / 200 = 1436.2% -- If > 100%, need more io_capacity. -- Increase innodb_io_capacity (now 200) if the drives can handle it.

( innodb_io_capacity ) = 200 -- I/O ops per second capable on disk . 100 for slow drives; 200 for spinning drives; 1000-2000 for SSDs; multiply by RAID factor. Limits write IO requests per second (IOPS). -- For starters: HDD: 200; SSD: 2000.

( innodb_adaptive_hash_index ) = innodb_adaptive_hash_index = ON -- Whether to use the adapative hash (AHI). -- ON for mostly readonly; OFF for DDL-heavy

( innodb_flush_log_at_trx_commit ) = 0 -- 1 = secure; 2 = faster -- (You decide) Use 1, along with sync_binlog (now 1)=1 for the greatest level of fault tolerance. 0 is best for speed. 2 is a compromise between 0 and 1.

( innodb_adaptive_hash_index ) = innodb_adaptive_hash_index = ON -- Usually should be ON. -- There are cases where OFF is better. See also innodb_adaptive_hash_index_parts (now 8) (after 5.7.9) and innodb_adaptive_hash_index_partitions (MariaDB and Percona). ON has been implicated in rare crashes (bug 73890). 10.5.0 decided to default OFF.

( innodb_print_all_deadlocks ) = innodb_print_all_deadlocks = OFF -- Whether to log all Deadlocks. -- If you are plagued with Deadlocks, turn this on. Caution: If you have lots of deadlocks, this may write a lot to disk.

( (Com_insert + Com_update + Com_delete + Com_replace) / Com_commit ) = (217409 + 106854 + 160 + 4061) / 271162 = 1.21 -- Statements per Commit (assuming all InnoDB) -- Low: Might help to group queries together in transactions; High: long transactions strain various things.

( slow_query_log ) = slow_query_log = OFF -- Whether to log slow queries. (5.1.12)

( long_query_time ) = 10 -- Cutoff (Seconds) for defining a "slow" query. -- Suggest 2

( log_slow_slave_statements ) = log_slow_slave_statements = OFF -- (5.6.11, 5.7.1) By default, replicated statements won't show up in the slowlog; this causes them to show. -- It can be helpful in the slowlog to see writes that could be interfering with Replica reads.

( thread_stack ) = 1M = 1.05e+6 -- The size of each stack frame. -- Too small = won't run; too big = waste RAM.

Abnormally small:

Com_set_option = 2.1 /HR
gtid_executed_compression_period = 0

Abnormally large:

( Innodb_pages_read + Innodb_pages_written ) / Uptime = 2,872
Com_group_replication_start = 0.067 /HR
Com_group_replication_stop = 0.067 /HR
Innodb_buffer_pool_reads * innodb_page_size / innodb_buffer_pool_size = 26958.7%
Innodb_data_read = 46874794 /sec
Innodb_data_reads = 2861 /sec
Innodb_pages_read = 2861 /sec
Innodb_pages_read + Innodb_pages_written = 2872 /sec
Innodb_system_rows_deleted = 0.74 /sec
Innodb_system_rows_inserted = 0.74 /sec
Innodb_system_rows_updated = 77 /HR
Mysqlx_notified_by_group_replication = 20
Performance_schema_session_connect_attrs_longest_seen = 466
max_error_count = 1,024
optimizer_trace_offset = --1
performance_schema_error_size = 5,310
performance_schema_max_cond_classes = 150
performance_schema_max_mutex_classes = 350
performance_schema_max_rwlock_classes = 60
performance_schema_max_stage_classes = 175
performance_schema_max_statement_classes = 219
performance_schema_max_thread_classes = 100
slave_parallel_workers = 4

Abnormal strings:

binlog_checksum = NONE
character_set_system = utf8mb3
enforce_gtid_consistency = ON
event_scheduler = ON
gtid_executed = 3f0fc6fb-a406-43eb-8460-d1a590b9d240:1-12329678:13025231-13025521, 
gtid_mode = ON
gtid_purged = 3f0fc6fb-a406-43eb-8460-d1a590b9d240:1-9732616:10023974-10024475, 
have_query_cache = NO
innodb_fast_shutdown = 1
mysqlx_compression_algorithms = DEFLATE_STREAM,LZ4_MESSAGE,ZSTD_STREAM
optimizer_trace = enabled=off,one_line=off
optimizer_trace_features = greedy_search=on, range_optimizer=on, dynamic_range=on, repeated_subselect=on
protocol_compression_algorithms = zlib,zstd,uncompressed
slave_allow_batching = ON
slave_parallel_type = LOGICAL_CLOCK
slave_preserve_commit_order = ON
slave_rows_search_algorithms = INDEX_SCAN,HASH_SCAN
sql_slave_skip_counter = 0
version_compile_zlib = 1.2.13
2
  • Thanks for this in-depth recommendation. I am looking into the report that you have generated. Can you shed any light on what aspect could be causing the high memory usage?
    – O Genthe
    Feb 15 at 14:36
  • @OGenthe - Frankly, no. Nothing sees high enough to be even noticeable, so I shifted toward looking for transient things that could be hogs -- inefficient I/O, big queries (slowlog), etc. (In 20+ years of dealing with MySQL, I have almost never seen a "memory leak".)
    – Rick James
    Feb 15 at 22:08
0

O Genthe,
Your SHOW GLOBAL STATUS report includes threads_connected with a value of just over 100.

This query, SELECT 'SLEEPING Ram use', COUNT(*),SUM(time),SUM(memory_used),SUM(max_memory_used) FROM information_schema.processlist WHERE command="Sleep";

will likely confirm the approximate count and two memory_used values for sleeping process id's.

MySQL generally expects a Connect, Process, Close from each client when something needs to be accomplished for the client. Failure to do the 'Close' will leave a thread_connected. Also if some users are allowed to do ad-hoc queries from the MySQL Command Prompt and do not EXIT when finished, that could leave a thread connected.

Please post the results of the above query so we know your count and the other two memory_used values.

For additional information search on Google or Bing for 'MySQL Connect Process Close Tutorial' articles. Most articles are reasonable in their documentation.

Your workload analysis resulted in the following suggestions for your AWS EC2 Parameter Group settings.

thread_cache_size=100  # from 11 to reduce threads_created of 135.
innodb_io_capacity=500  # from 200 to use more of available SSD IOPS.
read_rnd_buffer_size=16384  # from 262144 to reduce handler_read_rnd_next Rate Per Second of 270,569.
read_buffer_size=262144  # from 131072 to reduce handler_read_next RPS of 97,021.

There are many more opportunities to manage Global Variables for reduction in query completion time required.

SHOW GLOBAL STATUS also reports handler_rollback an average of 1 every ~ 5 seconds. These incidents can be reported in your error_log if you will SET GLOBAL innodb_print_all_deadlocks=1; and 10 minutes later turn it back OFF with 0 to avoid overwhelming reporting of errors. Search for 'MySQL Deadlock prevention tutorial', for assistance.

View profile, please.

12
  • This query: SELECT 'SLEEPING Ram use', COUNT(*),SUM(time),SUM(memory_used),SUM(max_memory_used) FROM information_schema.processlist WHERE command="Sleep" returns an error: ERROR 1054 (42S22): Unknown column 'memory_used' in 'field list' The only columns seem to be | ID | USER | HOST | DB | COMMAND | TIME | STATE | INFO |
    – O Genthe
    Feb 19 at 8:35
  • There do not seem to be any actual deadlocks, though I may be making an error in how/where I look. There is no 'LATEST DETECTED DEADLOCK' when running SHOW ENGINE INNODB STATUS;. Also, if I run SET GLOBAL innodb_print_all_deadlocks=1; no deadlock information appears in the error log, despite growing handler_rollback numbers. I am assuming that this means that the rollbacks are just a part of normal operations, rather than being caused by deadlocks but can you confirm?
    – O Genthe
    Feb 19 at 8:47
  • @OGenthe Please post TEXT results of SHOW CREATE TABLE performance_schema.processlist; we may find the columns in the performance_schema world. Feb 19 at 16:53
  • 1
    SHOW CREATE TABLE performance_schema.processlist; results here justpaste.it/e0r2e
    – O Genthe
    Feb 20 at 9:56
  • 1
    I only left the innodb_print_all_deadlocks=1 on for about 15 minutes and got no output into the error log for deadlocks. Just to be clear, this is on a Debian 11 server on AWS EC2 instance. Output of the last 100 entries in the error.log file justpaste.it/drm2r
    – O Genthe
    Feb 20 at 10:00

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.