| Bug #104115 | Digest user functions pollute current THD | ||
|---|---|---|---|
| Submitted: | 25 Jun 2021 18:39 | Modified: | 25 Jul 2021 10:39 |
| Reporter: | Kaiwang CHen (OCA) | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: Stored Routines | Severity: | S2 (Serious) |
| Version: | 8.0 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[30 Jun 2021 12:39]
MySQL Verification Team
Hi Mr. CHen, Thank you for your bug report. We must confirm that your report sounds very interesting. However, your report is not complete. First of all, we would like you to check your findings on the release 8.0.25 or on the basis of the latest pull from the GitHub. Next, you should provide detailed info on the bad consequences of not abiding by C++ RAII rules in our code. Namely, please explain in detail the bad consequences of our coding and, especially, how would those consequences impact the end user or their application. Good programming rules are good to follow, but not following them, in itself, does not represent a bug.
[1 Jul 2021 5:04]
Kaiwang CHen
Yes, in 8.0.25 it is still has problem:
Thd_parse_modifier(THD *thd, uchar *token_buffer)
: m_thd(thd),
m_arena(&m_mem_root, Query_arena::STMT_REGULAR_EXECUTION),
m_backed_up_lex(thd->lex),
m_saved_parser_state(thd->m_parser_state),
m_saved_digest(thd->m_digest),
m_cs(thd->variables.character_set_client) {
thd->m_digest = &m_digest_state;
m_digest_state.reset(token_buffer, get_max_digest_length());
m_arena.set_query_arena(*thd);
thd->lex = &m_lex;
lex_start(thd);
}
~Thd_parse_modifier() {
lex_end(&m_lex);
m_thd->lex = m_backed_up_lex;
m_thd->set_query_arena(m_arena);
m_thd->m_parser_state = m_saved_parser_state;
m_thd->m_digest = m_saved_digest;
m_thd->variables.character_set_client = m_cs;
m_thd->update_charset();
}
In commit ef1ef59f2 there was a change in construction, but it did not fix the problem (switch arena) in discussion.
- m_arena.set_query_arena(thd);
- thd->set_query_arena(&m_arena);
+ m_arena.set_query_arena(*thd);
In community code itself, it does not have so bad impact because it is used only in the digest functions which only do parsing.
However, we tried to use the class to do some parsing and processing temporarily, we had new Item_int objects and called Item_int::print() which allocated memory in Item::str_value, and since arena was not switched and the free list lost new items, these new item objects were not destructed thus memory leaks in a busy use case.
BTW, Item_int::print() was fixed with Bug#28753556: IMPROVE CONST-NESS OF PRINT() FUNCTIONS. However, I guess missed item destruction could still cause leaks in corner cases.
[1 Jul 2021 5:14]
Kaiwang CHen
BTW, in commit 28614646 the free list was renamed to Query_arena::m_item_list linked by Item::next_free, which had been Query_arena::free_list linked by Item::next.
[1 Jul 2021 11:25]
MySQL Verification Team
Hi, Can you prove your point by some memory analysing / checking tool ??? We will gladly accept such a result, because, so far you have not provided any evidence of the memory leak. We would, very much, like to verify this report, provided you send us the desired info and analytic proof. Waiting on your feedback.
[1 Jul 2021 18:24]
Kaiwang CHen
I have memory leak as follows (two private frames #13 #14 omitted). However, I failed to reproduce the same leak in the digest function. I am not sure about the difference between private context and the digest function (stored program) execution context.
I will report back when I get a good case to prove it. A few weeks later, maybe. Sorry for the leaving.
The test query is: CALL private_proc("SELECT col1 FROM t1 WHERE col2 = 0")
Direct leak of 56 byte(s) in 1 object(s) allocated from:
#0 0x7f63e583a8a0 in malloc (/lib64/libasan.so.4+0xde8a0)
#1 0x5833ffd in my_raw_malloc mysys/my_malloc.cc:199
#2 0x5834153 in my_malloc(unsigned int, unsigned long, int) mysys/my_malloc.cc:81
#3 0x368a39b in String::real_alloc(unsigned long) sql-common/sql_string.cc:54
#4 0x31a1acd in String::alloc(unsigned long) include/sql_string.h:374
#5 0x368a850 in String::set_int(long long, bool, CHARSET_INFO const*) sql-common/sql_string.cc:172
#6 0x3a98cc0 in Item_int::print(String*, enum_query_type) sql/item.cc:3028
#7 0x3baad0a in Item_func::print_op(String*, enum_query_type) sql/item_func.cc:482
#8 0x3b252ee in Item_bool_func2::print(String*, enum_query_type) sql/item_cmpfunc.h:512
#9 0x3228325 in SELECT_LEX::print_where_cond(String*, enum_query_type) sql/sql_lex.cc:3318
#10 0x32336ba in SELECT_LEX::print_select(THD*, String*, enum_query_type) sql/sql_lex.cc:2941
#11 0x3233dcf in SELECT_LEX::print(THD*, String*, enum_query_type) sql/sql_lex.cc:2914
#12 0x3233f19 in SELECT_LEX_UNIT::print(String*, enum_query_type) sql/sql_lex.cc:2567
... two frames for hacking CALL and using similar logic as parse() for digest function ...
#15 0x359f3d4 in im::Sql_cmd_proc::execute(THD*) sql/package/proc.cc:200
#16 0x329f211 in mysql_execute_command(THD*, bool) sql/sql_parse.cc:4890
#17 0x32a1d52 in mysql_parse(THD*, Parser_state*, bool) sql/sql_parse.cc:5715
#18 0x32a4861 in dispatch_command(THD*, COM_DATA const*, enum_server_command) sql/sql_parse.cc:1871
#19 0x32a7963 in do_command(THD*, std::function<bool (THD*, COM_DATA const*, enum_server_command)>*) sql/sql_parse.cc:1333
#20 0x32a7a58 in do_command(THD*) sql/sql_parse.cc:1370
#21 0x3690dc2 in handle_connection sql/conn_handler/connection_handler_per_thread.cc:316
#22 0x64c9bce in pfs_spawn_thread storage/perfschema/pfs.cc:2879
#23 0x7f63e5547e24 in start_thread (/lib64/libpthread.so.0+0x7e24)
[2 Jul 2021 11:21]
MySQL Verification Team
Hi Sinisa, I in fact do get memory leaks so reporter might be right, although I'm unsure of the exact queries that lead to it.
I did this:
mysql> create procedure do_digest(a longblob) select statement_digest(a);
Query OK, 0 rows affected (0.04 sec)
Then ran millions of CALL do_digest("<random SQL query>");
and some of them must have leaked:
Server] mysqld: Shutdown complete (mysqld 8.0.27-tr-asan) (Built on 29 June 2021, commit 232cbed5ca965684df13e68081ac1d5f52dcb4e5 with gcc (GCC) 11.1.1 20210531 (Red Hat 11.1.1-3)).
=================================================================
==483315==ERROR: LeakSanitizer: detected memory leaks
Direct leak of 128 byte(s) in 2 object(s) allocated from:
#0 0x7f0dbcd4b93f in __interceptor_malloc (/lib64/libasan.so.6+0xae93f)
#1 0x2548f4f in my_raw_malloc ./mysys/my_malloc.cc:198
#2 0x2549002 in my_malloc(unsigned int, unsigned long, int) ./mysys/my_malloc.cc:81
#3 0xe91ccc in String::mem_realloc(unsigned long, bool) ./sql-common/sql_string.cc:121
#4 0xe91e99 in String::mem_realloc_exp(unsigned long) ./sql-common/sql_string.cc:163
#5 0xe92855 in String::append(char const*, unsigned long) ./sql-common/sql_string.cc:479
#6 0xf0bfb9 in Item_string::append(char*, unsigned long) ./sql/item.h:5194
#7 0x14c5716 in PTI_text_literal_concat::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:513
#8 0x14b4f68 in PTI_expr_with_alias::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:335
#9 0xeeb317 in PT_item_list::contextualize(Parse_context*) ./sql/parse_tree_helpers.h:112
...
Direct leak of 128 byte(s) in 1 object(s) allocated from:
#0 0x7f0dbcd4b93f in __interceptor_malloc (/lib64/libasan.so.6+0xae93f)
#1 0x2548f4f in my_raw_malloc ./mysys/my_malloc.cc:198
#2 0x2549002 in my_malloc(unsigned int, unsigned long, int) ./mysys/my_malloc.cc:81
#3 0xe91ccc in String::mem_realloc(unsigned long, bool) ./sql-common/sql_string.cc:121
#4 0xe91e99 in String::mem_realloc_exp(unsigned long) ./sql-common/sql_string.cc:163
#5 0xe92855 in String::append(char const*, unsigned long) ./sql-common/sql_string.cc:479
#6 0xf0bfb9 in Item_string::append(char*, unsigned long) ./sql/item.h:5194
#7 0x14c5716 in PTI_text_literal_concat::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:513
#8 0x14d5e2d in PTI_odbc_date::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:618
#9 0x14b27f0 in PTI_context::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:710
...
Direct leak of 104 byte(s) in 2 object(s) allocated from:
#0 0x7f0dbcd4b93f in __interceptor_malloc (/lib64/libasan.so.6+0xae93f)
#1 0x2548f4f in my_raw_malloc ./mysys/my_malloc.cc:198
#2 0x2549002 in my_malloc(unsigned int, unsigned long, int) ./mysys/my_malloc.cc:81
#3 0xe91ccc in String::mem_realloc(unsigned long, bool) ./sql-common/sql_string.cc:121
#4 0xe91e99 in String::mem_realloc_exp(unsigned long) ./sql-common/sql_string.cc:163
#5 0xe92855 in String::append(char const*, unsigned long) ./sql-common/sql_string.cc:479
#6 0xf0bfb9 in Item_string::append(char*, unsigned long) ./sql/item.h:5194
#7 0x14c5716 in PTI_text_literal_concat::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:513
#8 0x14b27f0 in PTI_context::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:710
#9 0x14d7f19 in PT_update::make_cmd(THD*) ./sql/parse_tree_nodes.cc:846
...
Direct leak of 48 byte(s) in 1 object(s) allocated from:
#0 0x7f0dbcd4b93f in __interceptor_malloc (/lib64/libasan.so.6+0xae93f)
#1 0x2548f4f in my_raw_malloc ./mysys/my_malloc.cc:198
#2 0x2549002 in my_malloc(unsigned int, unsigned long, int) ./mysys/my_malloc.cc:81
#3 0x254c2b7 in my_realloc(unsigned int, void*, unsigned long, int) ./mysys/my_malloc.cc:110
#4 0xe91c5f in String::mem_realloc(unsigned long, bool) ./sql-common/sql_string.cc:118
#5 0xe91e99 in String::mem_realloc_exp(unsigned long) ./sql-common/sql_string.cc:163
#6 0xe92855 in String::append(char const*, unsigned long) ./sql-common/sql_string.cc:479
#7 0xf0bfb9 in Item_string::append(char*, unsigned long) ./sql/item.h:5194
#8 0x14c5716 in PTI_text_literal_concat::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:513
#9 0x14b27f0 in PTI_context::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:710
...
Direct leak of 48 byte(s) in 1 object(s) allocated from:
#0 0x7f0dbcd4b93f in __interceptor_malloc (/lib64/libasan.so.6+0xae93f)
#1 0x2548f4f in my_raw_malloc ./mysys/my_malloc.cc:198
#2 0x2549002 in my_malloc(unsigned int, unsigned long, int) ./mysys/my_malloc.cc:81
#3 0xe91ccc in String::mem_realloc(unsigned long, bool) ./sql-common/sql_string.cc:121
#4 0xe91e99 in String::mem_realloc_exp(unsigned long) ./sql-common/sql_string.cc:163
#5 0xe92855 in String::append(char const*, unsigned long) ./sql-common/sql_string.cc:479
#6 0xf0bfb9 in Item_string::append(char*, unsigned long) ./sql/item.h:5194
#7 0x14c5716 in PTI_text_literal_concat::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:513
#8 0xeeb317 in PT_item_list::contextualize(Parse_context*) ./sql/parse_tree_helpers.h:112
#9 0x14d7dcb in PT_update::make_cmd(THD*) ./sql/parse_tree_nodes.cc:827
...
Direct leak of 48 byte(s) in 1 object(s) allocated from:
#0 0x7f0dbcd4b93f in __interceptor_malloc (/lib64/libasan.so.6+0xae93f)
#1 0x2548f4f in my_raw_malloc ./mysys/my_malloc.cc:198
#2 0x2549002 in my_malloc(unsigned int, unsigned long, int) ./mysys/my_malloc.cc:81
#3 0xe91ccc in String::mem_realloc(unsigned long, bool) ./sql-common/sql_string.cc:121
#4 0xe91e99 in String::mem_realloc_exp(unsigned long) ./sql-common/sql_string.cc:163
#5 0xe92855 in String::append(char const*, unsigned long) ./sql-common/sql_string.cc:479
#6 0xf0bfb9 in Item_string::append(char*, unsigned long) ./sql/item.h:5194
#7 0x14c5716 in PTI_text_literal_concat::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:513
#8 0x14a3ea4 in PTI_comp_op::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:166
#9 0x14b27f0 in PTI_context::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:710
...
Direct leak of 40 byte(s) in 1 object(s) allocated from:
#0 0x7f0dbcd4b93f in __interceptor_malloc (/lib64/libasan.so.6+0xae93f)
#1 0x2548f4f in my_raw_malloc ./mysys/my_malloc.cc:198
#2 0x2549002 in my_malloc(unsigned int, unsigned long, int) ./mysys/my_malloc.cc:81
#3 0xe91ccc in String::mem_realloc(unsigned long, bool) ./sql-common/sql_string.cc:121
#4 0xe91e99 in String::mem_realloc_exp(unsigned long) ./sql-common/sql_string.cc:163
#5 0xe92855 in String::append(char const*, unsigned long) ./sql-common/sql_string.cc:479
#6 0xf0bfb9 in Item_string::append(char*, unsigned long) ./sql/item.h:5194
#7 0x14c5716 in PTI_text_literal_concat::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:513
#8 0x1237290 in Item_func::itemize(Parse_context*, Item**) ./sql/item_func.cc:347
#9 0x14d11aa in PTI_truth_transform::itemize(Parse_context*, Item**) ./sql/parse_tree_items.cc:473
...
[2 Jul 2021 11:29]
MySQL Verification Team
Hi Mr. CHen, There is no problem, what so ever. When you have resolved exactly what is going on and have anything concrete, just write a comment in this report and we shall react immediately.
[2 Jul 2021 11:39]
MySQL Verification Team
Here's a sample testcase that leaks memory...
mysql> select statement_digest(" select `t0034` into @b where grouping(day(_gb18030 '$7*' '] AF7~<$D# *)#^FE *& %4<B $] C@~b!$: */ ' '*:!F[.*D' '! !$ ' ) )") ;
+-------------------------------------------------------------------------------------------------------------------------------------------------+
| statement_digest(" select `t0034` into @b where grouping(day(_gb18030 '$7*' '] AF7~<$D# *)#^FE *& %4<B $] C@~b!$: */ ' '*:!F[.*D' '! !$ ' ) )") |
+-------------------------------------------------------------------------------------------------------------------------------------------------+
| e574adef4a901720e13db3296f6a4867d4836e0a4c34886fe5584bc4ae9350cb |
+-------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
[2 Jul 2021 11:55]
MySQL Verification Team
Hi Mr. CHen, There are some good news. One of our colleagues managed to repeat the memory link, with sufficient proof that digest functions do leak some memory. Verified for the version 8.0. The code in version 5.7 does not have all those functions. Done.
[25 Jul 2021 10:39]
Kaiwang CHen
Great!
[25 Jul 2021 10:39]
Kaiwang CHen
Great!
[5 May 13:54]
Dyre Tjeldvoll
Posted by developer: Thank you for the bug report and excellent analysis. A fix has been pushed to mysql-trunk and we expect it to be available in the 10.0, 9.7.1, and 8.4.10 releases.
Description: Digest user functions, statement_digest() and statement_digest_text(), do parsing in the current thd's query arena, which is not expected. For example, Item_func_statement_digest::val_str_ascii() does: THD *thd = current_thd; Thd_parse_modifier thd_mod(thd, m_token_buffer); if (parse(thd, args[0], statement_string)) ... compute_digest_hash(&thd->m_digest->m_digest_storage, digest); The RAII class Thd_parse_modifier is supposed to switch to a temporary arena, but it fails to do so in current implementation. In construction, it only saves the arena, however, thd arena is not switched. In destruction, it sets back to the same thing, which is effectively a noop. // construction m_arena.set_query_arena(*thd); // destruction m_thd->set_query_arena(m_arena); How to repeat: Test query: select statement_digest("select 9"); Set breakpoint at Item_func_statement_digest::val_str_ascii() and check thd->free_list when Thd_parse_modifier takes effect. New items from the embedded argument query will be prepended to thd->free_list and the list is reset to the old head at the end of Thd_parse_modifier scope. Set breakpoint at MEM_ROOT::Alloc(), and observe that in Thd_parse_modifier scope, memory allocation is from the old thd->mem_root rather than Thd_parse_modifier::m_mem_root. Suggested fix: Use a temporary call arena and a backup arena as in sp_head::execute_trigger(): MEM_ROOT call_mem_root; Query_arena call_arena(&call_mem_root, Query_arena::STMT_INITIALIZED_FOR_SP); Query_arena backup_arena; // switch thd->swap_query_arena(call_arena, &backup_arena); // restore thd->swap_query_arena(backup_arena, &call_arena); call_arena.free_items(); free_root(&call_mem_root, MYF(0)); In old code, they are set_n_backup_active_arena() and restore_active_arena(). Besides, Thd_parse_modifier should also take over switching parser state and client character set, which is currently handled in parse(). Some old code might rely on current_thd, so it may be switched as well (not sure).