InnoDB, внутренние блокировки, факап

Llama

Имеем следующую нагрузку:1) ~1500+ insert/sec2) ~10000 select/secКоличество "простых" update и delete не существенно.Примерно половина insert - это insert ... on duplicate key update.Размер активно используемых таблиц - 1-10M записей, повсеместно InnoDBPercona 5.5, последний билд, Debian 6 64bitКэш запросов выключен.Бинлоги, асинхронная репликация.Симптомы: периодически всё встаёт колом - список процессов занят insert и insert ... update в 2-3 наиболее активно используемые таблицы (порядка 450 запросов в списке), SHOW ENGINE INNODB STATUS работает от нескольких секунд до полутора минут, при этом CPU idle увеличивается до 99%, iowait нулевой.Затем внезапно базу отпускате, далее тихо, спокойно, idle ~30-50%, iowait иногда 1-2%, ну т.е. нормальный такой режим работы.Оборудование: 2xE2620 (итого 16 потоков выполнения), 24Gb RAM, 4xSAS RAID10 + writeback + bbuЕстественно в лог ошибок падает ругань об исчерпании коннектов, в лог медленных запросов - кучка всяческих insert'ов.Пока отправил программиста подумать над использованием "чистого" update там, где сейчас юзаются insert ... update, благо данные позволяют в некоторых наиболее используемых таблицах в большей части случаев "попадать" сразу update'ом.Основные настройки таковы:innodb_buffer_pool_size = 20Ginnodb_buffer_pool_instances = 4innodb_use_sys_malloc = ******************************* = 2innodb_flush_method = O_DIRECTinnodb_log_files_in_group = 2innodb_log_file_size = 512Minnodb_file_per_table = 1На сервере только БДПодскажите, что это вообще может такое быть, куда рыть дальше?
23 ответа

Llama

24Gb RAM...innodb_buffer_pool_size = 20G
InnoDB reserves additional memory for buffers and control structures, so that the total allocated space is approximately 10% greater than the specified size.
Вы уверены, что оставшейся памяти (порядка 2ГБ) хватает на системные расходы и память, выделяемую на каждый коннект?


Llama

SHOW ENGINE INNODB STATUS работает от нескольких секунд до полутора минут,
а показывает оно что?


Llama

[quot miksoft]
24Gb RAM...innodb_buffer_pool_size = 20GВы уверены, что оставшейся памяти (порядка 2ГБ) хватает на системные расходы и память, выделяемую на каждый коннект?
Да, я прикидывал с помощью mysqltuner.pl - должно влазить, с учетом расходов на коннекты и т.п., в любом случае средний iowait 0.2%, с пиками до 2-3% данные за последние 12 часов, исключая время бэкапа). Т.е. если в своп mysql и попадает - то какой-то не слишком нужной ему частью, иначе был бы заметный iowait.Дополнительная деталь: в момент воспроизведения проблемы (а воспроизводится несколько раз в час стабильно) mysql потребляет 101% CPU согласно top, idle в это же время порядка 93%.Т.е. там что-то очень тяжелое работает и блокирует весь процесс работы.


Llama

а показывает оно что?
Жду воспроизведения проблемы, снимаю статус и заливаю на pastebin какой (ибо на форум эту простыню совать как-то слишком жестоко)show processlist представляет интерес?


Llama

на форум эту простыню совать как-то слишком жестоко
В спойлере - нормально.


Llama

Llama,а сколько коннектов в норме, в пике и при появлении проблемы?


Llama

Llama,а сколько коннектов в норме, в пике и при появлении проблемы?
В норме (постоянные соедиения со стороны php используются) порядка 100-120, в пике - 450, больше коннектов просто клиенты не могут установить. Теперь выдержка из 'show engine innodb status' на момент воспроизведения проблемы
*************************** 1. row *************************** Type: InnoDB Name: Status: =====================================120503 17:06:35 INNODB MONITOR OUTPUT=====================================Per second averages calculated from the last 4 seconds-----------------BACKGROUND THREAD-----------------srv_master_thread loops: 2862 1_second, 2845 sleeps, 286 10_second, 2 background, 1 flushsrv_master_thread log flush and writes: 2978----------SEMAPHORES----------OS WAIT ARRAY INFO: reservation count 3897472, signal count 3860199--Thread 140476019189504 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 1waiters flag 0--Thread 140475736094464 has waited at btr0cur.c line 560 for 5.0000 seconds the semaphore:S-lock on RW-latch at 0x7fc2b4214668 '&new_index->lock'a writer (thread id 140476030777088) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 560Last time write locked in file /home/jenkins/workspace/percona-server-5.5-debs/label_exp/debian6-64/target/Percona-Server-5.5.22-rel25.2/storage/innobase/btr/btr0cur.c line 553--Thread 140476015994624 has waited at trx0trx.c line 1775 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 1waiters flag 0--Thread 140475980850944 has waited at btr0cur.c line 560 for 5.0000 seconds the semaphore:S-lock on RW-latch at 0x7fc2b4214668 '&new_index->lock'a writer (thread id 140476030777088) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 560Last time write locked in file /home/jenkins/workspace/percona-server-5.5-debs/label_exp/debian6-64/target/Percona-Server-5.5.22-rel25.2/storage/innobase/btr/btr0cur.c line 553--Thread 140475636856576 has waited at trx0trx.c line 819 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 1waiters flag 0--Thread 140476001617664 has waited at btr0cur.c line 560 for 1.0000 seconds the semaphore:S-lock on RW-latch at 0x7fc2b4214668 '&new_index->lock'a writer (thread id 140476030777088) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 560Last time write locked in file /home/jenkins/workspace/percona-server-5.5-debs/label_exp/debian6-64/target/Percona-Server-5.5.22-rel25.2/storage/innobase/btr/btr0cur.c line 553--Thread 140475748341504 has waited at trx0trx.c line 2061 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475760588544 has waited at trx0trx.c line 1775 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140474340652800 has waited at lock0lock.c line 3922 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140474343581440 has waited at lock0lock.c line 5132 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 1waiters flag 0--Thread 140476030777088 has waited at lock0lock.c line 3205 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140474345977600 has waited at trx0trx.c line 1775 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476010403584 has waited at trx0trx.c line 1775 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475998422784 has waited at lock0lock.c line 5456 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475739555584 has waited at trx0trx.c line 2145 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475748607744 has waited at lock0lock.c line 3922 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 1waiters flag 0--Thread 140475762185984 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476014397184 has waited at trx0trx.c line 1187 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475738224384 has waited at btr0cur.c line 560 for 1.0000 seconds the semaphore:S-lock on RW-latch at 0x7fc2b4214668 '&new_index->lock'a writer (thread id 140476030777088) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 560Last time write locked in file /home/jenkins/workspace/percona-server-5.5-debs/label_exp/debian6-64/target/Percona-Server-5.5.22-rel25.2/storage/innobase/btr/btr0cur.c line 553--Thread 140475635791616 has waited at trx0trx.c line 1775 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476004280064 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476007208704 has waited at trx0trx.c line 1187 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476019721984 has waited at lock0lock.c line 5370 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475748873984 has waited at trx0trx.c line 1775 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475756861184 has waited at lock0lock.c line 5536 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475630200576 has waited at trx0trx.c line 1775 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475971000064 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475974194944 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475966740224 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140474351834880 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476009338624 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476009871104 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140474343048960 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140476006942464 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0--Thread 140475751802624 has waited at trx0trx.c line 796 for 0.0000 seconds the semaphore:Mutex at 0x7fc8646af1c0 '&kernel_mutex', lock var 0waiters flag 0Mutex spin waits 58306713, rounds 222188945, OS waits 3261333RW-shared spins 3071256, rounds 18934586, OS waits 315001RW-excl spins 171654, rounds 12080084, OS waits 230487Spin rounds per wait: 3.81 mutex, 6.17 RW-shared, 70.37 RW-excl--------FILE I/O--------I/O thread 0 state: waiting for completed aio requests (insert buffer thread)I/O thread 1 state: waiting for completed aio requests (log thread)I/O thread 2 state: waiting for completed aio requests (read thread)I/O thread 3 state: waiting for completed aio requests (read thread)I/O thread 4 state: waiting for completed aio requests (read thread)I/O thread 5 state: waiting for completed aio requests (read thread)I/O thread 6 state: waiting for completed aio requests (write thread)I/O thread 7 state: waiting for completed aio requests (write thread)I/O thread 8 state: waiting for completed aio requests (write thread)I/O thread 9 state: waiting for completed aio requests (write thread)Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] , ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0Pending flushes (fsync) log: 0; buffer pool: 0365511 OS file reads, 6314176 OS file writes, 32809 OS fsyncs3.00 reads/s, 16384 avg bytes/read, 25.99 writes/s, 4.00 fsyncs/s-------------------------------------INSERT BUFFER AND ADAPTIVE HASH INDEX-------------------------------------Ibuf: size 251, free list len 923, seg size 1175, 19957 mergesmerged operations: insert 82085, delete mark 80269, delete 11864discarded operations: insert 0, delete mark 0, delete 0Hash table size 42499511, node heap has 23845 buffer(s)3573.36 hash searches/s, 2048.49 non-hash searches/s---LOG---Log sequence number 5840977867698Log flushed up to 5840977851008Last checkpoint at 5840245204222Max checkpoint age 869019772Checkpoint age target 841862905Modified age 732663476Checkpoint age 7326634760 pending log writes, 0 pending chkp writes6153985 log i/o's done, 18.75 log i/o's/second----------------------BUFFER POOL AND MEMORY----------------------Total memory allocated 23332420619; in additional pool allocated 8388608Internal hash tables (constant factor + variable factor) Adaptive hash index 730680736 (339996088 + 390684648) Page hash 5313416 (buffer pool 0 only) Dictionary cache 87987125 (85000912 + 2986213) File system 294752 (82672 + 212080) Lock system 54592552 (53125256 + 1467296) Recovery system 0 (0 + 0)Dictionary memory allocated 2986213Buffer pool size 1310716Buffer pool size, bytes 21474770944Free buffers 897640Database pages 389231Old database pages 143741Modified db pages 49267Pending reads 1Pending writes: LRU 0, flush list 0, single page 0Pages made young 1546, not young 00.00 youngs/s, 0.00 non-youngs/sPages read 365020, created 24210, written 1472883.00 reads/s, 0.25 creates/s, 6.00 writes/sBuffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/sLRU len: 389231, unzip_LRU len: 0I/O sum[0]:cur[0], unzip sum[0]:cur[0]----------------------INDIVIDUAL BUFFER POOL INFO-------------------------BUFFER POOL 0Buffer pool size 327679Buffer pool size, bytes 5368692736Free buffers 222871Database pages 98865Old database pages 36514Modified db pages 13303Pending reads 1Pending writes: LRU 0, flush list 0, single page 0Pages made young 472, not young 00.00 youngs/s, 0.00 non-youngs/sPages read 92267, created 6597, written 391530.75 reads/s, 0.00 creates/s, 1.50 writes/sBuffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/sLRU len: 98865, unzip_LRU len: 0I/O sum[0]:cur[0], unzip sum[0]:cur[0]---BUFFER POOL 1Buffer pool size 327679Buffer pool size, bytes 5368692736Free buffers 224349Database pages 97362Old database pages 35959Modified db pages 12364Pending reads 0Pending writes: LRU 0, flush list 0, single page 0Pages made young 363, not young 00.00 youngs/s, 0.00 non-youngs/sPages read 90857, created 6505, written 376130.75 reads/s, 0.00 creates/s, 1.50 writes/sBuffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/sLRU len: 97362, unzip_LRU len: 0I/O sum[0]:cur[0], unzip sum[0]:cur[0]---BUFFER POOL 2Buffer pool size 327679Buffer pool size, bytes 5368692736Free buffers 225954Database pages 95754Old database pages 35362Modified db pages 11240Pending reads 0Pending writes: LRU 0, flush list 0, single page 0Pages made young 340, not young 00.00 youngs/s, 0.00 non-youngs/sPages read 90745, created 5009, written 334421.00 reads/s, 0.25 creates/s, 1.50 writes/sBuffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/sLRU len: 95754, unzip_LRU len: 0I/O sum[0]:cur[0], unzip sum[0]:cur[0]---BUFFER POOL 3Buffer pool size 327679Buffer pool size, bytes 5368692736Free buffers 224466Database pages 97250Old database pages 35906Modified db pages 12360Pending reads 0Pending writes: LRU 0, flush list 0, single page 0Pages made young 371, not young 00.00 youngs/s, 0.00 non-youngs/sPages read 91151, created 6099, written 370800.50 reads/s, 0.00 creates/s, 1.50 writes/sBuffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/sLRU len: 97250, unzip_LRU len: 0I/O sum[0]:cur[0], unzip sum[0]:cur[0]--------------ROW OPERATIONS--------------0 queries inside InnoDB, 0 queries in queue7 read views open inside InnoDB---OLDEST VIEW---Normal read viewRead view low limit trx n:o 7251C3A50Read view up limit trx id 7251A22BCRead view low limit trx id 7251C3A50Read view individually stored trx ids:Read view trx id 7251C3A4FRead view trx id 7251C3A46Read view trx id 7251C3A43Read view trx id 7251C3A32Read view trx id 7251C3963Read view trx id 7251C393FRead view trx id 7251C38A7Read view trx id 7251C3820Read view trx id 7251C37C8Read view trx id 7251C37BBRead view trx id 7251C3779Read view trx id 7251C36F0Read view trx id 7251C369ERead view trx id 7251C3549Read view trx id 7251C34C9Read view trx id 7251C341ARead view trx id 7251C322ARead view trx id 7251C31FFRead view trx id 7251C31D2Read view trx id 7251C316ERead view trx id 7251C3166Read view trx id 7251C2DE9Read view trx id 7251C2D49Read view trx id 7251C2CDBRead view trx id 7251C2CC4Read view trx id 7251C2C5ARead view trx id 7251C2A5BRead view trx id 7251C2A3BRead view trx id 7251C2951Read view trx id 7251C2924Read view trx id 7251C2904Read view trx id 7251C28D1Read view trx id 7251C2850Read view trx id 7251C26C9Read view trx id 7251C25CERead view trx id 7251C250DRead view trx id 7251C24ABRead view trx id 7251C249CRead view trx id 7251C2482Read view trx id 7251C23A3Read view trx id 7251C2381Read view trx id 7251C2278Read view trx id 7251C21F3Read view trx id 7251C2134Read view trx id 7251C1F9CRead view trx id 7251C1F82Read view trx id 7251C1F72Read view trx id 7251C1DB2Read view trx id 7251C1BCDRead view trx id 7251C1B94Read view trx id 7251C1B37Read view trx id 7251C1AD5Read view trx id 7251C19CERead view trx id 7251C1936Read view trx id 7251C192FRead view trx id 7251C189FRead view trx id 7251C1899Read view trx id 7251C187CRead view trx id 7251C17AFRead view trx id 7251C179ARead view trx id 7251C1690Read view trx id 7251C156ERead view trx id 7251C14EBRead view trx id 7251C14EARead view trx id 7251C13C8Read view trx id 7251C1357Read view trx id 7251C11E2Read view trx id 7251C1056Read view trx id 7251C0F88Read view trx id 7251C0F1CRead view trx id 7251C0EE6Read view trx id 7251C0DC2Read view trx id 7251C0CCARead view trx id 7251C0C5BRead view trx id 7251C0C41Read view trx id 7251C0BE3Read view trx id 7251C0AA8Read view trx id 7251C0A43Read view trx id 7251C09D7Read view trx id 7251C0978Read view trx id 7251C0934Read view trx id 7251C076FRead view trx id 7251C073DRead view trx id 7251C04B9Read view trx id 7251C04A0Read view trx id 7251C01FARead view trx id 7251********* view trx id 7251C010ARead view trx id 7251C0045Read view trx id 7251C0029Read view trx id 7251BFFF7Read view trx id 7251BFEABRead view trx id 7251BFE75Read view trx id 7251BFE71Read view trx id 7251BFE13Read view trx id 7251BFDADRead view trx id 7251BFCEERead view trx id 7251BFCC9Read view trx id 7251BFC9ARead view trx id 7251BFC8DRead view trx id 7251BFC78Read view trx id 7251BFC28Read view trx id 7251BFC0FRead view trx id 7251BFBF6Read view trx id 7251BFAD8Read view trx id 7251BFAC9Read view trx id 7251BFA21Read view trx id 7251BFA04Read view trx id 7251BF849Read view trx id 7251BF802Read view trx id 7251BF628Read view trx id 7251BF5A2Read view trx id 7251BF4F5Read view trx id 7251BF3BERead view trx id 7251BF2C4Read view trx id 7251BF203Read view trx id 7251BF0FARead view trx id 7251BEFA1Read view trx id 7251BEF83Read view trx id 7251BEF7BRead view trx id 7251BEE17Read view trx id 7251BEE04Read view trx id 7251BEDCERead view trx id 7251BEDA9Read view trx id 7251BED9DRead view trx id 7251BECECRead view trx id 7251BEC3DRead view trx id 7251BEC26Read view trx id 7251BEAF9Read view trx id 7251BE8E2Read view trx id 7251BE53FRead view trx id 7251BE3C0Read view trx id 7251BE3B6Read view trx id 7251BE370Read view trx id 7251BE222Read view trx id 7251BE20CRead view trx id 7251BE193Read view trx id 7251BE0BCRead view trx id 7251BDF46Read view trx id 7251BDE17Read view trx id 7251BDE14Read view trx id 7251BDE11Read view trx id 7251BDE10Read view trx id 7251BDB6ERead view trx id 7251BDB5FRead view trx id 7251BDB04Read view trx id 7251BDA76Read view trx id 7251BD8C2Read view trx id 7251BD89ERead view trx id 7251BD7DFRead view trx id 7251BD69ERead view trx id 7251BD606Read view trx id 7251BD5D6Read view trx id 7251BD4FCRead view trx id 7251BD372Read view trx id 7251BD36FRead view trx id 7251BD35ERead view trx id 7251BD350Read view trx id 7251BD34FRead view trx id 7251BD34ERead view trx id 7251BD34ARead view trx id 7251BD349Read view trx id 7251BD345Read view trx id 7251BD344Read view trx id 7251BD342Read view trx id 7251BD339Read view trx id 7251BD338Read view trx id 7251BD337Read view trx id 7251BD332Read view trx id 7251BD331Read view trx id 7251BD32ERead view trx id 7251BD32DRead view trx id 7251BD32BRead view trx id 7251BD327Read view trx id 7251BD323Read view trx id 7251BD321Read view trx id 7251BD320Read view trx id 7251BD31ERead view trx id 7251BD31CRead view trx id 7251BD319Read view trx id 7251BD312Read view trx id 7251BD30CRead view trx id 7251BD307Read view trx id 7251BD2FDRead view trx id 7251BCFC4Read view trx id 7251BCD1FRead view trx id 7251BCCF0Read view trx id 7251BCBC3Read view trx id 7251BC863Read view trx id 7251BC400Read view trx id 7251BC082Read view trx id 7251BBFF0Read view trx id 7251BBF90Read view trx id 7251BBE6FRead view trx id 7251BBDDARead view trx id 7251BB80BRead view trx id 7251BB63CRead view trx id 7251BB60FRead view trx id 7251BB60DRead view trx id 7251BB55FRead view trx id 7251BB424Read view trx id 7251BB2FCRead view trx id 725********** view trx id 725********** view trx id 725********** view trx id 725********** view trx id 725********** view trx id 725********** view trx id 725********** view trx id 725********** view trx id 725********** view trx id 725********** view trx id 7251B9F8ERead view trx id 7251B9E69Read view trx id 7251B9C0BRead view trx id 7251B9B3ARead view trx id 7251B9AE2Read view trx id 7251B9A43Read view trx id 7251B98DBRead view trx id 7251B9790Read view trx id 7251B971ERead view trx id 7251B96D7Read view trx id 7251B962ERead view trx id 7251B9377Read view trx id 7251B936ARead view trx id 7251B8EA3Read view trx id 7251B8D4FRead view trx id 7251B8D0BRead view trx id 7251B8C92Read view trx id 7251B8C33Read view trx id 7251B8C28Read view trx id 7251B8BD8Read view trx id 7251B8AE9Read view trx id 7251B89DFRead view trx id 7251B898ARead view trx id 7251B8640Read view trx id 7251B85B6Read view trx id 7251B83B3Read view trx id 7251B8365Read view trx id 7251B8352Read view trx id 7251B828FRead view trx id 7251B8234Read view trx id 7251B81A0Read view trx id 7251B7FB1Read view trx id 7251B7FA2Read view trx id 7251B7D9FRead view trx id 7251B7D60Read view trx id 7251B7D51Read view trx id 7251B7D17Read view trx id 7251B7CF6Read view trx id 7251B7CF4Read view trx id 7251B7C63Read view trx id 7251B7B64Read view trx id 7251B7B39Read view trx id 7251B7780Read view trx id 7251B76BERead view trx id 7251B757ERead view trx id 7251B6FD5Read view trx id 7251B6E98Read view trx id 7251B6E07Read view trx id 7251B6DB0Read view trx id 7251B6D32Read view trx id 7251B6C11Read view trx id 7251B69CDRead view trx id 7251B68D6Read view trx id 7251B685FRead view trx id 7251B6734Read view trx id 7251B66B4Read view trx id 7251B667BRead view trx id 7251B637DRead view trx id 7251B62A3Read view trx id 7251B6292Read view trx id 7251B6111Read view trx id 7251B607DRead view trx id 7251B5F65Read view trx id 7251B5EEBRead view trx id 7251B5D32Read view trx id 7251B5B91Read view trx id 7251B5B3BRead view trx id 7251B5A63Read view trx id 7251B59EERead view trx id 7251B595BRead view trx id 7251B590ARead view trx id 7251B585BRead view trx id 7251B582CRead view trx id 7251B57DDRead view trx id 7251B5672Read view trx id 7251B5586Read view trx id 7251B5579Read view trx id 7251B53BCRead view trx id 7251B5226Read view trx id 7251B51F3Read view trx id 7251B515DRead view trx id 7251B511FRead view trx id 7251B510ARead view trx id 7251B4DC0Read view trx id 7251B4D57Read view trx id 7251B4CB0Read view trx id 7251B4A15Read view trx id 7251B48D4Read view trx id 7251B48D2Read view trx id 7251B4805Read view trx id 7251B45C1Read view trx id 7251B432FRead view trx id 7251B42B1Read view trx id 7251B42A1Read view trx id 7251B415FRead view trx id 7251B3C23Read view trx id 7251B39E2Read view trx id 7251B39D8Read view trx id 7251B38DARead view trx id 7251B38ACRead view trx id 7251B38ABRead view trx id 7251B35C8Read view trx id 7251B354ERead view trx id 7251B353BRead view trx id 7251B32B1Read view trx id 7251B3272Read view trx id 7251B3266Read view trx id 7251B322DRead view trx id 7251B3228Read view trx id 7251B31B4Read view trx id 7251B2EA4Read view trx id 7251B2E30Read view trx id 7251B2C50Read view trx id 7251B2BFARead view trx id 7251B2BBDRead view trx id 7251B2AD3Read view trx id 7251B29D4Read view trx id 7251B27A1Read view trx id 7251B262FRead view trx id 7251B241ARead view trx id 7251B23D7Read view trx id 7251B2119Read view trx id 7251B20EARead view trx id 7251B1F24Read view trx id 7251B1A3ARead view trx id 7251B18F8Read view trx id 7251B18D8Read view trx id 7251B189BRead view trx id 7251B17A2Read view trx id 7251B1605Read view trx id 7251B1487Read view trx id 7251B1407Read view trx id 7251B11C1Read view trx id 7251B0E75Read view trx id 7251B0DFCRead view trx id 7251B0C3FRead view trx id 7251B0C16Read view trx id 7251B0B73Read view trx id 7251B0AFFRead view trx id 7251B0975Read view trx id 7251B080ARead view trx id 7251B0186Read view trx id 7251B0127Read view trx id 7251AFF51Read view trx id 7251AFCD0Read view trx id 7251AFC44Read view trx id 7251AFC06Read view trx id 7251AFBBERead view trx id 7251AFB27Read view trx id 7251AFADCRead view trx id 7251AF726Read view trx id 7251AF2FERead view trx id 7251AE961Read view trx id 7251********* view trx id 7251AE489Read view trx id 7251AE0DARead view trx id 7251AE033Read view trx id 7251ADFDARead view trx id 7251ADF62Read view trx id 7251ADEB0Read view trx id 7251ADAB3Read view trx id 7251ADA93Read view trx id 7251AD954Read view trx id 7251AD800Read view trx id 7251AD71BRead view trx id 7251AD53ERead view trx id 7251AD4DDRead view trx id 7251ACDC0Read view trx id 7251ACC38Read view trx id 7251ACAF4Read view trx id 7251ACA61Read view trx id 7251AC7C3Read view trx id 7251AC76BRead view trx id 7251AC3F5Read view trx id 7251AC384Read view trx id 7251ABE35Read view trx id 7251ABD7BRead view trx id 7251ABD1CRead view trx id 7251AB92DRead view trx id 7251AB551Read view trx id 7251AB463Read view trx id 7251AAEA9Read view trx id 7251AACB0Read view trx id 7251AAB52Read view trx id 7251AAAF0Read view trx id 7251AA660Read view trx id 7251AA56ARead view trx id 7251AA3EDRead view trx id 7251AA208Read view trx id 7251A9EDCRead view trx id 7251A984CRead view trx id 7251A9840Read view trx id 7251A963ARead view trx id 7251A944ARead view trx id 7251A9154Read view trx id 7251A90B1Read view trx id 7251A8A7ARead view trx id 7251A88B7Read view trx id 7251A80E5Read view trx id 7251A7AE1Read view trx id 7251A7876Read view trx id 7251A76D1Read view trx id 7251A7448Read view trx id 7251A728CRead view trx id 7251A6B89Read view trx id 7251A6395Read view trx id 7251A61F7Read view trx id 7251A57ABRead view trx id 7251A4715Read view trx id 7251A4466Read view trx id 7251A3A68Read view trx id 7251A2FAFRead view trx id 7251A2D09Read view trx id 7251A2CB0Read view trx id 7251A22BC-----------------Main thread process no. 18360, id 140476072740608, state: sleepingNumber of rows inserted 1424502, updated 1838449, deleted 371101, read 20150077238.00 inserts/s, 9.75 updates/s, 7.75 deletes/s, 12893.78 reads/s
Секцию транзакций не публикую пока, т.к. оттуда надо пвырезать приватную информацию, если оно полезно - вырежу и покажу.Пока склоняюсь к этому варианту: http://www.mysqlperformanceblog.com/2011/12/02/kernel_mutex-problem-or-******-throughput-with-single-variable/Буду пробовать покрутить настройки.


Llama

В норме (постоянные соедиения со стороны php используются) порядка 100-120, в пике - 450
Э... Тогда повторяю свой вопрос касательно достаточности памяти. По несколько мегабайт на коннект - вот и нету ваших оставшихся 2 ГБ. Дальше только своп.


Llama

Э... Тогда повторяю свой вопрос касательно достаточности памяти. По несколько мегабайт на коннект - вот и нету ваших оставшихся 2 ГБ. Дальше только своп.
Еще раз: мониторинг отрицает нагрузку на дисковую подсистему вообще и использование свопа в частности.И то и другое у меня под наблюдением в течении длительного времени и при воспроизведении проблемы я конечно запускаю top и смотрю что там происходит.После утреннего рестарта БД у меня например оно на 20Gb даже не разогрелось - RSS mysqld чуть больше 10Gb, Free memory (даже не кэш ОС, а просто совсем свободная память) 8Gb+, а проблема воспроизводится.


Llama

Продолжаем:innodb_thread_concurrency=16 слегка облегчило проблему, но не решило её полностьюinnodb_sync_spin_loops=200 включил в момент факапа, не помоглоУменьшил максимальное количество соединений с веб-сервера 440 до 240, посмотрим, как будет дальше себя вести.


Llama

пришло время переустанавливать виндоус поставить стандартный дистрибутив 5.5 кто знает что они там накрутили.


Llama

Секцию транзакций не публикую пока, т.к. оттуда надо пвырезать приватную информацию, если оно полезно - вырежу и покажу.
да все что угодно может натолкнуть на мысли. чего там скрывать то?pt-summary и pt-mysql-summary еще покажите. show full processlist с планами тоже может быть полезен


Llama

пришло время переустанавливать виндоус поставить стандартный дистрибутив 5.5 кто знает что они там накрутили.
У MySQL безусловно есть много интересных и по-своем полезных вариантов, и честно говоря оракловый форк мне как-то не очень нравится, в первую очередь тем, что некоторые значения там менялись только перезагрузкой сервер БД, а для меня это очень больно, данные греются относительно долго, и возможностей по дебагу подземных стуков там меньше чем в перконе. Так что лечение проблемы методом подбора форка/версии я пожалуй оставлю на самый-самый уж крайний случай.Проблема с kernel_mutex в багтрэкера оракла есть, решения в ветке свободной версии 5.5 не заявлено, в 5.6 реализация видимо иная + есть thread pool plugin (за деньги), но эти варианты я пока что тоже оставляю в стороне.На текущий момент удалось локализовать порблему по времени - воспроиводится со вполне конкретной периодичностью несколько раз в час (сужу по количеству записей в PROCESSLIST) т.е. вполне вероятно, что если не причиной, то катализатором являются джобы. Завтра программист будет этот вопрос изучть детальнее.


Llama

На текущий момент удалось локализовать порблему по времени - воспроиводится со вполне конкретной периодичностью несколько раз в час (сужу по количеству записей в PROCESSLIST) т.е. вполне вероятно, что если не причиной, то катализатором являются джобы. Завтра программист будет этот вопрос изучть детальнее.
Тогда большая вероятность, что не проблема сервера, а простая логическая блокировка слишком большого объема данных.Некоторые не понимают, как работают движки-плагины и что неудачные запросы способны блокировать данных больше чем кажется нужным на первый взгляд без изучения плана.


Llama

Продолжаем:innodb_thread_concurrency=16 слегка облегчило проблему, но не решило её полностьюinnodb_sync_spin_loops=200 включил в момент факапа, не помоглоУменьшил максимальное количество соединений с веб-сервера 440 до 240, посмотрим, как будет дальше себя вести.
Llama, а что, если innodb_thread_concurrency еще несколько прижать, например, до 8, и innodb_sync_spin_loops постоянно установить в 100, а не только в момент проблемы?---


Llama

а что, если innodb_thread_concurrency еще несколько прижать, например, до 8, и innodb_sync_spin_loops постоянно установить в 100, а не только в момент проблемы?---
Смысла ставить innodb_thread_concurrency меньше реального количества потоков выполения CPU я как-то не вижу, документация рекомендует 2xCPU + number of discs, я сегодня увеличу как минимум на количество I/O thread.Судя по всему, при innodb_thread_concurrency=0 и 450 коннектах создавалось порядка 450 потоков в ОС. Принудительное ограничение количества постоянных соединений с одной стороны и количества порождаемых потоков в другой пока позволило решить с большего проблему.Кроме того, примерно 30% (по количеству вызовов) операций insert...update были заменены на простой update + insert.Итоге сейчас пробую играться со следующим конфигом:innodb_buffer_pool_size = 20Ginnodb_buffer_pool_instances = 4innodb_use_sys_malloc = ******************************* = 2innodb_flush_method = O_DIRECTinnodb_log_files_in_group = 2innodb_log_file_size = 512Minnodb_file_per_table = 1innodb_thread_concurrency = 4*********************** = 100max_connections = 300 (по факту не более 250)


Llama

Смысла ставить innodb_thread_concurrency меньше реального количества потоков выполения CPU я как-то не вижу, документация рекомендует 2xCPU + number of discs,
А Вы рискните попробовать, возможно, бессмысленные, на первый взгляд, вещи обретут неведомый доселе смысл :)Мне помогло, Зайцев тоже видит в этом смысл: http://www.mysqlperformanceblog.com/2011/12/02/kernel_mutex-problem-cont-or-triple-your-throughput/. ---


Llama

чето вы больно много мечтаете. хайололоад.не обратили внимания, что все эти заметки борются со снижением производительности, а не с несколькисекундными полными зависаниями.Тут более вероятна нормальная блокировка приложением. Пока приложение что-то внутри себя делает, блокировка не отпускается и все транзакции висят.


Llama

А Вы рискните попробовать, возможно, бессмысленные, на первый взгляд, вещи обретут неведомый доселе смысл :)Мне помогло, Зайцев тоже видит в этом смысл: http://www.mysqlperformanceblog.com/2011/12/02/kernel_mutex-problem-cont-or-triple-your-throughput/. ---
Бложец я читаю. Включая коментарии. Эти значния (spin, concurrency, еще можно тикеты добавить) - это слабопредсказуемая магия которую надо крутить в разные стороны во всяких сочетаниях под нагрузкой.Мне пока не выделили ресурсов для написания толкового аналитического костыля, т.е. вполне возможно, что 8 лучше чем 40 и в моём случае тоже, но адекватно (с точки зрения бизнеса) померить я это не представляю как - по-хорошем надо брать лог веб-фронтэнда, выдергивать из него время ответа бэкенда, считать 95% и 99%, строить всякие графики и т.п. - но пока решили оставить сие занятие на уровне "работает - забэкапь конфиг и ничего не меняй". Т.к. нагрузка на систему в целом может меняться в связи с действиями отдельных её пользователей, то просто по idle считать не показательно.Пока вроде бы всё хорошо, slow query log радикально уменьшился, продолжаю выкидывать части системы не критичные к задержкам асинхронной репликации на слейв.


Llama

Привключения продолжаются.Текущая средня наргузка в прайм-тайм выглядит так:11k select/sec 1.6k insert/sec 0.6k update/sec0.1k delete/secТ.е. от части insert .. on duplicate key update в экспириментальном порядке избавилисьКроме того, удаление данных из промежуточных таблиц стали делать чаще и удаляем теперь по штучно, по primary key - это дало возможность во многом избавиться от gap lock без смены repeatable read на read commited.Нашелся способ более-менее надёжно отслеживать появление проблема - считаю количество выполняемых запросов в information_schema.PROCESSLIST (т.е. state<>'') и вывожу в мониторинг.Крутил innodb_thread_concurrency : уменьшение её до 8 приводит к увеличению среднего количества записей в information_schema.PROCESSLIST, но в целом не избалявет от проблемы залипания innodb окончательно.Радует конечно тот факт, что удалось избавится от "регулярных" залипаний по расписанию, но дальше я как-то продвинутся не смог.Написал костыль, который с интервалом один раз в секунду делает 'show engine innodb status' и 'show processlist', отследил с его помощью проблему: около 50k строк текста, порядка 3.5Mb.Внутри - секунда до начала проблемы, собственно ~20 секунд проблем, и еще несколько секунд после неё.Начало в 19:57:52 cкачать


Llama

все-таки попробуйте innodb_buffer_pool_size = 16G (допустим, чуть меньше 80% ОЗУ)посм'отрите статистику


Llama

все-таки попробуйте innodb_buffer_pool_size = 16G (допустим, чуть меньше 80% ОЗУ)посм'отрите статистику
Уменьшил до 18Gb, греется, пока одно залипание за 3 часа вскоре после запуска.