MySQL Bugs: #81657: DBUG_PRINT in THD::decide_logging_format prints incorrectly, access out-of-bound

Bug #81657	DBUG_PRINT in THD::decide_logging_format prints incorrectly, access out-of-bound
Submitted:	31 May 2016 11:46	Modified:	23 Sep 2016 9:24
Reporter:	Laurynas Biveinis (OCA)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.5+	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	asan, debug

Description:
THD::decide_logging_format does

#ifndef DBUG_OFF
    {
      static const char *prelocked_mode_name[] = {
        "NON_PRELOCKED",
        "PRELOCKED",
        "PRELOCKED_UNDER_LOCK_TABLES",
      };
      DBUG_PRINT("debug", ("prelocked_mode: %s",
                           prelocked_mode_name[locked_tables_mode]));
    }
#endif

but the type of locked_tables_mode is

enum enum_locked_tables_mode
{
  LTM_NONE= 0,
  LTM_LOCK_TABLES,
  LTM_PRELOCKED,
  LTM_PRELOCKED_UNDER_LOCK_TABLES
};

resulting in incorrect printout and out-of-bound read if it is LTM_PRELOCKED_UNDER_LOCK_TABLES.

How to repeat:
This shows up as an ASan error on 5.5:
cmake ... -DWITH_DEBUG=ON -DWITH_ASAN=ON
...
./mtr --debug-server rpl_unsafe_statements
...
rpl.rpl_unsafe_statements 'mix'          [ fail ]
...
mysqltest: At line 54: query 'INSERT INTO t1(i) VALUES(3)' failed: 2013: Lost connection to MySQL server during query
...
=================================================================
==32732==ERROR: AddressSanitizer: global-buffer-overflow on address 0x000001a7fff8 at pc 0x0000005fc568 bp 0x7f11fccf6250 sp 0x7f11fccf6240
READ of size 8 at 0x000001a7fff8 thread T19
    #0 0x5fc567 in THD::decide_logging_format(TABLE_LIST*) /home/laurynas/mysql-server/sql/sql_class.cc:4406
    #1 0x5a5b94 in lock_tables(THD*, TABLE_LIST*, unsigned int, unsigned int) /home/laurynas/mysql-server/sql/sql_base.cc:5845
    #2 0x5bee36 in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /home/laurynas/mysql-server/sql/sql_base.cc:5571
    #3 0x6324a5 in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /home/laurynas/mysql-server/sql/sql_base.h:500
    #4 0x6324a5 in mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool) /home/laurynas/mysql-server/sql/sql_insert.cc:714
    #5 0x67025f in mysql_execute_command(THD*) /home/laurynas/mysql-server/sql/sql_parse.cc:2938
    #6 0x67be42 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /home/laurynas/mysql-server/sql/sql_parse.cc:5780
    #7 0x67f74a in dispatch_command(enum_server_command, THD*, char*, unsigned int) /home/laurynas/mysql-server/sql/sql_parse.cc:1038
    #8 0x683df9 in do_command(THD*) /home/laurynas/mysql-server/sql/sql_parse.cc:773
    #9 0x86c6b6 in do_handle_one_connection(THD*) /home/laurynas/mysql-server/sql/sql_connect.cc:862
    #10 0x86c8db in handle_one_connection /home/laurynas/mysql-server/sql/sql_connect.cc:781
    #11 0xd53f20 in pfs_spawn_thread /home/laurynas/mysql-server/storage/perfschema/pfs.cc:1015
    #12 0x7f12092b06f9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76f9)
    #13 0x7f120895bb5c in clone (/lib/x86_64-linux-gnu/libc.so.6+0x106b5c)

0x000001a7fff8 is located 40 bytes to the left of global variable 'DEFAULT_WHERE' defined in '/home/laurynas/mysql-server/sql/sql_class.cc:71:20' (0x1a80020) of size 8
0x000001a7fff8 is located 0 bytes to the right of global variable 'prelocked_mode_name' defined in '/home/laurynas/mysql-server/sql/sql_class.cc:4401:26' (0x1a7ffe0) of size 24
SUMMARY: AddressSanitizer: global-buffer-overflow /home/laurynas/mysql-server/sql/sql_class.cc:4406 THD::decide_logging_format(TABLE_LIST*)
Shadow bytes around the buggy address:
  0x000080347fa0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x000080347fb0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x000080347fc0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x000080347fd0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x000080347fe0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x000080347ff0: 00 00 00 00 00 00 00 00 f9 f9 f9 f9 00 00 00[f9]
  0x000080348000: f9 f9 f9 f9 00 f9 f9 f9 f9 f9 f9 f9 00 00 00 00
  0x000080348010: 00 00 00 00 f9 f9 f9 f9 00 00 f9 f9 f9 f9 f9 f9
  0x000080348020: 00 00 f9 f9 f9 f9 f9 f9 00 00 00 00 00 00 00 00
  0x000080348030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x000080348040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Heap right redzone:      fb
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack partial redzone:   f4
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
Thread T19 created by T0 here:
    #0 0x7f1209b3a253 in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.2+0x36253)
    #1 0xd574dd in spawn_thread_v1 /home/laurynas/mysql-server/storage/perfschema/pfs.cc:1038
    #2 0x511e52 in inline_mysql_thread_create /home/laurynas/mysql-server/include/mysql/psi/mysql_thread.h:1049
    #3 0x511e52 in create_thread_to_handle_connection(THD*) /home/laurynas/mysql-server/sql/mysqld.cc:5070
    #4 0x51331c in create_new_thread /home/laurynas/mysql-server/sql/mysqld.cc:5162
    #5 0x51331c in handle_connections_sockets() /home/laurynas/mysql-server/sql/mysqld.cc:5424
    #6 0x51686c in mysqld_main(int, char**) /home/laurynas/mysql-server/sql/mysqld.cc:4686
    #7 0x4ff8ae in main /home/laurynas/mysql-server/sql/main.cc:25
    #8 0x7f120887582f in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2082f)

==32732==ABORTING

Suggested fix:
Sync THD::decide_logging_format DBUG_PRINT with the enum

Bug 81657 fix for 5.5 (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug81657-5.5.patch (application/octet-stream, text), 613 bytes.

Hello Laurynas,

Thank you for the report and contribution.

Thanks,
Umesh

Posted by developer:
 
Seems to be related to internals only, so closing without change log entry.

David, user visible consequences could have been possible.

On second thought, that may have been in debug only. Ignore me :)

The fix is broken in 5.6, see bug 83124