| 2009-05-22 02:35:00 |
MadMatt |
description |
I want to track all the related data we are collecting and all the things we try in this one bug.
Basically under heavy load, innodb will start to throw random errors in secondary indexes. Here is an example of the error with some extra logging turned on:
49332298-2994417918-Innodb inside btr_cur_search_to_nth_level index myidx1 thread: 1160882512
49332299-2994417994-... S1: space: 5 page_no 4 : thread : 1160882512
49332300-2994418044-... S1: space: 3 page_no 40949 : thread : 1100904784
49332301-2994418098-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1080850768
49332302-2994418175-... S1: space: 5 page_no 3 : thread : 1080850768
49332303-2994418225-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100904784
49332304-2994418302-... S1: space: 3 page_no 3 : thread : 1100904784
49332305-2994418352-... S1: space: 5 page_no 1062 : thread : 1080850768
49332306-2994418405-... S1: space: 3 page_no 54 : thread : 1100904784
49332307-2994418456-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332308-2994418533-... S1: space: 3 page_no 40949 : thread : 1100904784
49332309-2994418587-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100904784
49332310-2994418664-... S1: space: 3 page_no 3 : thread : 1100904784
49332311-2994418714-... S1: space: 3 page_no 54 : thread : 1100904784
49332312-2994418765-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1077369168
49332313-2994418842-... S1: space: 3 page_no 40949 : thread : 1100904784
49332314-2994418896-... S1: space: 7 page_no 3 : thread : 1077369168
49332315-2994418946-... S1: space: 7 page_no 329 : thread : 1077369168
49332316-2994418998-... S1: space: 7 page_no 2825 : thread : 1077369168
49332317-2994419051-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332318:2994419128:InnoDB: error in sec index entry update in
49332319-2994419171-InnoDB: index `myidx1` of table `dbt2`... S1: space: 3 page_no 57834 : thread : 1080318288
49332320-2994419263-Innodb inside btr_cur_search_to_nth_level index GEN_CLUST_INDEX thread: 1100372304
49332321-2994419348-... S1: space: 6 page_no 3 : thread : 1100372304
49332322-2994419398-... S1: space: 6 page_no 41 : thread : 1100372304
49332323-2994419449-... S1: space: 6 page_no 5974 : thread : 1100372304
49332324-2994419502-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332325-2994419579-... S1: space: 7 page_no 3 : thread : 1100106064
49332326-2994419629-.`new_order`
49332327-2994419642-InnoDB: tuple DATA TUPLE: 3 fields;
49332328-2994419678- 0: len 4; hex 80000006; asc ... S1: space: 7 page_no 358 : thread : 1100106064
49332329-2994419763-... S1: space: 7 page_no 17866 : thread : 1100106064
49332330-2994419817-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332331-2994419894-... S1: space: 7 page_no 3 : thread : 1100106064
49332332-2994419944-;; 1: len 4; hex 80000efd; asc ... S1: space: 1 page_no 57 : thread : 1081928016
49332333-2994420029-... S1: space: 1 page_no 17623 : thread : 1081928016
49332334-2994420083-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100638544
49332335-2994420160-... S1: space: 5 page_no 3 : thread : 1100638544
49332336-2994420210-... S1: space: 5 page_no 849 : thread : 1100638544
49332337-2994420262-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1080318288
49332338-2994420339-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100638544
This will eventually crash the machine.
Yves has managed to get this to fail with 1 single warehouse on DBT2. In order to do this you need to use a tmpfs ( fast disk ) and store everything on it.
I have gotten this to appear after about 20 minutes of running a 20W test with regular disk and a 768M BP....
We appear to be hitting some event. Possibly a flush or some process that only wakes up after so many changes.
Additionally we think we may have missed a call the invalidates, reads a page, moves a block/page, or does something outside of buf_LRU_search_and_free_block & buf_read_page_low .... |
I want to track all the related data we are collecting and all the things we try in this one bug.
Basically under heavy load, innodb will start to throw random errors in secondary indexes.
here is the error:
InnoDB: error in sec index entry update in
InnoDB: index `myidx1` of table `dbt2`.`new_order`
InnoDB: tuple DATA TUPLE: 3 fields;
0: len 4; hex 80000001; asc ;;
1: len 4; hex 80000bea; asc ;;
2: len 4; hex 80000005; asc ;;
InnoDB: record PHYSICAL RECORD: n_fields 3; compact format; info bits 32
0: len 4; hex 80000001; asc ;;
1: len 4; hex 80000bea; asc ;;
2: len 4; hex 80000004; asc ;;
TRANSACTION 14469, ACTIVE 1 sec, process no 7982, OS thread id 2995481488 updating or deleting
mysql tables in use 1, locked 1
26 lock struct(s), heap size 2496, 65 row lock(s), undo log entries 60
MySQL thread id 31, query id 1246503 localhost root updating
DELETE FROM new_order
WHERE no_o_id = 3050
AND no_w_id = 1
AND no_d_id = 5
Here is an example of the error with some extra logging turned on:
49332298-2994417918-Innodb inside btr_cur_search_to_nth_level index myidx1 thread: 1160882512
49332299-2994417994-... S1: space: 5 page_no 4 : thread : 1160882512
49332300-2994418044-... S1: space: 3 page_no 40949 : thread : 1100904784
49332301-2994418098-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1080850768
49332302-2994418175-... S1: space: 5 page_no 3 : thread : 1080850768
49332303-2994418225-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100904784
49332304-2994418302-... S1: space: 3 page_no 3 : thread : 1100904784
49332305-2994418352-... S1: space: 5 page_no 1062 : thread : 1080850768
49332306-2994418405-... S1: space: 3 page_no 54 : thread : 1100904784
49332307-2994418456-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332308-2994418533-... S1: space: 3 page_no 40949 : thread : 1100904784
49332309-2994418587-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100904784
49332310-2994418664-... S1: space: 3 page_no 3 : thread : 1100904784
49332311-2994418714-... S1: space: 3 page_no 54 : thread : 1100904784
49332312-2994418765-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1077369168
49332313-2994418842-... S1: space: 3 page_no 40949 : thread : 1100904784
49332314-2994418896-... S1: space: 7 page_no 3 : thread : 1077369168
49332315-2994418946-... S1: space: 7 page_no 329 : thread : 1077369168
49332316-2994418998-... S1: space: 7 page_no 2825 : thread : 1077369168
49332317-2994419051-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332318:2994419128:InnoDB: error in sec index entry update in
49332319-2994419171-InnoDB: index `myidx1` of table `dbt2`... S1: space: 3 page_no 57834 : thread : 1080318288
49332320-2994419263-Innodb inside btr_cur_search_to_nth_level index GEN_CLUST_INDEX thread: 1100372304
49332321-2994419348-... S1: space: 6 page_no 3 : thread : 1100372304
49332322-2994419398-... S1: space: 6 page_no 41 : thread : 1100372304
49332323-2994419449-... S1: space: 6 page_no 5974 : thread : 1100372304
49332324-2994419502-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332325-2994419579-... S1: space: 7 page_no 3 : thread : 1100106064
49332326-2994419629-.`new_order`
49332327-2994419642-InnoDB: tuple DATA TUPLE: 3 fields;
49332328-2994419678- 0: len 4; hex 80000006; asc ... S1: space: 7 page_no 358 : thread : 1100106064
49332329-2994419763-... S1: space: 7 page_no 17866 : thread : 1100106064
49332330-2994419817-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100106064
49332331-2994419894-... S1: space: 7 page_no 3 : thread : 1100106064
49332332-2994419944-;; 1: len 4; hex 80000efd; asc ... S1: space: 1 page_no 57 : thread : 1081928016
49332333-2994420029-... S1: space: 1 page_no 17623 : thread : 1081928016
49332334-2994420083-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100638544
49332335-2994420160-... S1: space: 5 page_no 3 : thread : 1100638544
49332336-2994420210-... S1: space: 5 page_no 849 : thread : 1100638544
49332337-2994420262-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1080318288
49332338-2994420339-Innodb inside btr_cur_search_to_nth_level index PRIMARY thread: 1100638544
This will eventually crash the machine.
Yves has managed to get this to fail with 1 single warehouse on DBT2. In order to do this you need to use a tmpfs ( fast disk ) and store everything on it.
I have gotten this to appear after about 20 minutes of running a 20W test with regular disk and a 768M BP....
We appear to be hitting some event. Possibly a flush or some process that only wakes up after so many changes.
Additionally we think we may have missed a call the invalidates, reads a page, moves a block/page, or does something outside of buf_LRU_search_and_free_block & buf_read_page_low .... |
|
