MySQL Bugs: #111247: Executing a SELECT statement causes to allocate lots of memory for binlog

Bug #111247	Executing a SELECT statement causes to allocate lots of memory for binlog
Submitted:	1 Jun 2023 15:02	Modified:	2 Jun 2023 7:28
Reporter:	Yawei Sun	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	MySQL8.0.22, 8.0.23	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
When binlog is enabled, executing a SELECT statement causes to allocate lots of memory for binlog, the SELECT statement calls a function which does not contain any DML. We can see that the memory usage grows hundreds of megabytes during the execution by "select current_alloc from sys.memory_global_by_current_bytes where event_name = 'memory/sql/THD::main_mem_root'" . We found that the memory is mainly allocate in function get_var_with_binlog, which is in src/sql/sql/item_func.cc through jemalloc. There is no the issue when binlog is disabled.

How to repeat:
--source include/master-slave.inc
--source include/have_binlog_format_row.inc

--echo #
--echo # Prepare environment
--echo #
# create tables
CREATE TABLE `member_base_secret` (`id` bigint NOT NULL AUTO_INCREMENT, `entity_id` bigint NOT NULL COMMENT '实体Id', `entity_column` varchar(50) DEFAULT 'NAME' COMMENT '列名', `secret_value` varchar(1024) NOT NULL COMMENT '密文', PRIMARY KEY (`id`)) ENGINE=InnoDB AUTO_INCREMENT=2031586 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;

# create function
delimiter $$;
CREATE FUNCTION `PMS_DECRYPT`(arg_value VARCHAR(3000)) RETURNS varchar(3000) CHARSET utf8mb4 DETERMINISTIC 
BEGIN 
IF arg_value IS NOT NULL AND TRIM(arg_value) <> '' AND TRIM(@AES_KEY_VALUE) <> '' AND CHAR_LENGTH(@AES_KEY_VALUE) >= 32 THEN 
SET @real_value = AES_DECRYPT(from_base64(arg_value),@AES_KEY_VALUE); 
IF @real_value IS NOT NULL THEN 
RETURN(@real_value); 
END IF; 
END IF; 
RETURN(arg_value); 
END $$
delimiter ;$$
# insert data into table member_base_secret
--let $insert_loop_count = 5000
while ($insert_loop_count) {
  --disable_query_log
  --disable_result_log
  insert into member_base_secret(entity_id, secret_value) value ('32879435', 'aJNtKaE//8DksU03FyX4YA==');
  insert into member_base_secret(entity_id, secret_value) value ('72168810', '/1LYJQef6GFGWX8KQt58of8KvLMH4TMEM0s16+blnyE=');
  insert into member_base_secret(entity_id, secret_value) value ('72176931', 'FtngxzeyLtXFZaLwFqatxg==');
  insert into member_base_secret(entity_id, secret_value) value ('72286979', 'YRc8Um12WcVGwzpDKu4ZJQ==');
  insert into member_base_secret(entity_id, secret_value) value ('72287654', '/dgPxRdaVdcoZq5zu7RDxQ==');
  insert into member_base_secret(entity_id, secret_value) value ('72287742', 'd0FPktUGL3dgjSj9k2Mc+A==');
  insert into member_base_secret(entity_id, secret_value) value ('72290279', 'EktgzNE4MtlMS8nCmcLfWQ==');
  insert into member_base_secret(entity_id, secret_value) value ('72292516', 'M5UbeO83nhLil+KC6SQUmGIdOEVWABcWYnnDB1U5a9k=');
  insert into member_base_secret(entity_id, secret_value) value ('72292894', 'iXD4BEZutQqIbCMJ5FpMEw==');
  insert into member_base_secret(entity_id, secret_value) value ('72293498', 'hpU/Iv07bvjIfBuHbGrypg==');
  insert into member_base_secret(entity_id, secret_value) value ('72298802', 'xXxYNyJKnUAuEM0zuFDTyg==');
  insert into member_base_secret(entity_id, secret_value) value ('72298888', '6WLe71RL4vAOzPvCECJF+g==');
  insert into member_base_secret(entity_id, secret_value) value ('72300306', 'ivf4EqSFYhuxj+XT6PFOdA==');
  insert into member_base_secret(entity_id, secret_value) value ('72303812', 'R1PoeF34wWcs+ILaUIhgFQ==');
  insert into member_base_secret(entity_id, secret_value) value ('72304022', 'M5UbeO83nhLil+KC6SQUmGIdOEVWABcWYnnDB1U5a9k=');
  insert into member_base_secret(entity_id, secret_value) value ('72304033', 'ELTxYV9EitOEQn/+f1+bNQ==');
  insert into member_base_secret(entity_id, secret_value) value ('72309158', 'tJDDzo7YRzZ6aXwrSnzaoA==');
  insert into member_base_secret(entity_id, secret_value) value ('72309240', 'xSnknef6McrRawH09tJQPg==');
  insert into member_base_secret(entity_id, secret_value) value ('72309607', 'VKjtsyfJSXUmAb3q4t10QA==');
  insert into member_base_secret(entity_id, secret_value) value ('72309616', 'jwP0zQLhtYOiBqE1zy+EXw==');
  --dec $insert_loop_count
  --enable_query_log
  --enable_result_log
}
select count(*) from member_base_secret;

--echo #
--echo # Execute SQL statment and check check the meemory usage during the same time
--echo #
set @AES_KEY_VALUE='47fed2ba90324cd49f56a10e5fb80248';
set block_encryption_mode = 'aes-256-ecb';
--let $loop_count = 100

--connect(con0, localhost, root,,,,,)
--connect(con1, localhost, root,,,,,)
--connection con0
set sql_mode = '';
--send SELECT GROUP_CONCAT(b.entity_column, ':', b.secret_value, ':', PMS_DECRYPT(b.secret_value) SEPARATOR ';;') AS columnValue FROM member_base_secret b GROUP BY b.entity_id ORDER BY b.id ASC LIMIT 100;
--connection con1
while ($loop_count) {
  --send select current_alloc from sys.memory_global_by_current_bytes where event_name = 'memory/sql/THD::main_mem_root';
  --reap
  --dec $loop_count
  --sleep 1
}
--disable_query_log
--disable_result_log
connection con0;
--reap
--enable_query_log
--enable_result_log

--echo #
--echo # Clean up environment
--echo #
--source include/rpl_connection_master.inc
drop table member_base_secret;
drop function PMS_DECRYPT;
--source include/rpl_end.inc

Hi,

What isolation level are you using for test?
Have you tried different isolation levels?

I set transaction-isolation is REPEATABLE-READ, just now I set it to SERIALIZABLE, and meet the same problems

To ensure it's not the problem about transaction isolation, I tried the READ COMMITTED and READ UNCOMMITTED , but doesn't get better

Hi,

Thank you for the report and the test case. I'm still not 100% convinced this is a bug but I'm verifying this behavior as it is reproducible. We'll see what replication team can say about this.