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:
None 
Category:MySQL Server: Stored Routines Severity:S2 (Serious)
Version:8.0 OS:Any
Assigned to: CPU Architecture:Any

[25 Jun 2021 18:39] Kaiwang CHen
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).
[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: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!