|
Attached output of Windbg. it looks like almost 400 threads are waiting, and there is some kind of deadlock.
most of the threads wait for LOCK_open, in open_table, close_tables and similar places, one thread however that is somewhere in "SHOW CREATE" is waiting on condition variable and is probably holding the lock , that others wait for
mysqld!pthread_cond_timedwait
mysqld!translog_flush_wait_for_end
mysqld!translog_flush
mysqld!pagecache_fwrite
mysqld!flush_cached_blocks
mysqld!flush_pagecache_blocks_int
mysqld!flush_pagecache_blocks_with_filter
mysqld!_ma_once_end_block_record
mysqld!maria_close
mysqld!closefrm
mysqld!intern_close_table
mysqld!free_cache_entry
mysqld!close_thread_table
mysqld!close_open_tables
mysqld!close_thread_tables
mysqld_show_create
|
|
eidbadr, as I understand, the problem happens regularly for you? Could you maybe set up a monitor for the processlist (periodic execution of SHOW FULL PROCESSLIST, so we at least see where the problem starts?
It's better if the monitoring is done by a persistent connection, because new ones will be locked out, but if it's difficult, set it up any way that is suitable for you.
|
|
windbg_output2_1b20_2016-05-20_19-33-35-246.txt Attaching another windbg dump of all threads. hang on the same place basically, waiting for lsn to be flushed.
2 threads are waiting for different LSN to be flushed (one thread for 30082577968, another one for 30082578109). All other threads seems to hang waiting for LOCK_open
2 mysqld.exe!pthread_cond_timedwait(pthread_cond_t * cond=0x0000000000000000, _RTL_CRITICAL_SECTION * mutex=0x00007ff7d15b6da5, const timespec * abstime=0x00000055a7159000)
|
3 mysqld.exe!translog_flush_wait_for_end(__int64 lsn=30082577968)
|
4 mysqld.exe!translog_flush(__int64 lsn=367408970136)
|
5 mysqld.exe!ma_commit(st_ma_transaction * trn=0x00000007010fb630)
|
6 mysqld.exe!ha_maria::implicit_commit(THD * thd=0x00000055a6cfd700, bool new_trn=false)
|
7 mysqld.exe!mysql_execute_command(THD * thd=0x00000055a6cfd790)
|
8 mysqld.exe!mysql_parse(THD * thd=0x00000055a6cfae70, char * rawbuf=0x00000055a82bea40, unsigned
|
|
and
5 mysqld.exe!translog_flush_wait_for_end(__int64 lsn=30082578109)
|
6 mysqld.exe!translog_flush(__int64 lsn=0)
|
7 mysqld.exe!pagecache_fwrite(st_pagecache * pagecache=0x000000546ca7e310, st_pagecache_file * filedesc=0x00000055a7cb98a0, unsigned char * buffer=0x0000000000000001, unsigned __int64 pageno=36, pagecache_page_type type=PAGECACHE_PLAIN_PAGE, int flags=36)
|
8 mysqld.exe!flush_cached_blocks(st_pagecache * pagecache=0x0000000000000002, st_pagecache_file * file=0x00000055adf367f8, st_pagecache_block_link * * cache=0x0000000000000000, st_pagecache_block_link * * end=0x00007ff7ffffffff, flush_type type=FLUSH_RELEASE, int * first_errno=0x0000000000000000)
|
9 mysqld.exe!flush_pagecache_blocks_int(st_pagecache * pagecache=0x00007ff7d2712b60, st_pagecache_file * file=0x0000000000000001, flush_type type=-764335264, pagecache_flush_filter_result (pagecache_page_type, unsigned __int64, __int64, void *) * filter=0x0000000000000000, void * filter_arg=0x0000000000000000)
|
10 mysqld.exe!flush_pagecache_blocks_with_filter(st_pagecache * pagecache=0x00000055adf35ed0, st_pagecache_file * file=0x0000000000000000, flush_type type=FLUSH_IGNORE_CHANGED, pagecache_flush_filter_result (pagecache_page_type, unsigned __int64, __int64, void *) * filter=0x0000000000000000, void * filter_arg=0x0000000000000000)
|
11 mysqld.exe!_ma_once_end_block_record(st_maria_share * share=0x0000000000000002)
|
12 mysqld.exe!maria_close(st_maria_handler * info=0x00000055a7cbda00)
|
13 mysqld.exe!closefrm(TABLE * table=0x0000005599e05b10, bool free_share=128)
|
14 mysqld.exe!intern_close_table(TABLE * table=0x000000554bcc37ee)
|
15 mysqld.exe!free_cache_entry(TABLE * table=0x000000554bcc37ee)
|
16 mysqld.exe!open_table(THD * thd=0x00007ff7d25fa850, TABLE_LIST * table_list=0x00007ff7d17bec86, st_mem_root * mem_root=0x0000000000000007, Open_table_context * ot_ctx=0x00007ff7d194a70c)
|
17 mysqld.exe!open_and_process_table(THD * thd=0x00000055979ff700, LEX * lex=0x00000055a7cbe2d0, TABLE_LIST * tables=0x0000000000000000, unsigned int * counter=0x00000055a103c998, unsigned int flags=0, Prelocking_strategy * prelocking_strategy=0x00000055a7cbe2d0, bool has_prelocking_list=false, Open_table_context * ot_ctx=0x00000055a7cbe110, st_mem_root * new_frm_mem=0x00000055a7cbe140)
|
18 mysqld.exe!open_tables(THD * thd=0x00007ff700000004, TABLE_LIST * * start=0x00007ff700000000, unsigned int * counter=0x00000055a7cbe230, unsigned int flags=0, Prelocking_strategy * prelocking_strategy=0x00000055a7cbe2d0)
|
19 mysqld.exe!open_and_lock_tables(THD * thd=0x00007ff700000001, TABLE_LIST * tables=0x00000055a103c998, bool derived=false, unsigned int flags=2701379601, Prelocking_strategy * prelocking_strategy=0x00000055a7cbe2d0)
|
20 mysqld.exe!mysql_insert(THD * thd=0x00000055979fea00, TABLE_LIST * table_list=0x00000055a7cbe580, List<Item> & fields={...}, List<List<Item> > & values_list=<struct at NULL>, List<Item> & update_fields={...}, List<Item> & update_values={...}, enum_duplicates duplic=DUP_ERROR, bool ignore=false)
|
21 mysqld.exe!mysql_execute_command(THD * thd=0x00000055979fea70)
|
Here is the log_descriptor struct with relevant info
>Debug.Print log_descriptor
{pagecache=0x00007ff7d27134e0 {mysqld.exe!st_pagecache maria_log_pagecache_var} {mem_size=2097152 min_warm_blocks=...} ...}
|
pagecache: 0x00007ff7d27134e0 {mysqld.exe!st_pagecache maria_log_pagecache_var} {mem_size=2097152 min_warm_blocks=...}
|
flags: 0
|
open_flags: 32770
|
log_file_max_size: 1073741824
|
server_version: 50549
|
server_id: 1
|
buffer_capacity_chunk_2: 1047552
|
half_buffer_capacity_chunk_2: 523776
|
page_overhead: 7
|
page_capacity_chunk_2: 8184
|
directory: 0x00007ff7d1ef9c58 "d:\\leutek\\mariadb\\data\\"
|
open_files: {buffer=0x00000054545969b0 "ШYTT" elements=1 max_element=10 ...}
|
max_file: 7
|
min_file: 7
|
open_files_lock: {m_rwlock={srwlock={Ptr=0x0000000000000000 } have_exclusive_srwlock=0 lock={DebugInfo=0x0000000000000000 <NULL> ...} ...} ...}
|
directory_fd: -1
|
buffers: 0x00007ff7d1ef9f58 {{buffer=0x00007ff7d1ef9f58 "w\x4" last_lsn=30082576829 prev_last_lsn=30082576007 ...}, ...}
|
dirty_buffer_mask: 8 '\b'
|
dirty_buffer_mask_lock: {m_mutex={DebugInfo=0xffffffffffffffff {Type=??? CreatorBackTraceIndex=??? CriticalSection=??? ...} ...} ...}
|
horizon: 30082578112
|
bc: {ptr=0x00007ff7d21fb9f0 }
|
max_lsn: 30082578109
|
flushed: 30082575408
|
sent_to_disk: 30082578109
|
log_start: 30073560955
|
previous_flush_horizon: 30082574187
|
in_buffers_only: 30082572288
|
sent_to_disk_lock: {m_mutex={DebugInfo=0xffffffffffffffff {Type=??? CreatorBackTraceIndex=??? CriticalSection=??? ...} ...} ...}
|
log_flush_lock: {m_mutex={DebugInfo=0x00000055c3a79830 {Type=0 CreatorBackTraceIndex=0 CriticalSection=mysqld.exe!0x00007ff7d26faa58 {...} ...} ...} ...}
|
log_flush_cond: {m_cond={native_cond={Ptr=0x00000055a7cb9270 } waiting=2815136368 lock_waiting={DebugInfo=0x0000000000000000 <NULL> ...} ...} ...}
|
new_goal_cond: {m_cond={native_cond={Ptr=0x0000000000000000 } waiting=0 lock_waiting={DebugInfo=0x0000000000000000 <NULL> ...} ...} ...}
|
file_header_lock: {m_mutex={DebugInfo=0xffffffffffffffff {Type=??? CreatorBackTraceIndex=??? CriticalSection=??? ...} ...} ...}
|
unfinished_files_lock: {m_mutex={DebugInfo=0xffffffffffffffff {Type=??? CreatorBackTraceIndex=??? CriticalSection=??? ...} ...} ...}
|
unfinished_files: {buffer=0x0000005454596b90 "" elements=0 max_element=10 ...}
|
min_need_file: 7
|
min_file_number: 7
|
purger_lock: {m_mutex={DebugInfo=0xffffffffffffffff {Type=??? CreatorBackTraceIndex=??? CriticalSection=??? ...} ...} ...}
|
last_lsn_checked: 0
|
is_everything_flushed: 1 '\x1'
|
flush_in_progress: 0 '\0'
|
flush_no: 36608
|
next_pass_max_lsn: 0
|
max_lsn_requester: 9520
|
|
mysqld.001
mysqld.zip
windbg_output.txt