Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
5.5(EOL), 10.0(EOL), 10.1(EOL)
-
None
-
10.1.32
Description
When certain queries from INFORMATION_SCHEMA get killed, they stay in the processlist for long time (10-20 min depending on the version), even if the server is already idle, like this:
User Host db Command Time State Info Progress
|
43 rqg localhost:58730 test Killed 636 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
44 rqg localhost:58731 test Killed 636 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
45 rqg localhost:58732 test Killed 636 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
46 rqg localhost:58733 test Killed 636 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
48 rqg localhost:58735 test Killed 636 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
50 rqg localhost:58737 test Killed 636 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
62 rqg localhost:58749 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
63 rqg localhost:58750 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
64 rqg localhost:58751 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
65 rqg localhost:58752 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
66 rqg localhost:58753 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
67 rqg localhost:58754 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
68 rqg localhost:58755 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
69 rqg localhost:58756 test Killed 525 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
71 rqg localhost:58758 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
72 rqg localhost:58759 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
73 rqg localhost:58760 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
74 rqg localhost:58761 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
75 rqg localhost:58762 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
76 rqg localhost:58763 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
77 rqg localhost:58764 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
78 rqg localhost:58765 test Killed 515 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
91 rqg localhost:58779 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
92 rqg localhost:58780 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
93 rqg localhost:58781 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
94 rqg localhost:58782 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
95 rqg localhost:58783 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
96 rqg localhost:58784 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
97 rqg localhost:58785 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
98 rqg localhost:58786 test Killed 395 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
100 rqg localhost:58788 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
101 rqg localhost:58789 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
102 rqg localhost:58790 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
103 rqg localhost:58791 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
104 rqg localhost:58792 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
105 rqg localhost:58793 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
106 rqg localhost:58794 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
107 rqg localhost:58795 test Killed 384 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
119 rqg localhost:58807 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
120 rqg localhost:58808 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
121 rqg localhost:58809 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
122 rqg localhost:58810 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
123 rqg localhost:58811 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
124 rqg localhost:58812 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
125 rqg localhost:58813 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
126 rqg localhost:58814 test Killed 274 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
129 rqg localhost:58817 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
130 rqg localhost:58818 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
131 rqg localhost:58819 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
132 rqg localhost:58820 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
133 rqg localhost:58821 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
134 rqg localhost:58822 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
135 rqg localhost:58823 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
136 rqg localhost:58824 test Killed 254 Filling schema table SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE` 0.000
|
186 root localhost:58875 NULL Query 0 init show processlist 0.000
|
Eventually these sessions disappear from the list.
It seems to be impossible to shut down the server during this time. If shutdown is issued, the server throws a lot of errors into the error log, but even after that the shutdown is delayed (note timestamps in the log below):
Version: '10.0.26-MariaDB-debug' socket: '/home/elenst/test_results/analyze_deadlock_10.0/mysql.sock' port: 10720 Source distribution
|
160621 23:00:22 [Note] /home/elenst/git/10.0/sql/mysqld: Normal shutdown
|
 |
160621 23:00:22 [Note] Event Scheduler: Purging the queue. 0 events
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 136 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 135 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 134 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 133 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 132 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 131 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 130 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 129 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 126 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 125 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 124 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 123 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 122 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 121 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 120 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 119 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 107 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 106 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 105 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 104 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 103 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 102 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 101 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 100 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 98 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 97 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 96 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 95 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 94 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 93 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 92 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 91 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 78 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 77 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 76 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 75 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 74 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 73 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 72 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 71 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 69 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 68 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 67 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 66 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 65 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 64 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 63 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:00:46 [Warning] /home/elenst/git/10.0/sql/mysqld: Forcing close of thread 62 user: 'rqg'
|
 |
160621 23:00:46 [ERROR] mysqld: Got an error writing communication packets
|
160621 23:07:12 [Note] InnoDB: FTS optimize thread exiting.
|
160621 23:07:12 [Note] InnoDB: Starting shutdown...
|
160621 23:07:15 [Note] InnoDB: Shutdown completed; log sequence number 1652401
|
160621 23:07:15 [Note] /home/elenst/git/10.0/sql/mysqld: Shutdown complete
|
Killed threads look like this:
#0 0x00007f1d500d889c in __lll_lock_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#1 0x00007f1d500d409b in _L_lock_1006 () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#2 0x00007f1d500d401c in pthread_mutex_lock () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#3 0x0000000000e7956b in safe_mutex_lock (mp=0x208afa8 <maria_pagecache_var+200>, my_flags=0, file=0x101bed8 "/home/elenst/git/10.0/storage/maria/ma_pagecache.c", line=3027) at /home/elenst/git/10.0/mysys/thr_mutex.c:294
|
#4 0x0000000000a49fb7 in inline_mysql_mutex_lock (that=0x208afa8 <maria_pagecache_var+200>, src_file=0x101bed8 "/home/elenst/git/10.0/storage/maria/ma_pagecache.c", src_line=3027) at /home/elenst/git/10.0/include/mysql/psi/mysql_thread.h:689
|
#5 0x0000000000a50bd9 in pagecache_unlock_by_link (pagecache=0x208aee0 <maria_pagecache_var>, block=0x7f1d3dc55a70, lock=PAGECACHE_LOCK_WRITE_TO_READ, pin=PAGECACHE_PIN_LEFT_PINNED, first_REDO_LSN_for_page=0, lsn=0, was_changed=1 '\001', any=0 '\000') at /home/elenst/git/10.0/storage/maria/ma_pagecache.c:3027
|
#6 0x0000000000a8997a in write_block_record (info=0x7f1c02bf0070, old_record=0x0, record=0x7f1c17788088 "\031\001", row=0x7f1c02bf00c8, bitmap_blocks=0x7f1c02bf00c8, head_block_is_read=1 '\001', row_pos=0x7f1bfc9fdb00, undo_lsn=1, old_record_checksum=0) at /home/elenst/git/10.0/storage/maria/ma_blockrec.c:3144
|
#7 0x0000000000a8a9aa in allocate_and_write_block_record (info=0x7f1c02bf0070, record=0x7f1c17788088 "\031\001", row=0x7f1c02bf00c8, undo_lsn=1) at /home/elenst/git/10.0/storage/maria/ma_blockrec.c:3528
|
#8 0x0000000000a8aab9 in _ma_write_init_block_record (info=0x7f1c02bf0070, record=0x7f1c17788088 "\031\001") at /home/elenst/git/10.0/storage/maria/ma_blockrec.c:3568
|
#9 0x0000000000a9bc43 in maria_write (info=0x7f1c02bf0070, record=0x7f1c17788088 "\031\001") at /home/elenst/git/10.0/storage/maria/ma_write.c:156
|
#10 0x0000000000a273a1 in ha_maria::write_row (this=0x7f1c174b8c88, buf=0x7f1c17788088 "\031\001") at /home/elenst/git/10.0/storage/maria/ha_maria.cc:1280
|
#11 0x00000000006d9606 in handler::ha_write_tmp_row (this=0x7f1c174b8c88, buf=0x7f1c17788088 "\031\001") at /home/elenst/git/10.0/sql/sql_class.h:4993
|
#12 0x00000000006e80e7 in schema_table_store_record (thd=0x7f1c19b39070, table=0x7f1c174a9088) at /home/elenst/git/10.0/sql/sql_show.cc:3542
|
#13 0x0000000000b85846 in i_s_innodb_buffer_page_fill (thd=0x7f1c19b39070, tables=0x7f1c1749d418, info_array=0x7f1bff006078, num_page=10000) at /home/elenst/git/10.0/storage/xtradb/handler/i_s.cc:4992
|
#14 0x0000000000b85f9e in i_s_innodb_fill_buffer_pool (thd=0x7f1c19b39070, tables=0x7f1c1749d418, buf_pool=0x7f1d4e49d738, pool_id=1) at /home/elenst/git/10.0/storage/xtradb/handler/i_s.cc:5209
|
#15 0x0000000000b860bf in i_s_innodb_buffer_page_fill_table (thd=0x7f1c19b39070, tables=0x7f1c1749d418) at /home/elenst/git/10.0/storage/xtradb/handler/i_s.cc:5256
|
#16 0x00000000006f9b19 in get_schema_tables_result (join=0x7f1c1749e970, executed_place=PROCESSED_BY_JOIN_EXEC) at /home/elenst/git/10.0/sql/sql_show.cc:8168
|
#17 0x000000000069c30a in JOIN::exec_inner (this=0x7f1c1749e970) at /home/elenst/git/10.0/sql/sql_select.cc:2538
|
#18 0x000000000069b8fe in JOIN::exec (this=0x7f1c1749e970) at /home/elenst/git/10.0/sql/sql_select.cc:2373
|
#19 0x000000000069ef3b in mysql_select (thd=0x7f1c19b39070, rref_pointer_array=0x7f1c19b3d348, tables=0x7f1c1749d418, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684619520, result=0x7f1c1749e950, unit=0x7f1c19b3c9e0, select_lex=0x7f1c19b3d0d0) at /home/elenst/git/10.0/sql/sql_select.cc:3308
|
#20 0x0000000000694f03 in handle_select (thd=0x7f1c19b39070, lex=0x7f1c19b3c918, result=0x7f1c1749e950, setup_tables_done_option=0) at /home/elenst/git/10.0/sql/sql_select.cc:373
|
#21 0x0000000000667b05 in execute_sqlcom_select (thd=0x7f1c19b39070, all_tables=0x7f1c1749d418) at /home/elenst/git/10.0/sql/sql_parse.cc:5293
|
#22 0x000000000065fcf9 in mysql_execute_command (thd=0x7f1c19b39070) at /home/elenst/git/10.0/sql/sql_parse.cc:2562
|
#23 0x000000000066a90d in mysql_parse (thd=0x7f1c19b39070, rawbuf=0x7f1c1749d088 "SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE`", length=60, parser_state=0x7f1bfc9ff5f0) at /home/elenst/git/10.0/sql/sql_parse.cc:6574
|
#24 0x000000000065ce95 in dispatch_command (command=COM_QUERY, thd=0x7f1c19b39070, packet=0x7f1c19b3f071 "SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE`", packet_length=60) at /home/elenst/git/10.0/sql/sql_parse.cc:1308
|
#25 0x000000000065c114 in do_command (thd=0x7f1c19b39070) at /home/elenst/git/10.0/sql/sql_parse.cc:998
|
#26 0x0000000000786f7b in do_handle_one_connection (thd_arg=0x7f1c19b39070) at /home/elenst/git/10.0/sql/sql_connect.cc:1378
|
#27 0x0000000000786ced in handle_one_connection (arg=0x7f1c19b39070) at /home/elenst/git/10.0/sql/sql_connect.cc:1293
|
#28 0x00007f1d500d1e9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#29 0x00007f1d4efc1cbd in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
#30 0x0000000000000000 in ?? ()
|
4 all threads' stack traces from 10.0 are attached:
- threads1_active – from the time when some connections are already killed, but there is still activity on the server;
- threads2_still – from the time when all incoming requests are finished, only killed threads are hanging;
- threads3_shutdown - from the time after 'shutdown' command was issued, but the server is still responding;
- threads4_shutdown_not_responding – from the time after 'shutdown' command was issued and the server stopped responding, but mysqld process is still there.
Reproducible on all of 5.5, 10.0, 10.1, 10.2.
Important notes:
- With given server settings, the table in question is quite big, but not that big. If a query is not killed, it might take 3-4 minutes to finish on the same server, same machine; but not 10+ minutes like the killed query takes.
- The type of query is not important; I'm using COUNT just to produce small result set while still having a long enough query, but otherwise aggregate functions are not necessary here.
- I could only reproduce it on a debug build. Maybe release versions are just faster, or maybe they are essentially different.
- I'm not sure whether other tables are affected. If it's only a weird behavior with this particular table and only on a debug server, it is not a big problem, and maybe even is not worth fixing; but my concern is that the root cause is more generic, and it might affect realistic scenarios on release servers, only not so reliably. We always have some mysterious external reports about processlists full of killed queries, about server hanging on shutdown, and such. Maybe it's somehow related.
To reproduce with RQG (try different value of threads and innodb-buffer-pool-size, depending on what your machine is capable of:
|
is.yy |
query:
|
SELECT COUNT(*) FROM INFORMATION_SCHEMA.`INNODB_BUFFER_PAGE`;
|
|
command line |
perl ./runall-new.pl \
|
--threads=16 \
|
--duration=600 \
|
--queries=100M \
|
--grammar=is.yy \
|
--reporters=QueryTimeout \
|
--mysqld=--innodb-buffer-pool-size=4G \
|
--skip-gendata \
|
--skip-shutdown \
|
--basedir=<your basedir> \
|
--vardir=<your vardir>
|
(I recommend using RQG from https://github.com/elenst/rqg , that's the version for MariaDB which is currently maintained).
The test will pass, as it does not have any monitors to detect deadlocks and such (intentionally, to avoid unrelated queries); but you can monitor the processlist and error log separately to see what is happening.