Windows Tools for MySQL DBAs: Basic Minidump Analysis

"To a man with a hammer, everything looks like a nail."

Even though I had written many posts explaining the use of gdb for various MySQL-related tasks, I have to use other OS level troubleshooting tools from time to time. Moreover, as MySQL and MariaDB are still supported and used under Microsoft Windows in production by customers I have to serve them there, and use Windows-specific tools sometimes. So, I decided to start a series of posts (that I promised to my great colleague Vladislav Vaintroub (a.k.a Wlad) who helped me a lot over years and actually switched my attention from Performance Schema towards debuggers) about different Windows tools for MySQL DBAs (and support engineers).

Developers (and maybe even power users) on Windows probably know all I plan to describe and way more, by heart, but for me many things were not obvious and took some time to search, try or even ask for some advises... So, this series of posts is going to be useful at least for me (and mostly UNIX users, like me), as a source of hints and links that may save me some time and efforts in the future.

In this first post I plan to describe basic installation of "Debugging Tools for Windows" and use of cdb command line debugger to analyze minidumps (that one gets on Windows upon crashes when core-file option is added to my.ini and may get for hanging mysqld.exe process with minimal efforts using different tools) and get backtraces and few other details from them. I also plan to show simple command lines to share with DBAs and users whom you help, that allow to get useful details (more or less full backtraces, crash analysis, OS details etc) for further troubleshooting when/if dumps can not or should not be shared.

---

I have to confess: I use Microsoft Windows on desktops and laptops. I started from Windows 3.0 back in 1992 and ended with Windows 10 on my wife's laptop. I use Windows even for work. Today 2 of my 4 machines used for work-related tasks run Windows (64-bit XP on old Dell box I've got from MySQL AB back in 2005 and 64-bit Windows 7 on this Acer netbook). At the same time, most of work I have to do since 1992 is related to UNIX of all kinds (from Xenix and SCO OpenDesktop that I connected to from VT220 terminal in at my first job after the university, to recent Linux versions used by customers in production, my Fedora 27 box and Ubuntu 14.04 netbook used as build, Docker, VirtualBox, testing, benchmarking etc servers). I had never become a real powerful user of Windows (no really complex .bat files, PowerShell programming or even Basic macros in Word, domains, shadow copy services usage for backups, nothing fancy). But on UNIX I had to master shell, vi :), some Perl and a lot of command line tools.

I had to do some software development on Windows till 2005, built MySQL on Windows sometimes up to 2012 when I joined Percona (that had nothing to do with Windows at all), so I have old version of Visual Studio, some older WinDbg and other debugging tools here and there, but had not used them more than once a year, until recently... Last time I attached WinDbg to anything MySQL-related it was MariaDB 10.1.13, during some troubleshooting related to MDEV-10191.

Suddenly in March I've got issues from customers related to hanging upon startup/InnoDB recovery and under load, and crashing while using some (somewhat exotic) storage engine, all these - on modern versions of Microsoft Windows, in production. I had no other option but to get and study backtraces (of all threads or crashing threads) and check source code. It would be so easy to get them on Linux (just ask them to install gdb , attach it to hanging mysqld process or point out to the mysqld binary and core, and get the output of thread apply all backtrace, minor details aside). But how to do this on Winsdows, in command line if possible (as I hate to share screenshots and write long explanations on where to click and what to copy/paste)? I had to check in WinDbg, get some failures because of my outdated and incomplete environment (while customer with proper environment provided useful outputs anyway), then, eventually, asked Wlad for some help. Eventually I was able to make some progress.

To be ready to do this again next time with confidence, proper test environment and without wasting anybody else's time, I decided to repeat some of these efforts in clean environment and make notes, that I am going to share in this series of blog posts. Today I'll concentrate on installing current "Debugging Tools for Windows" and using cdb from them to process minidumps.

1. Installing "Debugging Tools for Windows"

There is a nice, easy to find document from Microsoft on how to get cdb and other debugging tools for Windows. For recent versions you just have to download Windows 10 SDK and then install these tools (and everything else you may need) from it. Proceed to this page, read the details, click on "Download .EXE" to get winsdksetup.exe , start it and select "Debugging Tools for Windows" when requested to select the features. Eventually you'll get some 416+ MB downloaded and installed by default in C:\Program Files (x86)\Windows Kits\10\Debuggers\. (on default 64-bit Windows installation with C: as system disk). Quick check shows I have everything I need:

C:\Program Files (x86)\Windows Kits\10\Debuggers\x64>dir
...
11/10/2017  11:55 PM           154,936 cdb.exe
...
11/10/2017  11:55 PM           576,312 windbg.exe
...

Here is the list of most useful cdb options for the next step:

C:\Program Files (x86)\Windows Kits\10\Debuggers\x64>cdb /?
cdb version 10.0.16299.91
usage: cdb [options]

Options:

  <command-line> command to run under the debugger
  -? displays command line help text
...
  -i <ImagePath> specifies the location of the executables that generated the
                 fault (see _NT_EXECUTABLE_IMAGE_PATH)
...
  -lines requests that line number information be used if present
...
  -logo <logfile> opens a new log file
...
  -p <pid> specifies the decimal process ID to attach to
...
  -pv specifies that any attach should be noninvasive
...
  -y <SymbolsPath> specifies the symbol search path (see _NT_SYMBOL_PATH)
  -z <CrashDmpFile> specifies the name of a crash dump file to debug
...
Environment Variables:

    _NT_SYMBOL_PATH=[Drive:][Path]
        Specify symbol image path.
...
Control Keys:

     <Ctrl-B><Enter> Quit debugger
...

Remember Crtl-B key combination as a way to quit from cdb. I looked as funny as the beginner vi user few times, clicking on everything to get out of that tool...

2. Basic Use of cdb to Process Minidump

Let's assume you've got mysqld.dmp minidump file (a kind of "core" file on UNIX, but better, at least smaller usually) created during some crash. Depending on binaries used, you may need to make sure you have .PDB files in some directory, for the mysqld.exe binary and all .dll files for plugins/extra storage engines used, in some directory. Default path to .PDB files is defined by the _NT_SYMBOL_PATH environment variable and may include multiple directories ad URLs.

Initially I've got advice to set this environment variable as follows:

set _NT_SYMBOL_PATH=srv*c:\symbols*http://msdl.microsoft.com/download/symbols

This assumes that I have a collection of .PDB files in c:\symbols on some locally available server and rely on Microsoft's symbols server for the rest. For anything missing we can always add -y option to point to some directory with additional .PDB files. Note that MariaDB provides .pdb files along with .exe in .msi installer, not only in .zip file with binaries.

So, if your mysqld.dmp file is located in h:\, mysqld.exe for the same version as generated that minidump is located in p:\software and all related .dll files and .pdb files for them all are also there, the command to get basic details about the crash in file h:\out.txt would be the following:

cdb -z h:\mysqld.dmp -i p:\software -y p:\software -logo h:\out.txt -c "!sym prompts;.reload;.ecxr;q"

You can click on every option underlined above to get details. It produces output like this:

C:\Program Files (x86)\Windows Kits\10\Debuggers\x64>cdb -z h:\mysqld.dmp -i p:\
software -y p:\software -logo h:\out.txt -c "!sym prompts;.reload;.ecxr;q"

Microsoft (R) Windows Debugger Version 10.0.16299.91 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [h:\mysqld.dmp]
User Mini Dump File: Only registers, stack and portions of memory are available


************* Path validation summary **************
Response                         Time (ms)     Location
OK                                             p:\software

************* Path validation summary **************
Response                         Time (ms)     Location
OK                                             p:\software
Deferred                                       srv*c:\symbols*http://msdl.micros
oft.com/download/symbols
Symbol search path is: p:\software;srv*c:\symbols*http://msdl.microsoft.com/down
load/symbols
Executable search path is: p:\software
Windows 10 Version 14393 MP (4 procs) Free x64
Product: Server, suite: TerminalServer SingleUserTS
10.0.14393.206 (rs1_release.160915-0644)
Machine Name:
Debug session time: ...
System Uptime: not available
Process Uptime: 0 days X:YY:ZZ.000
............................................
This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(1658.fd0): Access violation - code c0000005 (first/second chance not available)

ntdll!NtGetContextThread+0x14:
00007fff`804a7d84 c3              ret
0:053> cdb: Reading initial command '!sym prompts;.reload;.ecxr;q'
quiet mode - symbol prompts on
............................................
rax=0000000000000000 rbx=0000000000000000 rcx=0000000000000006
rdx=000001cf0ac2e118 rsi=000001cf0abeeef8 rdi=000001cf0ac2e118
rip=00007fff5f313b0d rsp=000000653804e2b0 rbp=000001cf165c9cc8
 r8=0000000000000000  r9=00007fff5f384448 r10=000000653804ef70
r11=000000653804eb28 r12=0000000000000000 r13=000001cf0ab49d48
r14=0000000000000000 r15=000001cf0b083028
iopl=0         nv up ei pl zr na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010246
ha_spider!spider_db_connect+0xdd:
00007fff`5f313b0d 8b1498          mov     edx,dword ptr [rax+rbx*4] ds:00000000`
00000000=????????quit:

C:\Program Files (x86)\Windows Kits\10\Debuggers\x64>

that also goes to the file pointed out by the -logo option. Here we have some weird crash in Spider engine of MariaDB that  is not a topic of current post.

If you think the crash is related to some activity of other threads, you can get all unique stack dumps with the following options:

cdb -lines -z h:\mysqld.dmp -i p:\software -y p:\software -logo h:\out.txt -c "!sym prompts;.reload;!uniqstack -p;q"

This is how the backtrace of slave SQL thread may look like, note files with line numbers for each frame (-lines option):

. 44  Id: 1658.1584 Suspend: 0 Teb: 00000065`32185000 Unfrozen
      Priority: 0  Priority class: 32
Child-SP          RetAddr           Call Site
00000065`353fed08 00007fff`8046d119 ntdll!NtWaitForAlertByThreadId+0x14
00000065`353fed10 00007fff`7cbd8d78 ntdll!RtlSleepConditionVariableCS+0xc9
00000065`353fed80 00007ff6`2d7d62e7 KERNELBASE!SleepConditionVariableCS+0x28
00000065`353fedb0 00007ff6`2d446c8e mysqld!pthread_cond_timedwait(struct _RTL_CO
NDITION_VARIABLE * cond = 0x000001ce`66805688, struct _RTL_CRITICAL_SECTION * mu
tex = 0x000001ce`668051b8, struct timespec * abstime = <Value unavailable error>
)+0x27 [d:\winx64-packages\build\src\mysys\my_wincond.c @ 85]
(Inline Function) --------`-------- mysqld!inline_mysql_cond_wait+0x61 [d:\winx6
4-packages\build\src\include\mysql\psi\mysql_thread.h @ 1149]
00000065`353fede0 00007ff6`2d4b1718 mysqld!MYSQL_BIN_LOG::wait_for_update_relay_
log(class THD * thd = <Value unavailable error>)+0xce [d:\winx64-packages\build\
src\sql\log.cc @ 8055]
00000065`353fee90 00007ff6`2d4af03f mysqld!next_event(struct rpl_group_info * rg
i = 0x000001ce`667fe560, unsigned int64 * event_size = 0x00000065`353ff008)+0x2b
8 [d:\winx64-packages\build\src\sql\slave.cc @ 7148]
00000065`353fef60 00007ff6`2d4bb038 mysqld!exec_relay_log_event(class THD * thd
= 0x000001ce`6682ece8, class Relay_log_info * rli = 0x000001ce`66804d58, struct
rpl_group_info * serial_rgi = 0x000001ce`667fe560)+0x8f [d:\winx64-packages\buil
d\src\sql\slave.cc @ 3866]
00000065`353ff000 00007ff6`2d7d35cb mysqld!handle_slave_sql(void * arg = 0x00000
1ce`66803430)+0xa28 [d:\winx64-packages\build\src\sql\slave.cc @ 5145]
00000065`353ff780 00007ff6`2d852d51 mysqld!pthread_start(void * p = <Value unava
ilable error>)+0x1b [d:\winx64-packages\build\src\mysys\my_winthread.c @ 62]
(Inline Function) --------`-------- mysqld!invoke_thread_procedure+0xe [d:\th\mi
nkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 91]
00000065`353ff7b0 00007fff`80338364 mysqld!thread_start<unsigned int (void * par
ameter = 0x00000000`00000000)+0x5d [d:\th\minkernel\crts\ucrt\src\appcrt\startup
\thread.cpp @ 115]
00000065`353ff7e0 00007fff`804670d1 kernel32!BaseThreadInitThunk+0x14
00000065`353ff810 00000000`00000000 ntdll!RtlUserThreadStart+0x21

For crash analysis usually !analyze command is also used:

cdb -lines -z h:\mysqld.dmp -i p:\software -y p:\software -logo h:\out.txt -c "!sym prompts;.reload;!analyze -v;q"

It may give some details about the exception happened:

...

FAULTING_IP:
ha_spider!spider_db_connect+dd00007fff`5f313b0d 8b1498          mov     edx,dword ptr [rax+rbx*4]

EXCEPTION_RECORD:  (.exr -1)
ExceptionAddress: 00007fff5f313b0d (ha_spider!spider_db_connect+0x00000000000000
dd)
   ExceptionCode: c0000005 (Access violation)
  ExceptionFlags: 00000000
NumberParameters: 2
   Parameter[0]: 0000000000000000
   Parameter[1]: 0000000000000000
Attempt to read from address 0000000000000000
DEFAULT_BUCKET_ID:  NULL_POINTER_READ

PROCESS_NAME:  mysqld.exe

ERROR_CODE: (NTSTATUS) 0xc0000005 - <Unable to get error code text>

...

STACK_TEXT:
00000065`3804e2b0 00007fff`5f3132ad : 00000000`00000000 000001cf`1741ab68 000001
cf`0b083028 000001cf`0ac2e118 : ha_spider!spider_db_connect+0xdd
00000065`3804e330 00007fff`5f3117f8 : 000001ce`669107c8 000001cf`0ac2e118 000001
cf`1741ab68 00000000`00000001 : ha_spider!spider_db_conn_queue_action+0xad
00000065`3804ea20 00007fff`5f31a1ee : 00000000`00000000 000001cf`0abeeef8 000000
00`00000000 000001cd`c0b30000 : ha_spider!spider_db_before_query+0x108
00000065`3804eaa0 00007fff`5f31a0bf : 00000000`00000000 00000000`00000000 000000
65`3804ec70 00000000`00000038 : ha_spider!spider_db_set_names_internal+0x11e
00000065`3804eb30 00007fff`5f369b4e : 00000000`00000000 00000065`3804ec70 00007f
ff`5f387f08 00000000`00000000 : ha_spider!spider_db_set_names+0x3f
00000065`3804eb70 00007fff`5f32f5f1 : 00000000`00000001 00000065`00000000 41cfff
ff`00000001 00000000`00000001 : ha_spider!spider_mysql_handler::show_table_statu
s+0x15e
00000065`3804ece0 00007fff`5f3222e8 : 00000000`00000001 00000065`00000000 000000
00`5ab175cd 000001cf`0b0886f8 : ha_spider!spider_get_sts+0x201
00000065`3804edb0 00007ff6`2d7d35cb : 00000000`00000057 000001cf`0ab49d48 000000
00`00000000 00007fff`5f321c10 : ha_spider!spider_bg_sts_action+0x6d8
00000065`3804fa30 00007ff6`2d852d51 : 000001cf`17008fe0 000001cf`0aa3fef0 000000
00`00000000 00000000`00000000 : mysqld!pthread_start+0x1b
00000065`3804fa60 00007fff`80338364 : 00000000`00000000 00000000`00000000 000000
00`00000000 00000000`00000000 : mysqld!thread_start<unsigned int (__cdecl*)(void
 * __ptr64)>+0x5d
00000065`3804fa90 00007fff`804670d1 : 00000000`00000000 00000000`00000000 000000
00`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0x14
00000065`3804fac0 00000000`00000000 : 00000000`00000000 00000000`00000000 000000
00`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

...

Finally (for this post), this is how we can get information about a crashing thread, including details about local variables (like full backtrace in gdb). We apply !for_each_frame extension and use dv to "display variable":

cdb -z h:\mysqld.dmp -i p:\software -y p:\software -logo h:\out.txt -c "!sym prompts;.reload;.ecxr;!for_each_frame dv /t;q"

The result will include details about each frame, parameters and local variables, like this:

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
00 00000065`3804e2b0 00007fff`5f3132ad ha_spider!spider_db_connect+0xdd
struct st_spider_share * share = 0x000001cf`165c9cc8
struct st_spider_conn * conn = 0x000001cf`0ac2e118
int link_idx = 0n0
int error_num = <value unavailable>
class THD * thd = 0x000001cf`0abeeef8
int64 connect_retry_interval = <value unavailable>
int connect_retry_count = <value unavailable>
int64 tmp_time = <value unavailable>
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
01 00000065`3804e330 00007fff`5f3117f8 ha_spider!spider_db_conn_queue_action+0xa
d
struct st_spider_conn * conn = 0x000001cf`0ac2e118
int error_num = 0n0
char [1532] sql_buf = char [1532] ""
class spider_string sql_str = class spider_string
class spider_db_result * result = <value unavailable>
struct st_spider_db_request_key request_key = struct st_spider_db_request_key
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
02 00000065`3804ea20 00007fff`5f31a1ee ha_spider!spider_db_before_query+0x108
struct st_spider_conn * conn = 0x000001cf`0ac2e118
int * need_mon = 0x000001cf`1741ab68
int error_num = 0n0
bool tmp_mta_conn_mutex_lock_already = true
class ha_spider * spider = <value unavailable>
bool tmp_mta_conn_mutex_unlock_later = <value unavailable>
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
03 00000065`3804eaa0 00007fff`5f31a0bf ha_spider!spider_db_set_names_internal+0x
11e
struct st_spider_transaction * trx = 0x000001cf`0b083028
struct st_spider_share * share = 0x000001cf`0ab49d48
struct st_spider_conn * conn = 0x000001cf`0ac2e118
int all_link_idx = 0n0
int * need_mon = 0x000001cf`1741ab68
bool tmp_mta_conn_mutex_lock_already = true
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
04 00000065`3804eb30 00007fff`5f369b4e ha_spider!spider_db_set_names+0x3f
class ha_spider * spider = <value unavailable>
struct st_spider_conn * conn = <value unavailable>
int link_idx = <value unavailable>
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
05 00000065`3804eb70 00007fff`5f32f5f1 ha_spider!spider_mysql_handler::show_tabl
e_status+0x15e
class spider_mysql_handler * this = 0x000001cf`0a15dd00
int link_idx = 0n0
int sts_mode = 0n1
unsigned int flag = 1
int error_num = 0n1
struct st_spider_share * share = 0x000001cf`0ab49d48
struct st_spider_conn * conn = 0x000001cf`0ac2e118
class spider_db_result * res = <value unavailable>
unsigned int64 auto_increment_value = 0
unsigned int pos = 0
struct st_spider_db_request_key request_key = struct st_spider_db_request_key
struct st_spider_db_request_key request_key = struct st_spider_db_request_key
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
06 00000065`3804ece0 00007fff`5f3222e8 ha_spider!spider_get_sts+0x201
struct st_spider_share * share = 0x000001cf`0ab49d48
int link_idx = 0n0
int64 tmp_time = 0n1521579469
class ha_spider * spider = 0x00000065`3804ef70
double sts_interval = 10
int sts_mode = 0n1
int sts_sync = 0n0
int sts_sync_level = 0n2
unsigned int flag = 0x18
int error_num = <value unavailable>
int get_type = 0n1
struct st_spider_patition_handler_share * partition_handler_share = <value unava
ilable>
double tmp_sts_interval = <value unavailable>
struct st_spider_share * tmp_share = <value unavailable>
int tmp_sts_sync = <value unavailable>
class ha_spider * tmp_spider = <value unavailable>
int roop_count = <value unavailable>
int tmp_sts_mode = <value unavailable>
class THD * thd = <value unavailable>
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
07 00000065`3804edb0 00007ff6`2d7d35cb ha_spider!spider_bg_sts_action+0x6d8
void * arg = 0x000001cf`0ab49d48
int error_num = 0n0
class ha_spider spider = class ha_spider
unsigned int * conn_link_idx = 0x000001cf`1741ab78
unsigned char * conn_can_fo = 0x000001cf`1741ab80 "--- memory read error at addr
ess 0x000001cf`1741ab80 ---"
struct st_spider_conn ** conns = 0x000001cf`1741ab70
int * need_mons = 0x000001cf`1741ab68
int roop_count = 0n0
char ** conn_keys = 0x000001cf`1741ab88
class THD * thd = 0x000001cf`0abeeef8
class spider_db_handler ** dbton_hdl = 0x000001cf`1741ab90
struct st_spider_transaction * trx = 0x000001cf`0b083028
struct st_mysql_mutex spider_global_trx_mutex = <value unavailable>
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
08 00000065`3804fa30 00007ff6`2d852d51 mysqld!pthread_start+0x1b
void * p = <value unavailable>
void * arg = 0x000001cf`0ab49d48
<function> * func = 0x00007fff`5f321c10
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
09 (Inline Function) --------`-------- mysqld!invoke_thread_procedure+0xe
void * context = 0x000001cf`17008fe0
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
0a 00000065`3804fa60 00007fff`80338364 mysqld!thread_start<unsigned int (__cdecl
*)(void * __ptr64)>+0x5d
void * parameter = 0x00000000`00000000
<function> * procedure = 0x00007ff6`2d7d35b0
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
0b 00000065`3804fa90 00007fff`804670d1 kernel32!BaseThreadInitThunk+0x14
Unable to enumerate locals, Win32 error 0n87
Private symbols (symbols.pri) are required for locals.
Type ".hh dbgerr005" for details.
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
0c 00000065`3804fac0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
Unable to enumerate locals, Win32 error 0n87
Private symbols (symbols.pri) are required for locals.
Type ".hh dbgerr005" for details.

--- 

Stay tuned. I keep working on complex MySQL/MariaDB problems under Windows, so soon will have few more findings and links to share.

Fun with Bugs #63 - On Bugs Detected by ASan

Among other things Geir Hoydalsvik stated in his nice post yesterday:

 "We’ve fixed a number of bugs detected by UBsan and Asan."

This is indeed true, I already noted many related bugs fixed in recent MySQL 8.0.4. But I think that a couple of details are missing in the blog post. First of all, there still a notable number of bugs detected by ASan or noted in builds with ASan that remain "Verified". Second, who actually found and reported these bugs?

I decided to do a quick search and present my summary to clarify these details. Let me start with the list of "Verified" or "Open" bugs in public MySQL bugs database, starting from the oldest one:

• Bug #69715 - "UBSAN: Item_func_mul::int_op() mishandles 9223372036854775809*-1". The oldest related "Verified" bug I found was reported back in 2013 by Arthur O'Dwyer. Shane Bester from Oracle kindly keeps checking it with recent and upcoming releases, so we know that even '9.0.0-dmr-ubsan' (built on 20 October 2017) was still affected.
• Bug #80309 - "some innodb tests fail with address sanitizer (WITH_ASAN)". It was reported by Richard Prohaska and remains "Verified" for more than two years already.
• Bug #80581 - "rpl_semi_sync_[non_]group_commit_deadlock crash on ASan, debug". This bug reported by Laurynas Biveinis from Percona two years ago is still "Verified".
• Bug #81674 - "LeakSanitizer-enabled build fails to bootstrap server for MTR". This bug reported by  Laurynas Biveinis affects only MySQL 5.6, but still, why not to backport the fix from 5.7?
• Bug #82026 - "Stack buffer overflow with --ssl-cipher=<more than 4K characters>". Bug detected by ASan was noted by Yura Sorokin from Percona and reported by Laurynas Biveinis.
• Bug #82915 - "SIGKILL myself when using innodb_limit_optimistic_insert_debug=2 and drop table". ASan debug builds are affected. This bug was reported by Roel Van de Paar from Percona.
• Bug #85995 - "Server error exit due to empty datadir causes LeakSanitizer errors". This bug in MySQL 8.0.1 (that had to affect anyone who runs tests on ASan debug builds on a regular basis) was reported by Laurynas Biveinis and stay "Verified" for almost a year.
• Bug #87129 - "Unstable test main.basedir". This test problem reported by Laurynas Biveinis affects ASan builds, among others. See also his Bug #87190 - "Test main.group_by is unstable".
• Bug #87201 - "XCode 8.3.3+ -DWITH_UBSAN=ON bundled protobuf build error". Yet another (this time macOS-specific) bug found by Laurynas Biveinis.
• Bug #87295 - "Test group_replication.gr_single_primary_majority_loss_1 produces warnings". Potential bug in group replication noted by Laurynas Biveinis in ASan builds.
• Bug #87923 - "ASan reporting a memory leak on merge_large_tests-t". This bug by Laurynas Biveinis is still "Verified", while Tor Didriksen's comment states that it it resolved with the fix for Bug #87922 (that is closed as fixed in MySQL 8.0.4). Why not to close this one also?
• Bug #89438 - "LeakSanitizer errors on xplugin unit tests". As Laurynas Biveinis found, X Plugin unit tests report errors with LeakSanitizer.
• Bug #89439 - "LeakSanitizer errors on GCS unit tests". yet another bug report for MySQL 8.0.4 by Laurynas Biveinis.
• Bug #89961 - "add support for clang ubsan". This request was made by Tor Didriksen from Oracle. It is marked as "fixed in 8.0.12". It means we may get MySQL 8.0.11 released soon. That's why I decided to mention the bug here.

There were also few other test failures noted on ASan debug builds. I skipped them to make this post shorter.

Personally I do not run builds or tests with ASan on a regular basis. I appreciate Oracle's efforts to make code warning-free, UBSan- and ASan-clean, and fix bugs found with ASan. But I'd also want them to process all/most of related bugs in public database properly before making announcements of new related achievement, and clearly admit and appreciate a lot of help and contribution from specific community members (mostly Laurynas Biveinis in this case).

Percona engineers seem to test ASan builds of MySQL 5.7 and 8.0 (or Percona's closely related versions) regularly, for years, and contribute back public bug reports. I suspect they found way more related bugs than internal Oracle's QA. I think we should explicitly thank them for this contribution that made MySQL better!

Fun With Bugs #62 - On Bugs Related to JSON Support in MySQL

Comparing to "online ALTER" or FULLTEXT indexes in InnoDB, I am not that much exposed to using JSON in MySQL. OK, there is EXPLAIN ... FORMAT=JSON statement that is quite useful, optimizer trace in MySQL is also in JSON format, but otherwise I rarely have to even read this kind of data since my lame attempt to pass one introductory MongoDB training couse back in 2015 (when I mostly enjoyed mongo shell). Even less I care about storing JSON in MySQL.

But it seems community users do use it, and there is a book for them... So, out of pure curiosity last week I decided to check known bugs reported by MySQL Community users that are related to this feature (it has a separate category "MySQL Server: JSON" in public bugs database. This is a (short enough) list of my findings:

• Bug #89543 - "stack-overflow on gis.geojson_functions / json.json_functions_innodb". This is a recent bug report from Laurynas Biveinis. Based on last comment, it may have something to do with specific GCC compiler version and exact build option (WITH_UBSAN=ON) used. But for me it's yet another indication that community (Percona's in this case) extra QA still matters for MySQL quality. 
• Bug #88033 - "Generated INT column with value from JSON document". As Geert Vanderkelen says: "would be great if JSON null is NULL".
• Bug #87440 - "use union index,the value of key_len different with used_key_parts’ value." This is actually a bug in optimizer (or EXPLAIN ... FORMAT=JSON), but as it is still "Open" and nobody cared to check it, it still stays in the wrong category.
  
• Bug #85755 - "JSON containing null value is extracted as a string "null"". Similar to Geert's case above, Dave Pullin seems to need an easy way to get real NULL in SQL when the value is null in JSON. It is stated in comments that now everything works as designed, and it works exactly the same in MariaDB 10.2.13. Some users are not happy though and the bug remains still "Verified".
• Bug #84082 - "JSON_OBJECT("k", dateTime) adds milliseconds to time". In MariaDB 10.2.13 the result is different:
  

  MariaDB [(none)]> SELECT version(), JSON_OBJECT("k", cast("2016-11-19 17:46:31" as datetime(0)));
  +-----------------+--------------------------------------------------------------+
  | version()       | JSON_OBJECT("k", cast("2016-11-19 17:46:31" as datetime(0))) |
  +-----------------+--------------------------------------------------------------+
  | 10.2.13-MariaDB | {"k": "2016-11-19 17:46:31"}                                 |
  +-----------------+--------------------------------------------------------------+
  1 row in set (0.00 sec)

• Bug #83954 - "JSON handeling of DECIMAL values, JSON from JSON string". Take care when you cast values to JSON type.
• Bug #81677 - "Allows to force JSON columns encoding into pure UTF-8". This report is still "Open" and probably everything works as designed.
• Bug #79813 - "Boolean values are returned inconsistently with JSON_OBJECT". Take care while working with boolean properties.
• Bug #79053 - "Second argument "one" to JSON_CONTAINS_PATH is a misnomer". Nice request from Roland Bouman to use "some" instead of "one" in this case. Probably too late to implement it...

There also several related feature requests, of them the following are still "Open":

• Bug #84167 - "Managing deeply nested JSON documents with JSON_SET, JSON_MERGE". As a comment says, "It would by nice if MySQL came up with a solution for this in a more constructive way".
• Bug #82311 - "Retrieve the last value of an array (JSON_POP)". I am not 100% sure what the user wants here, but even I can get last array element in MongoDB using $slice, for example:
  

  > db.text.find();
  { "_id" : ObjectId("5aafe41c6bd09c09625aa3d1"), "item" : "test" }
  { "_id" : ObjectId("5ab0e8c208d6fe081ebb4f40"), "item" : null }
  { "_id" : ObjectId("5ab0f0f6cc695c62b4b0a301"), "item" : [ { "val" : 10 }, { "val" : 11 } ] }
  > db.text.find({}, { item: { $slice: -1 }, _id: 0});
  { "item" : "test" }
  { "item" : null }
  { "item" : [ { "val" : 11 } ] }
  >

• Bug #80545 - "JSON field should be allow INDEX by specifying table_flag". It seems some 3rd party storage engine developers want to have a way to crate and use some nice indexes of their engines to get efficient index-based search in JSON documents.
• Bug #80349 - "MySQL 5.7 JSON: improve documentation and possible improvements". Simon Mudd asked for more documentation on the way feature is designed (for those interested in the details of JSON data type implementation in modern MySQL versions there is a detailed enough public worklog, WL#8132) and asked some more questions. Morgan Tocker answered at least some of them, but this report still stays "Open" since that times...

It would be great for remaining few "Open" reports from community users to be properly processed, and a couple of real bugs identified fixed. There are also features to work on, and in the meantime workarounds and best practices should be shared. Maybe there are enough of them for the entire book.

That's almost all I have to say about JSON in MySQL at the moment.

Checking User Threads With gdb in MySQL 5.7+

In one of my gdb-related posts last year I noted that there is no more simple global list of user threads in MySQL 5.7+:

"I had highlighted Global_THD_manager singleton also as during my next gdb sessions I had found out that simple global list of threads is also gone and in 5.7 everything is done via that Global_THD_manager. This is a topic for some other post, though."

In that post and many times later when I had to deal with MySQL 5.7+ I just checked OS threads one by one in gdb using thread  1 ... thread N commands. This is not efficient at best, as I also hit numerous background threads that I often do not care about. So, a couple of weeks ago I finally decided to get back to this topic and find out how to check just user threads one by one in recent MySQL versions. I had a nice hint by Shane Bester on how to get information about $i-th thread (that he shared in one of his comments to my Facebook post):

set $value = (THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data + (sizeof(THD**) * $i))

I've attached gdb to an instance of Percona Server 5.7.x that I had running in my CentOS 6.9 VM and tried few commands to check types and content of the Global_THD_manager elements:

(gdb) p Global_THD_manager::thd_manager
$1 = (Global_THD_manager *) 0x7fab087fd000
(gdb) p Global_THD_manager::thd_manager->thd_list
$2 = {m_size = 2, m_capacity = 500, m_buff = {{
      data = "\000\060b\344\252\177\000\000\000\220i\344\252\177\000\000\000\200x\344\252\177", '\000' <repeats 3977 times>, align = {<No data fields>}}},
  m_array_ptr = 0x7fab087fd010, m_psi_key = 0}

So, we see that internally there is some array of elements thd_list with m_size items (2 in my case) probably stored in some pre-allocated buffer of m_capacity (500) elements, stored in m_buff.data. The type of elements is not clear, but we can try Shane's hint and assume that they are of type THD**. Let's try to check what we see there after type castings:

(gdb) p (THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data)
$4 = (THD **) 0x7fab087fd010
(gdb) p  *(THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data)
$5 = (THD *) 0x7faae4623000
(gdb) p  **(THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data)
$6 = {<MDL_context_owner> = {
    _vptr.MDL_context_owner = 0x1c51f50}, <Query_arena> = {
...

So, we get reasonable addresses and when we dereference the resulting THD** pointer twice we indeed get a structure that looks like THD of MySQL 5.7+ (it's very different, say, in MariaDB 10.1.x), with reasonable content (that is huge and skipped above).

I've tried to get processlist id of thread based on findings of that post using intermediate gdb variables:

(gdb) set $ppthd = (THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data)
(gdb) p *($ppthd)
$7 = (THD *) 0x7faae4623000

...
(gdb) set $pthd = *($ppthd)
(gdb) p $pthd->m_thread_id
$10 = 5

and then directly, using offsets and checking for security contexts of threads:

(gdb) p  (**(THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data)).m_main_security_ctx.m_user
$14 = {m_ptr = 0x7faae463b060 "myuser", m_length = 6, m_charset = 0x1d21760,
  m_alloced_length = 8, m_is_alloced = true}
(gdb) p  (**(THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data + (sizeof(THD**)))).m_main_security_ctx.m_user
$15 = {m_ptr = 0x7faae46b1090 "root", m_length = 4, m_charset = 0x1d21760,
  m_alloced_length = 8, m_is_alloced = true}
(gdb) p  (**(THD**)(Global_THD_manager::thd_manager->thd_list.m_buff.data + (sizeof(THD**)))).m_thread_id
$16 = 9

to confirm that I correctly get user names and thread ids for both 2 user threads I had in that "list". As usual Shane Bester was right!

Now, if you want to get more details about Global_THD_manager, you can just check the sql/mysqld_thd_manager.h file. I was interested mostly in the following:

  int get_num_thread_running() const { return num_thread_running; }
  uint get_thd_count() const { return global_thd_count; }

  static Global_THD_manager *thd_manager;

  // Array of current THDs. Protected by LOCK_thd_list.
  typedef Prealloced_array<THD*, 500, true> THD_array;
  THD_array thd_list;

  // Array of thread ID in current use. Protected by LOCK_thread_ids.
  typedef Prealloced_array<my_thread_id, 1000, true> Thread_id_array;
  Thread_id_array thread_ids;

First of all, how consistent it is to use both int and uint data types for values that are always >=0... The fact that our thd_list elements is actually some template-based container, Prealloced_array, it also interesting, as it would be useful to find out how it is implemented. We can find all relevant details in the include/prealloced_array.h file. I'd like to highlight the following here:

"The interface is chosen to be similar to std::vector."

...
private:
  size_t         m_size;
  size_t         m_capacity;
  // This buffer must be properly aligned.
  my_aligned_storage<Prealloc * sizeof(Element_type), MY_ALIGNOF(double)>m_buff;
Element_type *m_array_ptr;

To summarize, MySQL 5.7+ uses more C++ now, with templates, singletons, iterators and more, but still Oracle prefers to implement their own container types instead of using some standard ones. One of these generic types, Prealloced_array, is widely used and is easy to deal with in gdb, as long as you know the element type.

On InnoDB's FULLTEXT Indexes

I had recently written about InnoDB features that I try to avoid by all means if not hate: "online" DDL and persistent optimizer statistics. Time to add one more to the list - FULLTEXT indexes.

This feature had a lot of problems when initially introduced in MySQL 5.6. There was a nice series of blog posts about the initial experience with it by my colleague from Percona (at that times) Ernie Souhrada: part I, part II, and part III. Many of the problems mentioned there were resolved or properly documented since that times, but even more were discovered. So, InnoDB FULLTEXT indexes may be used, with care, when MyISAM or other engines/means to add fulltext search is not an option. The list of bugs that are still important and must be taken into account is presented below.

What forced me to get back to this feature recently and hate it sincerely is one customer issue that led to this bug report: MDEV-14773  - "ALTER TABLE ... MODIFY COLUMN ... hangs for InnoDB table with FULLTEXT index". Note that I have to refer to MariaDB bug report here, as related upstream Bug #88844 is hidden from community (probably considered a shame, if not a security problem)! The bug is simple: if one applies any ALTER to the InnoDB table with FULLTEXT index, even not related that index and columns in in any way, chances are high that this ALTER may cause a kind of hang/infinite loop/conflict of the thread that tries to drop temporary table used by ALTER, as one of last steps, and FTS background optimize thread. Similar to other two problematic features, new background threads were introduced and their cooperation with other threads in InnoDB seems to be not that well designed/implemented.

There are many other bugs to take into account if you ever plan to add any single FULLTEXT index to your InnoDB table. Here is the list of the most important ones, mostly still "Verified" or open and ignored, that I collected during one of calm night shifts this week:

• Bug #78048 - "INNODB Full text Case sensitive not working". This bug was fixed only recently, in MySQL 5.6.39, 5.7.21, and 8.0.4.
• Bug #83776 - "InnoDB FULLTEXT search returns incorrect result for operators on ignored words". Still "Verified" on all GA versions and 8.0.x.
• Bug #76210 - "InnoDB FULLTEXT index returns wrong results for key/value pair documents". This bug was reported by Justin Swanhart 3 years ago, quickly verified and then seems to be ignored.
• Bug #86036 - "InnoDB FULLTEXT index has too strict innodb_ft_result_cache_limit max limit". I reported this bug 10 months ago, and it was immediately "Verified". It seems FULLTEXT indexes are hardly useful in general for large InnoDB tables because of this limitation.
• Bug #78977 - "Enable InnoDB fulltext index to use generated FTS_DOC_ID column". This is a feature request (still "Open") to get rid of this well known limitation/specific column.
• Bug #86460 - "Deleted DOCID are not maintained during OPTIMIZE of InnoDB FULLTEXT tables". If you want to get rid of deleted DOC_IDs in the INNODB_FT_DELETED, better just run ALTER TABLE ... ENGINE=InnoDB.
• Bug #75763 - "InnoDB FULLTEXT index reduces insert performance by up to 6x on JSON docs". yet another verified bug report by Justin Swanhart.
• Bug #69762 - "InnoDB fulltext match against in boolean mode misses results on join". Let me quote last comment there:
  

  "Since innodb doesn't support fulltext search on columns without fulltext index, and it is very complicated to support search on columns in multiple fulltext indexes in optimizer, it won't be fixed.
  
  We admit it's a point innodb fulltext is not compatible with myisam."

• Bug #85880 - "Fulltext query is too slow when each ngram token match a lot of documents". This bug is still "Open".
• Bug #78485 - "Fulltext search with char * produces a syntax error with InnoDB". Yet another verified regression comparing to MyISAM FULLTEXT indexes. Nobody cares for 2.5 years.
• Bug #80432 - "No results in fulltext search for top level domain in domain part of email ". It ended up as "Won't fix", but at least a workaround was provided by Oracle developer.
• Bug #81819 - "ALTER TABLE...LOCK=NONE is not allowed when FULLTEXT INDEX exists". Online ALTER just does not work for tables with FULLTEXT indexes. This is a serious limitation.
  
• Bug #72132 - "Auxiliary tables for InnoDB FTS indexes are always created in shared tablespace". This my bug report was fixed in .5.6.20+ and 5.7.5+, but the fact that this regression was not noted for a long time internally says a lot about the way the feature was developed and maintained.
• Bug #83560  - "InnoDB FTS - output from mysqldump extremely slow and blocks unrelated inserts". I have yet to check the metadata locks set when the table with FULLTEXT index is used in various SQL statements, but from this "Verified" report it is clear that just lading a dump of a table with FULLTEXT indexes may work too slow for any large table.
• Bug #71551 - "ft_boolean_syntax has no impact on InnoDB FTS". yet another inconsistency with MyISAM FULLTEXT indexes that was reported 4 years ago and "Verified", but still ignored after that.
  
• Bug #83741 - "InnoDB: Failing assertion: lock->magic_n == 22643". Surely, debug assertions can be ignored, but in most cases they are in the code for a good reason. This failure was reported by Roel Van de Paar from Percona.
• Bug #83397 - "INSERT INTO ... SELECT FROM ... fails if source has > 65535 rows on FTS". This "Verified" bug alone, reported by Daniël van Eeden, makes InnoDB FULLTEXT indexes hardly usable in production for large tables.
• Bug #80296 - "FTS query exceeds result cache limit". The bug is "Closed" silently (by the bug reporter maybe, Monty Solomon?), but users report that recent enough versions like 5.6.35 and 5.7.17 are still affected. See also Bug #82971 (no fix for MySQL 5.6.x for sure).
• Bug #85876 - "Fulltext search can not find word which contains "," or ".".  Still "Verified" for 1 months.
• Bug #68987 - "MySQL crash with InnoDB assertion failure in file pars0pars.cc". Crash was reported in MySQL 5.6.10, not repeatable. Then (different?) assertion failure was reported in debug builds only in MySQL 5.6.21+, and verified. Not sure what's going on with this bug report...
• Bug #83398 - "Slow and unexpected explain output on FTS". The fact that EXPLAIN may be slow when the table with FULLTEXT index is involved is now documented, so this report by Daniël van Eeden is closed.
  
• Bug #81930 - "incorrect result with InnoDB FTS and subquery". This bug report about wrong results by Sergei Golubchik from MariaDB was immediately "Verified", but ignored since that time.
• Bug #80347 - "mysqldump backup restore fails due to invalid FTS_DOC_ID (Error 182 and 1030)". There is a workaround based on mydumper/myloader at least...

To summarize, InnoDB FULLTEXT indexes is one of the most problematic InnoDB features for any production use because:

• There are all kinds of serious bugs, from wrong results to hangs, debug assertions and crashes, that do not seem to get any internal priority and stay "Verified" for years.
• There are performance regressions and missing features comparing to MyISAM FULLTEXT indexes, so migration may cause problems.
• InnoDB FULLTEXT indexes are not designed to work with really large tables/result sets.
• You should expect problems during routine DBA activities, like ALTERing tables or dumps and restores when any table with InnoDB FULLTEXT index is involved. 

If you still plan/have to use it, please, make sure to use the latest MySQL version, check the list above carefully and test/check the results of fulltext searches and routine DBA operations like altering the table. You may get a lot of surprises. Consider alternatives like Sphinx seriously.