| Bug #47300 | innodb insert dead lock | ||
|---|---|---|---|
| Submitted: | 14 Sep 2009 8:19 | Modified: | 21 Dec 2009 16:58 |
| Reporter: | jim chen | Email Updates: | |
| Status: | No Feedback | Impact on me: | |
| Category: | MySQL Server: Locking | Severity: | S2 (Serious) |
| Version: | 5.1.30 | OS: | Linux |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | dead lock | ||
[14 Sep 2009 8:20]
jim chen
the file is my.cnf
Attachment: netojns1.cnf (application/octet-stream, text), 5.12 KiB.
[14 Sep 2009 8:37]
Valeriy Kravchuk
I do not see any information about deadlock in SHOW INNODB STATUS. Can you, please, get the results of SHOW INNODB STATUS next time when deadlock will happen? Send also the results of: show create table tb_livenews_section_disk\G
[14 Sep 2009 10:01]
jim chen
table lock info
Attachment: mysqllockinfo.txt (text/plain), 6.42 KiB.
[14 Sep 2009 10:05]
jim chen
I think there's no dead lock too,but execute the insert sql one hour, my service can't work.
[14 Sep 2009 20:09]
Sveta Smirnova
Thank you for the feedback. Please send us output of SHOW PROCESSLIST in "lock" time also.
[16 Sep 2009 2:30]
jim chen
mysql> show full processlist; +-------+-----------------+-------------------+--------------------+---------+-------+------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +-------+-----------------+-------------------+--------------------+---------+-------+------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | 2 | event_scheduler | localhost | NULL | Daemon | 11534 | Waiting on empty queue | NULL | | 12156 | windin | 127.0.0.1:38443 | livenewsthird | Sleep | 67 | | NULL | | 14538 | windin | 127.0.0.1:60348 | livenewssubject | Sleep | 76 | | NULL | | 17070 | windin | 127.0.0.1:45110 | livenewsselectness | Query | 1949 | update | insert into tb_livenews_industry_disk (industrycode,newsid,sourceid,channel,publishdate,lan) values(new.industrycode,new.newsid,new.sourceid,new.channel,new.publishdate,new.lan) | | 19081 | windin | 127.0.0.1:53630 | livenewsselectness | Sleep | 0 | | NULL | | 19816 | windin | 127.0.0.1:52169 | livenewsimportance | Sleep | 12 | | NULL | | 19826 | windin | 127.0.0.1:54771 | livenewscommon | Sleep | 107 | | NULL | | 19832 | windin | 127.0.0.1:54978 | livenewscommon | Sleep | 2 | | NULL | | 19833 | windin | 127.0.0.1:54979 | livenewscommon | Sleep | 0 | | NULL | | 19834 | windin | 127.0.0.1:55148 | livenewsthird | Sleep | 0 | | NULL | | 19835 | windin | 127.0.0.1:55154 | livenewsselectness | Sleep | 74 | | NULL | | 19844 | windin | 10.100.1.72:34170 | NULL | Query | 0 | NULL | show full processlist | | 19845 | windin | 127.0.0.1:49152 | livenewscommon | Sleep | 107 | | NULL | | 19846 | windin | 127.0.0.1:49153 | livenewscommon | Sleep | 107 | | NULL | | 19847 | windin | 127.0.0.1:49155 | livenewscommon | Sleep | 107 | | NULL | | 19848 | windin | 127.0.0.1:49156 | livenewscommon | Sleep | 0 | | NULL | | 19849 | windin | 127.0.0.1:49159 | livenewscommon | Sleep | 3 | | NULL | | 19850 | windin | 127.0.0.1:49217 | livenewsthird | Sleep | 2 | | NULL | | 19851 | windin | 127.0.0.1:49227 | livenewssubject | Sleep | 0 | | NULL | | 19852 | windin | 127.0.0.1:49228 | livenewsselectness | Sleep | 8 | | NULL | +-------+-----------------+-------------------+--------------------+---------+-------+------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 20 rows in set (0.01 sec)
[16 Sep 2009 2:31]
jim chen
===================================== 090916 10:09:08 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 5 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 757, signal count 749 Mutex spin waits 0, rounds 3327, OS waits 78 RW-shared spins 1233, OS waits 615; RW-excl spins 62, OS waits 62 ------------ TRANSACTIONS ------------ Trx id counter 0 20200641 Purge done for trx's n:o < 0 20199313 undo n:o < 0 0 History list length 3 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0 0, not started, process no 31919, OS thread id 1147271488 MySQL thread id 19858, query id 8394719 localhost root show innodb status ---TRANSACTION 0 0, not started, process no 31919, OS thread id 1150998848 MySQL thread id 19844, query id 8382896 10.100.1.72 windin ---TRANSACTION 0 0, not started, process no 31919, OS thread id 1141946688 MySQL thread id 19854, query id 8391879 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 31919, OS thread id 1147537728 MySQL thread id 19852, query id 8388586 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 31919, OS thread id 1148336448 MySQL thread id 19851, query id 8394434 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 31919, OS thread id 1142479168 MySQL thread id 19850, query id 8393421 127.0.0.1 windin ---TRANSACTION 0 20200639, not started, process no 31919, OS thread id 1142212928 MySQL thread id 19835, query id 8393799 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 31919, OS thread id 1144875328 MySQL thread id 19834, query id 8384065 127.0.0.1 windin ---TRANSACTION 0 20200640, not started, process no 31919, OS thread id 1145940288 MySQL thread id 19816, query id 8364013 127.0.0.1 windin ---TRANSACTION 0 20200636, not started, process no 31919, OS thread id 1146472768 MySQL thread id 19081, query id 8394708 127.0.0.1 windin Opening tables SHOW FULL COLUMNS FROM "livenewsselectness"."tb_livenews_disk" ---TRANSACTION 0 20200323, not started, process no 31919, OS thread id 1145674048 MySQL thread id 14538, query id 8328076 127.0.0.1 windin ---TRANSACTION 0 20192792, not started, process no 31919, OS thread id 1146206528 MySQL thread id 12156, query id 8394668 127.0.0.1 windin ---TRANSACTION 0 20200627, ACTIVE 2049 sec, process no 31919, OS thread id 1144609088, thread declared inside InnoDB 500 mysql tables in use 1, locked 1 1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1 MySQL thread id 17070, query id 7944922 127.0.0.1 windin update insert into tb_livenews_industry_disk (industrycode,newsid,sourceid,channel,publishdate,lan) values(new.industrycode,new.newsid,new.sourceid,new.channel,new.publishdate,new.lan) -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (write thread) Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 11562 OS file reads, 21203 OS file writes, 7317 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 33, seg size 35, 99 inserts, 99 merged recs, 74 merges Hash table size 8850487, node heap has 2 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 1 2526135212 Log flushed up to 1 2526135212 Last checkpoint at 1 2526135212 0 pending log writes, 0 pending chkp writes 2566 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 4787954888; in additional pool allocated 12152832 Dictionary memory allocated 256760 Buffer pool size 262144 Free buffers 250392 Database pages 11750 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 11614, created 136, written 18574 0.00 reads/s, 0.00 creates/s, 0.00 writes/s No buffer pool page gets since the last printout -------------- ROW OPERATIONS -------------- 1 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Main thread process no. 31919, id 1140881728, state: waiting for server activity Number of rows inserted 24000, updated 10, deleted 3093, read 2605502 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================
[16 Sep 2009 9:15]
jim chen
the processlist when lock
Attachment: processlist.txt (text/plain), 18.22 KiB.
[16 Sep 2009 9:15]
jim chen
innodb status when lock
Attachment: innodbstatus.txt (text/plain), 4.49 KiB.
[21 Nov 2009 16:58]
Valeriy Kravchuk
Please, send the results of: show create table tb_livenews_section_disk\G Do you have any triggers on this table or triggers that modifies this table? In any case, there is no deadlock. I see INSERT into this table, likely - from trigger, and a lot of blocked SELECTs from another table. We have to find out how these table are related.
[22 Dec 2009 0:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
Description: insert into an innodb table,sametime dead lock. I create a memory table,and create delete,update,insert triggers on it,the trigger's function is save the memory table's data to the innodb table,when mysql restart,the server auto reload data from innodb to memory table. there only one thread insert data to memory table,bug have 30+ connections query data,if insert into innodb lock(dead),the memory is lock. show innodb status; ===================================== 090914 8:41:26 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 4 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 4168, signal count 3929 Mutex spin waits 0, rounds 525823, OS waits 418 RW-shared spins 7108, OS waits 2960; RW-excl spins 10727, OS waits 647 ------------ TRANSACTIONS ------------ Trx id counter 0 19830663 Purge done for trx's n:o < 0 19830606 undo n:o < 0 0 History list length 32 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0 0, not started, process no 12172, OS thread id 1148336448 MySQL thread id 74774, query id 62734442 localhost root show innodb status ---TRANSACTION 0 0, not started, process no 12172, OS thread id 1144609088 MySQL thread id 74768, query id 62734351 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 12172, OS thread id 1146206528 MySQL thread id 74758, query id 62670294 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 12172, OS thread id 1145141568 MySQL thread id 74757, query id 62717987 127.0.0.1 windin ---TRANSACTION 0 19830662, not started, process no 12172, OS thread id 1143544128 MySQL thread id 74756, query id 62733433 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 12172, OS thread id 1142745408 MySQL thread id 74752, query id 62717989 127.0.0.1 windin ---TRANSACTION 0 19830661, not started, process no 12172, OS thread id 1150200128 MySQL thread id 74750, query id 62734426 127.0.0.1 windin ---TRANSACTION 0 0, not started, process no 12172, OS thread id 1147537728 MySQL thread id 73462, query id 62727935 127.0.0.1 windin ---TRANSACTION 0 19830472, not started, process no 12172, OS thread id 1147271488 MySQL thread id 71560, query id 62734441 127.0.0.1 windin Opening tables SHOW FULL COLUMNS FROM "livenewscommon"."tb_livenews_disk" ---TRANSACTION 0 19830659, not started, process no 12172, OS thread id 1148070208 MySQL thread id 71521, query id 62731409 127.0.0.1 windin ---TRANSACTION 0 19830642, not started, process no 12172, OS thread id 1148868928 MySQL thread id 68369, query id 62734402 127.0.0.1 windin ---TRANSACTION 0 19825868, not started, process no 12172, OS thread id 1143810368 MySQL thread id 68357, query id 62734113 127.0.0.1 windin ---TRANSACTION 0 19830649, ACTIVE 3898 sec, process no 12172, OS thread id 1148602688, thread declared inside InnoDB 500 mysql tables in use 1, locked 1 1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 1 MySQL thread id 71966, query id 61844219 127.0.0.1 windin update insert into tb_livenews_industry_disk (industrycode,newsid,sourceid,channel,publishdate,lan) values(new.industrycode,new.newsid,new.sourceid,new.channel,new.publishdate,new.lan) -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (write thread) Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 13314 OS file reads, 61609 OS file writes, 23136 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 33, seg size 35, 84 inserts, 84 merged recs, 64 merges Hash table size 8850487, node heap has 260 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 1 2450820029 Log flushed up to 1 2450820029 Last checkpoint at 1 2450820029 0 pending log writes, 0 pending chkp writes 7404 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 4787954888; in additional pool allocated 12373504 Dictionary memory allocated 256760 Buffer pool size 262144 Free buffers 247823 Database pages 14061 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 13511, created 550, written 55145 0.00 reads/s, 0.00 creates/s, 0.00 writes/s No buffer pool page gets since the last printout -------------- ROW OPERATIONS -------------- 1 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Main thread process no. 12172, id 1140881728, state: waiting for server activity Number of rows inserted 91821, updated 348, deleted 119659, read 10809979 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ How to repeat: server:CPU*8 memory 8G /*==============================================================*/ /* Table: tb_livenews_section_mem */ /*==============================================================*/ create table tb_livenews_section_mem ( section varchar(20) not null, newsid int not null, sourceid mediumint not null default 0, channel smallint not null default 0, publishdate timestamp not null default current_timestamp on update current_timestamp, lan smallint not null default 0, index using hash(section), index using hash(sourceid), index using hash(channel), primary key (section, newsid) ) type = memory; /*==============================================================*/ /* Index: ix_tb_livenews_section_mem_source */ /*==============================================================*/ create index ix_tb_livenews_section_mem_source using hash on tb_livenews_section_mem ( section, sourceid ); /*==============================================================*/ /* Index: ix_tb_livenews_section_mem_channel */ /*==============================================================*/ create index ix_tb_livenews_section_mem_channel on tb_livenews_section_mem ( channel, section, sourceid ); /*==============================================================*/ /* Table: tb_livenews_section_disk */ /*==============================================================*/ create table tb_livenews_section_disk ( section varchar(20) not null, newsid int not null, sourceid mediumint not null default 0, channel smallint not null default 0, publishdate timestamp not null default current_timestamp, lan smallint not null default 0, primary key (section, newsid) ) type = innodb; /*-- tb_livenews_section_mem's trigger --*/ DROP TRIGGER /*!50032 IF EXISTS */ tr_livenews_section_mem_insert$$ DROP TRIGGER /*!50032 IF EXISTS */ tr_livenews_section_mem_update$$ DROP TRIGGER /*!50032 IF EXISTS */ tr_livenews_section_mem_delete$$ CREATE TRIGGER tr_livenews_section_mem_insert AFTER INSERT ON tb_livenews_section_mem FOR EACH ROW BEGIN if (@disable_trigger is null) then insert into tb_livenews_section_disk (section,newsid,sourceid,channel,publishdate,lan) values(new.section,new.newsid,new.sourceid,new.channel,new.publishdate,new.lan); end if; END; $$ CREATE TRIGGER tr_livenews_section_mem_update AFTER UPDATE ON tb_livenews_section_mem FOR EACH ROW BEGIN if (@disable_trigger is null) then update tb_livenews_section_disk set section=new.section,newsid=new.newsid,sourceid=new.sourceid, channel=new.channel,publishdate=new.publishdate,lan=new.lan where section=old.section and newsid=old.newsid; end if; END; $$ CREATE TRIGGER tr_livenews_section_mem_delete AFTER DELETE ON tb_livenews_section_mem FOR EACH ROW BEGIN if (@disable_trigger is null) then delete from tb_livenews_section_disk where section=old.section and newsid=old.newsid; end if; END; $$ how to do: one thread insert into tb_livenews_section_mem 30+ threads select from tb_livenews_section_mem select distinct newsid from tb_livenews_section_mem where section='same value' order by publishdate desc limit ?,? one day or two days where dead lock