Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.2.14, 10.0(EOL), 10.1(EOL), 10.2(EOL), 10.3(EOL)
Description
We are getting periodic crashes on our staging server, whilst adding a column and an index. to a table. There are about 200 databases in the server and these are updated to our latest development schemas nightly ready for testing. We will typically get a crash every other day or so. The database that fails varies, but each typically has several hundred thousand rows. The table update that triggers the crash is always:
ALTER TABLE order_line_items
|
ADD COLUMN `is_bundle_parent` tinyint(1) NOT NULL default 0,
|
ADD INDEX `index_order_line_items_on_is_bundle_parent` (`is_bundle_parent`)
|
Immediately before this alter table we update pretty much all the rows the table. which I suspect may be relevant,
UPDATE order_line_items SET bundle_line_item_id=id WHERE bundle_line_item_id IS NULL
|
In the mysql error log we see:
2018-05-08 22:43:00 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 1000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:43:20 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 2000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:43:40 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 3000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:44:00 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 4000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:44:20 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 5000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:44:40 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 6000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:45:00 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 7000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:45:20 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 8000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:45:40 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 9000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:46:00 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 10000 times. There are either pending IOs or flushes or the file is being extended.
|
2018-05-08 22:46:21 140184283293440 [Warning] InnoDB: Cannot rename file ./private_104550_production/order_line_items.ibd (space id 51213308), retried 11000 times. There are either pending IOs or flushes or the file is being extended.
|
followed by
--Thread 140184803284736 has waited at row0purge.cc line 853 for 241.00 seconds the semaphore:
|
S-lock on RW-latch at 0x563589733d10 created in file dict0dict.cc line 1107
|
a writer (thread id 140184283293440) has reserved it in mode exclusive
|
number of readers 0, waiters flag 1, lock_word: 0
|
Last time read locked in file row0purge.cc line 853
|
Last time write locked in file handler0alter.cc line 8546
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184278025984 has waited at dict0dict.cc line 1160 for 116.00 seconds the semaphore:
|
Mutex at 0x563589733d90, Mutex DICT_SYS created dict0dict.cc:1096, lock var 2
|
 |
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184736397056 has waited at ibuf0ibuf.cc line 4578 for 240.00 seconds the semaphore:
|
S-lock on RW-latch at 0x7f805f7eaf48 created in file buf0buf.cc line 1471
|
a writer (thread id 140184744789760) has reserved it in mode exclusive
|
number of readers 0, waiters flag 1, lock_word: 0
|
Last time read locked in file ibuf0ibuf.cc line 4578
|
Last time write locked in file mtr0mtr.ic line 147
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184728004352 has waited at ibuf0ibuf.cc line 4578 for 240.00 seconds the semaphore:
|
S-lock on RW-latch at 0x7f805f7eaf48 created in file buf0buf.cc line 1471
|
a writer (thread id 140184744789760) has reserved it in mode exclusive
|
number of readers 0, waiters flag 1, lock_word: 0
|
Last time read locked in file ibuf0ibuf.cc line 4578
|
Last time write locked in file mtr0mtr.ic line 147
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184803284736 has waited at row0purge.cc line 853 for 241.00 seconds the semaphore:
|
S-lock on RW-latch at 0x563589733d10 created in file dict0dict.cc line 1107
|
a writer (thread id 140184283293440) has reserved it in mode exclusive
|
number of readers 0, waiters flag 1, lock_word: 0
|
Last time read locked in file row0purge.cc line 853
|
Last time write locked in file handler0alter.cc line 8546
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184783165184 has waited at row0mysql.cc line 1780 for 240.00 seconds the semaphore:
|
S-lock on RW-latch at 0x563589733d10 created in file dict0dict.cc line 1107
|
a writer (thread id 140184283293440) has reserved it in mode exclusive
|
number of readers 0, waiters flag 1, lock_word: 0
|
Last time read locked in file row0purge.cc line 853
|
Last time write locked in file handler0alter.cc line 8546
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184270636800 has waited at dict0dict.cc line 1160 for 233.00 seconds the semaphore:
|
Mutex at 0x563589733d90, Mutex DICT_SYS created dict0dict.cc:1096, lock var 2
|
 |
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184853640960 has waited at srv0srv.cc line 2089 for 240.00 seconds the semaphore:
|
X-lock on RW-latch at 0x563589733d10 created in file dict0dict.cc line 1107
|
a writer (thread id 140184283293440) has reserved it in mode exclusive
|
number of readers 0, waiters flag 1, lock_word: 0
|
Last time read locked in file row0purge.cc line 853
|
Last time write locked in file handler0alter.cc line 8546
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184753182464 has waited at ibuf0ibuf.cc line 4578 for 240.00 seconds the semaphore:
|
S-lock on RW-latch at 0x7f805f7eaf48 created in file buf0buf.cc line 1471
|
a writer (thread id 140184744789760) has reserved it in mode exclusive
|
number of readers 0, waiters flag 1, lock_word: 0
|
Last time read locked in file ibuf0ibuf.cc line 4578
|
Last time write locked in file mtr0mtr.ic line 147
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184744789760 has waited at mtr0mtr.ic line 147 for 240.00 seconds the semaphore:
|
X-lock on RW-latch at 0x7f805f8749d8 created in file buf0buf.cc line 1471
|
a writer (thread id 0) has reserved it in mode SX
|
number of readers 0, waiters flag 1, lock_word: 10000000
|
Last time read locked in file ibuf0ibuf.cc line 4578
|
Last time write locked in file buf0flu.cc line 1213
|
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184820070144 has waited at dict0stats_bg.cc line 341 for 235.00 seconds the semaphore:
|
Mutex at 0x563589733d90, Mutex DICT_SYS created dict0dict.cc:1096, lock var 2
|
 |
2018-05-08 22:46:40 140184836855552 [Note] InnoDB: A semaphore wait:
|
--Thread 140184648525568 has waited at dict0dict.cc line 1160 for 35.00 seconds the semaphore:
|
Mutex at 0x563589733d90, Mutex DICT_SYS created dict0dict.cc:1096, lock var 2
|
The engine innodb status is the dumped. This is attached.
We have experimented with setting the following, but this has has no affect.
innodb_purge_threads = 1
|
innodb_adaptive_hash_index_parts = 1
|
Attachments
Issue Links
- relates to
-
MDEV-18717 Server crash when trying to alter add Primary Key to InnoDB table
- Closed