"To a man with a hammer, everything looks like a nail."
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>dirHere is the list of most useful cdb options for the next step:
...
11/10/2017 11:55 PM 154,936 cdb.exe
...
11/10/2017 11:55 PM 576,312 windbg.exe
...
C:\Program Files (x86)\Windows Kits\10\Debuggers\x64>cdb /?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...
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
...
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/symbolsThis 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:\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.
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>
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.
No comments:
Post a Comment