Mam dziwny problem, którego nie mogę rozwiązać. Jestem raczej programistą sieciowym niż administratorem serwera / bazy danych, więc mam nadzieję, że ktoś tutaj może mi pomóc.
Sytuacja
Pracuję w systemie, który obsługuje wiele update, inserti deleteprośby. Z tego powodu wybrałem INNODB jako silnik pamięci masowej ze względu na możliwość blokowania wierszy. Aktualizujemy 60 000 rekordów co 10 minut, używając Gearman do równoległego wykonywania naszej pracy na różnych serwerach. Kod jest w PHP i używamy Zend Framework.
Problem
SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transactionPowyższy błąd pojawia się prawie co 30 minut od jednego z naszych pracowników Gearman.
The mysql_report
MySQL 5.1.63-0+squeeze1 uptime 15 9:52:12 Tue Sep 11 21:25:23 2012
__ Key _________________________________________________________________
Buffer used 55.00k of 16.00M %Used: 0.34
Current 2.92M %Usage: 18.24
Write hit 99.95%
Read hit 100.00%
__ Questions ___________________________________________________________
Total 122.05M 91.7/s
DMS 106.63M 80.1/s %Total: 87.37
Com_ 10.23M 7.7/s 8.38
COM_QUIT 4.05M 3.0/s 3.32
QC Hits 1.09M 0.8/s 0.90
+Unknown 47.77k 0.0/s 0.04
Slow 2 s 11.14M 8.4/s 9.13 %DMS: 10.45 Log: ON
DMS 106.63M 80.1/s 87.37
INSERT 69.21M 52.0/s 56.70 64.90
UPDATE 22.94M 17.2/s 18.79 21.51
DELETE 11.19M 8.4/s 9.17 10.49
SELECT 3.30M 2.5/s 2.70 3.09
REPLACE 0 0/s 0.00 0.00
Com_ 10.23M 7.7/s 8.38
set_option 4.11M 3.1/s 3.37
show_fields 3.44M 2.6/s 2.82
begin 1.33M 1.0/s 1.09
__ SELECT and Sort _____________________________________________________
Scan 4.31M 3.2/s %SELECT: 130.57
Range 52 0.0/s 0.00
Full join 24 0.0/s 0.00
Range check 0 0/s 0.00
Full rng join 1 0.0/s 0.00
Sort scan 31.98k 0.0/s
Sort range 2.05M 1.5/s
Sort mrg pass 0 0/s
__ Query Cache _________________________________________________________
Memory usage 849.84k of 16.00M %Used: 5.19
Block Fragmnt 1.57%
Hits 1.09M 0.8/s
Inserts 2.52M 1.9/s
Insrt:Prune 1.83k:1 1.9/s
Hit:Insert 0.43:1
__ Table Locks _________________________________________________________
Waited 764 0.0/s %Total: 0.00
Immediate 106.63M 80.1/s
__ Tables ______________________________________________________________
Open 128 of 128 %Cache: 100.00
Opened 4.82k 0.0/s
__ Connections _________________________________________________________
Max used 301 of 300 %Max: 100.33
Total 4.05M 3.0/s
__ Created Temp ________________________________________________________
Disk table 3.44M 2.6/s
Table 3.44M 2.6/s Size: 32.0M
File 5 0.0/s
__ Threads _____________________________________________________________
Running 20 of 89
Cached 4 of 8 %Hit: 97.29
Created 109.59k 0.1/s
Slow 0 0/s
__ Aborted _____________________________________________________________
Clients 2.95k 0.0/s
Connects 3.22k 0.0/s
__ Bytes _______________________________________________________________
Sent 13.61G 10.2k/s
Received 26.90G 20.2k/s
__ InnoDB Buffer Pool __________________________________________________
Usage 89.62M of 1.46G %Used: 5.97
Read hit 100.00%
Pages
Free 90.26k %Total: 94.03
Data 5.24k 5.46 %Drty: 2.79
Misc 498 0.52
Latched 0 0.00
Reads 728.62G 547.2k/s
From file 816 0.0/s 0.00
Ahead Rnd 3 0.0/s
Ahead Sql 27 0.0/s
Writes 715.15M 537.1/s
Flushes 11.91M 8.9/s
Wait Free 0 0/s
__ InnoDB Lock _________________________________________________________
Waits 1008791 0.8/s
Current 18
Time acquiring
Total 184022524 ms
Average 18241 ms
Max 59096 ms
__ InnoDB Data, Pages, Rows ____________________________________________
Data
Reads 919 0.0/s
Writes 14.17M 10.6/s
fsync 7.40M 5.6/s
Pending
Reads 0
Writes 0
fsync 0
Pages
Created 43.90k 0.0/s
Read 2.64k 0.0/s
Written 11.91M 8.9/s
Rows
Deleted 47.34M 35.6/s
Inserted 49.70M 37.3/s
Read 639.52G 480.3k/s
Updated 56.33M 42.3/sKod
$this->db->beginTransaction();
try {
for($i = 0; $i < count($products); $i++)
{
$this->db->query("UPDATE userproducts SET lowest_price= :p1, last_lowest_price_update='".date("Y-m-d H:i:s", time())."' WHERE product_id = :p2", array(
'p1' => $products[$i]['price_total_end'][1],
'p2' => $products[$i]['asin']));
}
$this->db->commit();
} catch (Exception $e) {
$this->db->rollBack();
echo $e->getMessage();
}
$this->db->closeConnection();To jest kod, aby zaktualizować jedną tabelę. Mamy podobny kod do aktualizacji kolejnej tabeli. Przy powyższym kodzie, zatwierdzamy 50 żądań za każdym razem, gdy wywoływana jest ta metoda, co będzie robione co 30 sekund przez prawie 20 pracowników.
Jeszcze więcej informacji
mysqladmin status
Uptime: 6770 Threads: 109 Questions: 857696 Slow queries: 52469 Opens: 1382 Flush tables: 1 Open tables: 128 Queries per second avg: 126.690mysql> SHOW STATUS LIKE 'Open%';
+--------------------------+-------+
| Variable_name | Value |
+--------------------------+-------+
| Open_files | 21 |
| Open_streams | 0 |
| Open_table_definitions | 230 |
| Open_tables | 128 |
| Opened_files | 71653 |
| Opened_table_definitions | 0 |
| Opened_tables | 0 |
+--------------------------+-------+
7 rows in set (0.00 sec)mysql> SHOW CREATE TABLE userproducts\G
*************************** 1. row ***************************
Table: userproducts
Create Table: CREATE TABLE `userproducts` (
`id` int(20) NOT NULL AUTO_INCREMENT,
`userinfos_id` int(12) NOT NULL,
`seller_sku` varchar(35) COLLATE utf8_bin NOT NULL,
`product_id` varchar(20) COLLATE utf8_bin NOT NULL,
`price` float(8,2) NOT NULL,
`shipping` float(6,2) NOT NULL DEFAULT '0.00',
`alter_preis` float(8,2) DEFAULT NULL,
`ek_price` float(8,2) NOT NULL DEFAULT '-1.00',
`quantity` int(5) NOT NULL DEFAULT '0',
`lowest_price` float(8,2) DEFAULT NULL,
`titel` varchar(255) CHARACTER SET utf8 COLLATE utf8_unicode_ci NOT NULL DEFAULT 'n/a',
`url` varchar(255) COLLATE utf8_bin DEFAULT NULL,
`sales_rank` int(8) DEFAULT NULL,
`kategorie` varchar(255) COLLATE utf8_bin DEFAULT NULL,
`kategorie_2` varchar(255) COLLATE utf8_bin DEFAULT NULL,
`kategorie_3` varchar(255) COLLATE utf8_bin DEFAULT NULL,
`optimierung` int(1) NOT NULL DEFAULT '0',
`indi` int(1) DEFAULT '0',
`akt_festpreis` int(1) DEFAULT '0',
`new` int(1) DEFAULT '1',
`locked` int(1) DEFAULT '0',
`determined` int(1) DEFAULT '0',
`deleted` tinyint(1) NOT NULL DEFAULT '0',
`a_m_preis` float(8,2) DEFAULT NULL,
`a_h_preis` float(8,2) DEFAULT NULL,
`m_preis` float(8,2) NOT NULL DEFAULT '0.00',
`h_preis` float(8,2) NOT NULL DEFAULT '0.00',
`preisabstand` float(6,2) DEFAULT '0.00',
`preisabstand_art` varchar(12) COLLATE utf8_bin DEFAULT 'euro',
`festpreis` float(8,2) DEFAULT '0.00',
`last_update` datetime NOT NULL,
`last_lowest_price_update` datetime DEFAULT NULL,
PRIMARY KEY (`id`),
UNIQUE KEY `seller_sku_by_seller` (`userinfos_id`,`seller_sku`),
KEY `userinfos_id` (`userinfos_id`)
) ENGINE=InnoDB AUTO_INCREMENT=32301793 DEFAULT CHARSET=utf8 COLLATE=utf8_bin
1 row in set (0.00 sec)mysql> SHOW GLOBAL VARIABLES LIKE 'innodb%'\G
*************************** 1. row ***************************
Variable_name: innodb_adaptive_hash_index
Value: ON
*************************** 2. row ***************************
Variable_name: innodb_additional_mem_pool_size
Value: 104857600
*************************** 3. row ***************************
Variable_name: innodb_autoextend_increment
Value: 8
*************************** 4. row ***************************
Variable_name: innodb_autoinc_lock_mode
Value: 1
*************************** 5. row ***************************
Variable_name: innodb_buffer_pool_size
Value: 1572864000
*************************** 6. row ***************************
Variable_name: innodb_checksums
Value: ON
*************************** 7. row ***************************
Variable_name: innodb_commit_concurrency
Value: 0
*************************** 8. row ***************************
Variable_name: innodb_concurrency_tickets
Value: 500
*************************** 9. row ***************************
Variable_name: innodb_data_file_path
Value: ibdata1:1G;ibdata2:1G;ibdata3:1G:autoextend
*************************** 10. row ***************************
Variable_name: innodb_data_home_dir
Value: /var/lib/mysql/
*************************** 11. row ***************************
Variable_name: innodb_doublewrite
Value: ON
*************************** 12. row ***************************
Variable_name: innodb_fast_shutdown
Value: 1
*************************** 13. row ***************************
Variable_name: innodb_file_io_threads
Value: 4
*************************** 14. row ***************************
Variable_name: innodb_file_per_table
Value: ON
*************************** 15. row ***************************
Variable_name: innodb_flush_log_at_trx_commit
Value: 1
*************************** 16. row ***************************
Variable_name: innodb_flush_method
Value:
*************************** 17. row ***************************
Variable_name: innodb_force_recovery
Value: 0
*************************** 18. row ***************************
Variable_name: innodb_lock_wait_timeout
Value: 50
*************************** 19. row ***************************
Variable_name: innodb_locks_unsafe_for_binlog
Value: OFF
*************************** 20. row ***************************
Variable_name: innodb_log_buffer_size
Value: 26214400
*************************** 21. row ***************************
Variable_name: innodb_log_file_size
Value: 314572800
*************************** 22. row ***************************
Variable_name: innodb_log_files_in_group
Value: 2
*************************** 23. row ***************************
Variable_name: innodb_log_group_home_dir
Value: ./
*************************** 24. row ***************************
Variable_name: innodb_max_dirty_pages_pct
Value: 90
*************************** 25. row ***************************
Variable_name: innodb_max_purge_lag
Value: 0
*************************** 26. row ***************************
Variable_name: innodb_mirrored_log_groups
Value: 1
*************************** 27. row ***************************
Variable_name: innodb_open_files
Value: 300
*************************** 28. row ***************************
Variable_name: innodb_rollback_on_timeout
Value: OFF
*************************** 29. row ***************************
Variable_name: innodb_stats_method
Value: nulls_equal
*************************** 30. row ***************************
Variable_name: innodb_stats_on_metadata
Value: ON
*************************** 31. row ***************************
Variable_name: innodb_support_xa
Value: ON
*************************** 32. row ***************************
Variable_name: innodb_sync_spin_loops
Value: 20
*************************** 33. row ***************************
Variable_name: innodb_table_locks
Value: ON
*************************** 34. row ***************************
Variable_name: innodb_thread_concurrency
Value: 8
*************************** 35. row ***************************
Variable_name: innodb_thread_sleep_delay
Value: 10000
*************************** 36. row ***************************
Variable_name: innodb_use_legacy_cardinality_algorithm
Value: ON
36 rows in set (0.00 sec)mysql> SHOW ENGINE INNODB STATUS\G
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
120912 17:15:21 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 37 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 257219, signal count 242756
--Thread 47843758212864 has waited at ../../../storage/innobase/lock/lock0lock.c line 5108 for 0.00 seconds the semaphore:
Mutex at 0x2b82ed8712b8 created file ../../../storage/innobase/srv/srv0srv.c line 891, lock var 0
waiters flag 0
Mutex spin waits 0, rounds 125510621, OS waits 136209
RW-shared spins 100480, OS waits 14880; RW-excl spins 164568, OS waits 4813
------------------------
LATEST DETECTED DEADLOCK
------------------------
120912 17:14:59
*** (1) TRANSACTION:
TRANSACTION 0 20639503, ACTIVE 8 sec, process no 1655, OS thread id 47843745568512 fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 700 lock struct(s), heap size 63472, 38097 row lock(s), undo log entries 2
MySQL thread id 99112, query id 2086869 s16468810.onlinehome-server.info 87.106.82.83 web0 Updating
UPDATE userproducts SET lowest_price=44.9, last_lowest_price_update='2012-09-12 17:14:53' WHERE product_id LIKE 'B007J20HN2'
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 985 n bits 136 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639503 lock_mode X waiting
Record lock, heap no 60 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
[SOME STRANGE CHARAKTERS LIKE ABOVE]
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 985 n bits 136 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639496 lock_mode X locks rec but not gap waiting
Record lock, heap no 59 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
0: len 4; hex 815d9f43; asc ] C;; 1: len 6; hex 0000013ae793; asc : ;; 2: len 7; hex 000000002d01e9; asc - ;; 3: len 4; hex 80006f9a; asc o ;; 4: len 12; hex 30302d3956335a2d47555a34; asc 00-9V3Z-GUZ4;; 5: len 10; hex 42303032414c38463732; asc B002AL8F72;; 6: len 4; hex cdccdb42; asc B;; 7: len 4; hex 00000000; asc ;; 8: len 4; hex cdccdb42; asc B;; 9: len 4; hex 000080bf; asc ;; 10: len 4; hex 800003e7; asc ;; 11: len 4; hex cdccdb42; asc B;; 12: len 30; hex 537572706c75732056696e74616765204a61636b65204d36352052656769; asc Surplus Vintage Jacke M65 Regi;...(truncated); 13: len 30; hex 687474703a2f2f6563782e696d616765732d616d617a6f6e2e636f6d2f69; asc http://ecx.images-amazon.com/i;...(truncated); 14: len 4; hex 800034c5; asc 4 ;; 15: len 10; hex 42656b6c656964756e67; asc Bekleidung;; 16: len 3; hex 4e2f41; asc N/A;; 17: len 3; hex 4e2f41; asc N/A;; 18: len 4; hex 80000000; asc ;; 19: len 4; hex 80000000; asc ;; 20: len 4; hex 80000000; asc ;; 21: len 4; hex 80000000; asc ;; 22: len 4; hex 80000000; asc ;; 23: len 4; hex 80000000; asc ;; 24: len 1; hex 80; asc ;; 25: SQL NULL; 26: SQL NULL; 27: len 4; hex 00000000; asc ;; 28: len 4; hex 00000000; asc ;; 29: len 4; hex 00000000; asc ;; 30: len 4; hex 6575726f; asc euro;; 31: len 4; hex 00000000; asc ;; 32: len 8; hex 8000124cc3d28e8a; asc L ;; 33: len 8; hex 8000124cc3d28fc6; asc L ;;
*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 0 20639610
Purge done for trx's n:o < 0 20639595 undo n:o < 0 0
History list length 4
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 1655, OS thread id 47843726903040
MySQL thread id 99216, query id 2090678 localhost root
SHOW ENGINE INNODB STATUS
---TRANSACTION 0 20639607, not started, process no 1655, OS thread id 47843746371328
--- [ SOME MORE LIKE THESE ]
---TRANSACTION 0 20527676, not started, process no 1655, OS thread id 47843739748096
MySQL thread id 1340, query id 5247 s16468807.onlinehome-server.info 87.106.72.226 web0
---TRANSACTION 0 20639609, ACTIVE 0 sec, process no 1655, OS thread id 47843728910080 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1216, 2 row lock(s)
MySQL thread id 99095, query id 2090662 s16468809.onlinehome-server.info 87.106.82.94 web0 Updating
UPDATE `userproducts` SET `locked` = '0' WHERE (userinfos_id = '28565')
------- TRX HAS BEEN WAITING 0 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 985 n bits 136 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639609 lock_mode X locks rec but not gap waiting
Record lock, heap no 57 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
0: len 4; hex 8158219b; asc X! ;; 1: len 6; hex 0000013aeebe; asc : ;; 2: len 7; hex 000000003208b2; asc 2 ;; 3: len 4; hex 80006f95; asc o ;; 4: len 12; hex 32592d50484d342d54475458; asc 2Y-PHM4-TGTX;; 5: len 10; hex 42303031314246525832; asc B0011BFRX2;; 6: len 4; hex 00004040; asc @@;; 7: len 4; hex 00004040; asc @@;; 8: len 4; hex 00004040; asc @@;; 9: len 4; hex 000080bf; asc ;; 10: len 4; hex 80000001; asc ;; 11: len 4; hex 33330741; asc 33 A;; 12: len 21; hex 5b556e62656b616e6e7465722045696e62616e645d; asc [Unbekannter Einband];; 13: len 30; hex 687474703a2f2f6563782e696d616765732d616d617a6f6e2e636f6d2f69; asc http://ecx.images-amazon.com/i;...(truncated); 14: len 4; hex 800d67f7; asc g ;; 15: len 1; hex 42; asc B;; 16: len 3; hex 4e2f41; asc N/A;; 17: len 3; hex 4e2f41; asc N/A;; 18: len 4; hex 80000000; asc ;; 19: len 4; hex 80000000; asc ;; 20: len 4; hex 80000000; asc ;; 21: len 4; hex 80000000; asc ;; 22: len 4; hex 80000000; asc ;; 23: len 4; hex 80000000; asc ;; 24: len 1; hex 80; asc ;; 25: SQL NULL; 26: SQL NULL; 27: len 4; hex 00000000; asc ;; 28: len 4; hex 00000000; asc ;; 29: len 4; hex 00000000; asc ;; 30: len 4; hex 6575726f; asc euro;; 31: len 4; hex 00000000; asc ;; 32: len 8; hex 8000124cc3758ea7; asc L u ;; 33: len 8; hex 8000124cc3d291b5; asc L ;;
------------------
[SOME MORE OF THESE]
------------------
---TRANSACTION 0 20639544, ACTIVE 22 sec, process no 1655, OS thread id 47843758212864 fetching rows, thread declared inside InnoDB 158
mysql tables in use 1, locked 1
60 lock struct(s), heap size 6752, 5861 row lock(s), undo log entries 29
MySQL thread id 99161, query id 2090677 s16468810.onlinehome-server.info 87.106.82.83 web0 Updating
UPDATE userproducts SET shipping=0, last_lowest_price_update='2012-09-12 17:15:22' WHERE product_id LIKE 'B00851I800' AND userinfos_id=28570
---TRANSACTION 0 20639538, ACTIVE 24 sec, process no 1655, OS thread id 47843733726976 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
MySQL thread id 99159, query id 2088002 s16468808.onlinehome-server.info 87.106.82.91 web0 Updating
UPDATE userproducts SET lowest_price=10.69, last_lowest_price_update='2012-09-12 17:14:59' WHERE product_id LIKE 'B0065JFS2U'
------- TRX HAS BEEN WAITING 24 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 6 n bits 120 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639538 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
[ SAME STRANGE CHARAKTERS]
------------------
---TRANSACTION 0 20639510, ACTIVE 29 sec, process no 1655, OS thread id 47843554330368 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
MySQL thread id 99119, query id 2086898 s16468808.onlinehome-server.info 87.106.82.91 web0 Updating
UPDATE userproducts SET lowest_price=50.8, last_lowest_price_update='2012-09-12 17:14:53' WHERE product_id LIKE 'B002MPPOUC'
------- TRX HAS BEEN WAITING 29 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 6 n bits 120 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639510 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
0: len 4; hex 8000bb1d; asc ;; 1: len 6; hex 000001394831; asc 9H1;; 2: len 7; hex 000000003409ad; asc 4 ;; 3: len 4; hex 80000003; asc ;; 4: len 12; hex 30302d364f4e4a2d48305039; asc 00-6ONJ-H0P9;; 5: len 10; hex 42303037523531533241; asc B007R51S2A;; 6: len 4; hex d7e34243; asc BC;; 7: len 4; hex 00000000; asc ;; 8: len 4; hex d7e34243; asc BC;; 9: len 4; hex 000080bf; asc ;; 10: len 4; hex 80000003; asc ;; 11: len 4; hex d7e34243; asc BC;; 12: len 30; hex 54616765736465636b65206f646572204b697373656e2041746963612037; asc Tagesdecke oder Kissen Atica 7;...(truncated); 13: len 30; hex 687474703a2f2f6563782e696d616765732d616d617a6f6e2e636f6d2f69; asc http://ecx.images-amazon.com/i;...(truncated); 14: len 4; hex 800c7b52; asc {R;; 15: len 1; hex 4b; asc K;; 16: len 3; hex 4e2f41; asc N/A;; 17: len 3; hex 4e2f41; asc N/A;; 18: len 4; hex 80000001; asc ;; 19: len 4; hex 80000000; asc ;; 20: len 4; hex 80000000; asc ;; 21: len 4; hex 80000000; asc ;; 22: len 4; hex 80000000; asc ;; 23: len 4; hex 80000000; asc ;; 24: len 1; hex 80; asc ;; 25: SQL NULL; 26: SQL NULL; 27: len 4; hex 00000000; asc ;; 28: len 4; hex 00000000; asc ;; 29: len 4; hex 00000000; asc ;; 30: len 4; hex 6575726f; asc euro;; 31: len 4; hex 00000000; asc ;; 32: len 8; hex 8000124cc3b3ba08; asc L ;; 33: len 8; hex 8000124cc3d1d42c; asc L ,;;
------------------
---TRANSACTION 0 20639508, ACTIVE 30 sec, process no 1655, OS thread id 47843558143744 fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 700 lock struct(s), heap size 63472, 38096 row lock(s)
MySQL thread id 99117, query id 2086890 s16468810.onlinehome-server.info 87.106.82.83 web0 Updating
UPDATE userproducts SET lowest_price=109.9, last_lowest_price_update='2012-09-12 17:14:53' WHERE product_id LIKE 'B002AL8F72'
------- TRX HAS BEEN WAITING 1 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 631 page no 985 n bits 136 index `PRIMARY` of table `usr_web0_1`.`userproducts` trx id 0 20639508 lock_mode X waiting
Record lock, heap no 59 PHYSICAL RECORD: n_fields 34; compact format; info bits 0
0: len 4; hex 815d9f43; asc ] C;; 1: len 6; hex 0000013aef08; asc : ;; 2: len 7; hex 00000000391358; asc 9 X;; 3: len 4; hex 80006f9a; asc o ;; 4: len 12; hex 30302d3956335a2d47555a34; asc 00-9V3Z-GUZ4;; 5: len 10; hex 42303032414c38463732; asc B002AL8F72;; 6: len 4; hex cdccdb42; asc B;; 7: len 4; hex 00000000; asc ;; 8: len 4; hex cdccdb42; asc B;; 9: len 4; hex 000080bf; asc ;; 10: len 4; hex 800003e7; asc ;; 11: len 4; hex cdccdb42; asc B;; 12: len 30; hex 537572706c75732056696e74616765204a61636b65204d36352052656769; asc Surplus Vintage Jacke M65 Regi;...(truncated); 13: len 30; hex 687474703a2f2f6563782e696d616765732d616d617a6f6e2e636f6d2f69; asc http://ecx.images-amazon.com/i;...(truncated); 14: len 4; hex 800034c5; asc 4 ;; 15: len 10; hex 42656b6c656964756e67; asc Bekleidung;; 16: len 3; hex 4e2f41; asc N/A;; 17: len 3; hex 4e2f41; asc N/A;; 18: len 4; hex 80000000; asc ;; 19: len 4; hex 80000000; asc ;; 20: len 4; hex 80000000; asc ;; 21: len 4; hex 80000000; asc ;; 22: len 4; hex 80000000; asc ;; 23: len 4; hex 80000000; asc ;; 24: len 1; hex 80; asc ;; 25: SQL NULL; 26: SQL NULL; 27: len 4; hex 00000000; asc ;; 28: len 4; hex 00000000; asc ;; 29: len 4; hex 00000000; asc ;; 30: len 4; hex 6575726f; asc euro;; 31: len 4; hex 00000000; asc ;; 32: len 8; hex 8000124cc3d291ec; asc L ;; 33: len 8; hex 8000124cc3d28fc6; asc L ;;
------------------
--------
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
2714 OS file reads, 202235 OS file writes, 95816 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 8.70 writes/s, 4.68 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2,
0 inserts, 0 merged recs, 0 merges
Hash table size 3112859, node heap has 344 buffer(s)
7394.83 hash searches/s, 930.22 non-hash searches/s
---
LOG
---
Log sequence number 14 2880311684
Log flushed up to 14 2880309944
Last checkpoint at 14 2880298289
0 pending log writes, 0 pending chkp writes
83150 log i/o's done, 3.89 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 1884360120; in additional pool allocated 21052672
Dictionary memory allocated 1087464
Buffer pool size 96000
Free buffers 90835
Database pages 4818
Modified db pages 26
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 4102, created 716, written 187723
0.00 reads/s, 0.00 creates/s, 8.05 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
1 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 1655, id 47843546388224, state: sleeping
Number of rows inserted 844694, updated 784400, deleted 836993, read 11188899916
15.40 inserts/s, 87.40 updates/s, 12.51 deletes/s, 253212.99 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
1 row in set (0.01 sec)Pytania
Co w tym raporcie wygląda dziwnie? Dla mnie nie wygląda na to, że kończy nam się pamięć.
Co nie rozumiem jest danych InnoDB, Pages, Rows > Rows > Read. Dlaczego jest 480 000 odczytów na sekundę? Co to znaczy? I wydaje mi się, że są tylko 42 aktualizacje na sekundę, co nie jest tak szybkie.
Co powiesz na otwarte tabele lub pliki. Czy to zwykła wartość? Nie miałem doświadczenia w tym temacie.
Coś nie działa zgodnie z oczekiwaniami i mam nadzieję, że ktoś tutaj pomoże mi to znaleźć.
mysql
performance
innodb
M. Hirn
źródło
źródło
SHOW ENGINE INNODB STATUS;wyjściu?SHOW CREATE TABLE userproducts\G, 2) Proszę opublikować dane wyjścioweSHOW GLOBAL VARIABLES LIKE 'innodb%'\G, 3) Pytanie: Czy zainstalowałeś wtyczkę innodb ?, 4) ProszęSHOW ENGINE INNODB STATUS\GSHOW ENGINE INNODB STATUS\Gopublikować całego wyniku, ponieważ mogę przydzielić tylko tekst zawierający 30 000 liter. Więc musiałem coś pominąć. Pytanie 3) Co przez to rozumiesz? Nie zainstalowałem niczego, po prostu ustawiłem silnik tabeli na innodb.Odpowiedzi:
OBSERWACJA # 1
Po prostu patrząc na dane wyjściowe,
SHOW ENGINE INNODB STATUS\Gna dole każdej transakcji widzę różne komunikaty o blokadzie tabeli. Masz jedną transakcję zawierającą blokadę 38096 wierszyOBSERWACJA # 2
Patrząc wstecz na strukturę tabeli, widzę, że
userproductstabela nie ma indeksuproduct_id. Z tego powodu wykonuje się pełne skanowanie tabeli, aby wykonać aktualizację pojedynczego wiersza.OBSERWACJA # 3
Masz również zduplikowany indeks w
userproductstabeli. Dwa indeksy zaczynają się oduserinfos_idkolumny. Nie ma potrzeby rozszerzania indeksów za pomocą duplikatów wiodących kolumn.OBSERWACJA # 4
Masz innodb_thread_concurrency = 8. Powinien być ustawiony na zero dla nieskończonej współbieżności
Zobacz moje poprzednie posty na ten temat
May 26, 2011: O wydajności baz danych jednowątkowych i wielowątkowychSep 12, 2011: Czy można zmusić MySQL do korzystania z więcej niż jednego rdzenia?Feb 24, 2012: Strojenie dedykowanego serwera Percona za pomocą XtraDB dla OLTPMar 16, 2012: Używanie wielu rdzeni dla pojedynczych zapytań MySQL na DebianieZALECENIE # 1
Dodaj to do /etc/my.cnf
i zrestartuj MySQL
ZALECENIE # 2
Uruchom to w okresie wolnym
ZALECENIE # 3 (Opcjonalny cel długoterminowy)
Musisz zrestrukturyzować swój układ InnoDB, ponieważ masz na nim tabelę_pliku_inodb. To eliminuje potrzebę wielu plików ibdata. Potrzebujesz tylko jednego. Zobacz moje wcześniejsze posty na ten temat:
Oct 29, 2010: Mój oryginalny post w StackOverflowApr 01, 2012: Czy zaleca się innodb_file_per_table?Mar 25, 2012: Dlaczego InnoDB przechowuje wszystkie bazy danych w jednym pliku?Feb 03, 2012: Zaplanowana optymalizacja tabel w MySQL InnoDBSpróbuj !!!
źródło
Brakujący indeks na product_id jest zdecydowanie problemem.
Może to dodatkowo zoptymalizować sytuację: posortuj swoje identyfikatory_produktu przed podzieleniem ich na wątki.
źródło
OK, po pierwsze, błąd, o który się martwisz, w
lock wait timeout exceededgruncie rzeczy mówi, że coś się nie udało, ponieważ musiał zbyt długo czekać na zwolnienie blokady. Nie ma to związku z wykorzystaniem pamięci. Jest tutaj wątek StackOverflow z dobrą [podstawową] odpowiedzią na temat ogólnego rozwiązywania tego błędu.Jak tam zobaczysz, możesz uzyskać dużą ilość danych, uruchamiając
SHOW INNODB STATUS\Gi skonfigurować czas oczekiwania blokady InnoDB na bardziej odpowiednią dla twojego przypadku użycia.Jeśli chodzi o pytania dotyczące tego, co widzisz w raporcie, cóż, 480 000 wierszy czytanych na sekundę oznacza, że średnio 480 000 wierszy bazy danych było czytanych na sekundę w okresie objętym raportem.
Nie jestem w pełni usatysfakcjonowany odpowiedzią na pytanie „co dziwnie wygląda w raporcie”, ale powiedziałbym, że prawdopodobnie będziesz musiał podać więcej informacji na temat tego, co dokładnie działa przeciwko bazie danych, aby uzyskać odpowiedź na ten temat ... ale ilekroć widzę dużą wartość odczytu, na przykład 480 tysięcy wierszy czytanych na sekundę, natychmiast zaczynam się zastanawiać, jakie zapytania lub zapytania uciekają i próbuję odczytać całą bazę danych. Być może większe doświadczenie DBA ma inne podejście, ale nie widzę w tym nic z natury dziwnego, poza liczbą
updatesicreatesniezgodnością z liczbą aktualizacji rekordów, o których mówiłeś, że wykonujesz.źródło
updates? Cóż, myślę, że 56 milionów to dużo. To, co sprawia, że czuję, że coś jest nie tak, to 640 miliardów odczytów. Co toreadsjest Czy teSELECToświadczenia?updates/ s, ale raport MySQL pokazuje tylko 42,3 / s, czyli o wiele mniej niż oczekiwano dla podanego woluminu. Nawet dodając wszystkocreates, znacznie obniżyłeś głośność, o której mówiłeś. Jeśli to dlatego, że objętość 60 000/10 minut to przybliżona liczba, która nie jest zbyt dokładna, dobrze, ale wyróżniała się dla mnie. Jeśli chodzi oreadstak,SELECTinstrukcja powodujereadsw bazie danych. Jeśli wybiera z dużej liczby wierszy, odczytuje wiele wierszy. Ale tak, wydaje mi się to bardzo wysokie.