MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 22.01.19 16:27
Оценка:
Есть mysql сервер 8.0.13 на каком то виртуальном хостинге (подозреваю что он не сильно шустрый, xeon e5 (2 процессора), 4Gb RAM).
Есть единственная таблица в единственной InnoDB-базе, вида
CREATE TABLE `table1` (
  `str1` varchar(16) NOT NULL,
  `d1` double NOT NULL,
  `d2` double NOT NULL,
  `time` datetime NOT NULL
) ENGINE=InnoDB DEFAULT CHARSET=cp1251;

Чтений совсем нет (пока что), идет только вставка, раз в 1-3 секунды от нескольких клиентов (и редкое удаление старых записей), всего в таблице в конкретный момент времени 2-4 тысячи записей.

Так вот, insert очень сильно тормозит, 5-10-30 секунд идут вставки нескольких записей. При чем если один клиент затормозился, то и все встали тоже.
show full processlist показывает постоянные статусы запросов, вида 'waiting for handler commit'.
В слоу-логе на все такие медленные запросы есть логи вида '# Query_time: 19.675364 Lock_time: 0.000865 Rows_sent: 0 Rows_examined: 0'.
Куда еше можно копнуть?
Re: MySql\простенькая табличка, тормозит insert
От: BlackEric http://black-eric.lj.ru
Дата: 23.01.19 07:37
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>Куда еше можно копнуть?


Нескольких записей — это сколько? И сколько пишущих клиентов? Не может быть что они коннекты ждут из пула?
https://github.com/BlackEric001
Re[2]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 08:16
Оценка:
Здравствуйте, BlackEric, Вы писали:

BE>Нескольких записей — это сколько? И сколько пишущих клиентов? Не может быть что они коннекты ждут из пула?


От одной до 10ти одновременно вставляет один клиент. Клиент сейчас вообще один, ситуация вообще нихрена не изменилась.
'waiting for handler commit' — на этом статусе висит каждый запрос несколько секунд. Да, бывает и быстро выполняется, 50\50 как то.
Может впс дохлая? Там интерфейс даже еле шевелится..
Re[3]: MySql\простенькая табличка, тормозит insert
От: BlackEric http://black-eric.lj.ru
Дата: 23.01.19 08:40
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>Может впс дохлая? Там интерфейс даже еле шевелится..

Ну я бы с этого начинал.
https://github.com/BlackEric001
Re[4]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 08:43
Оценка:
Здравствуйте, BlackEric, Вы писали:
BE>Ну я бы с этого начинал.

Процессор в среднем 10-20%, оперативы занято 1.5 из 4Gb, подозрение на дисковую подсистему. Как ее можно чекнуть? Может у самой бд есть какие нибудь логи по этому поводу? Slow-лог толком ничего не говорит.
Re: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 10:38
Оценка:
Измерил скорость диска, получилось вот что
  disk

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

А вот что мне показал Workbench на explain запроса вида

insert into `table1` (str1,d1,d2,`time`) values ('str',1,1,'2019-01-01 10:00');




Т.е. происходит полное сканирование таблицы?
Это может повлиять на скорость вставки? И если да, как этого избежать, нужны индексы?
Re[2]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 11:52
Оценка:
Поправил в my.ini

innodb_buffer_pool_size 8M -> 128M
innodb_log_buffer_size 1M -> 8M
innodb_thread_concurrency 10 -> 4

Slow-лог стал заметно реже тревожиться (7 секунд стоит трезольд), но все равно как то не то.
Видимо виртуальный диск совсем дохлый на WPS.
Re: MySql\простенькая табличка, тормозит insert
От: Буравчик Россия  
Дата: 23.01.19 12:04
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>Чтений совсем нет (пока что), идет только вставка, раз в 1-3 секунды от нескольких клиентов (и редкое удаление старых записей), всего в таблице в конкретный момент времени 2-4 тысячи записей.


H>Так вот, insert очень сильно тормозит, 5-10-30 секунд идут вставки нескольких записей. При чем если один клиент затормозился, то и все встали тоже.

H>show full processlist показывает постоянные статусы запросов, вида 'waiting for handler commit'.
H>В слоу-логе на все такие медленные запросы есть логи вида '# Query_time: 19.675364 Lock_time: 0.000865 Rows_sent: 0 Rows_examined: 0'.
H>Куда еше можно копнуть?

Похоже на проблему локов. Если всех в один поток пустить, уйдут проблемы (innodb_thread_concurrency=1)?

Может это? https://www.percona.com/blog/2012/03/27/innodbs-gap-locks/
Best regards, Буравчик
Отредактировано 23.01.2019 12:05 Буравчик . Предыдущая версия .
Re[2]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 12:56
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Похоже на проблему локов. Если всех в один поток пустить, уйдут проблемы (innodb_thread_concurrency=1)?

Я там чуть выше писал, что оставил даже одного пишущего клиента, ситуация почти не изменилась.
Поставил сейчас и этот флаг — ничего не изменилось.
show full processlist показывает зависшим на 'waiting for handler commit' один insert.
При чем уже большинство инсертов пролетает бодро, раз 10-30 секунд он почему то виснет на несколько секунд..

Б>Может это? https://www.percona.com/blog/2012/03/27/innodbs-gap-locks/

Ну дык читателей у меня сейчас совсем нет..
Вставка идет простым insert, без всяких там ignore и т.д. Индексов на таблице тоже нет. Ключей по полям тоже нет.
Re[3]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 12:58
Оценка:
Меня вот теперь очень интересует, что означает этот 'waiting for handler commit', гугление что-то ничего внятного по этому вопросу не дало.
Re[3]: MySql\простенькая табличка, тормозит insert
От: Буравчик Россия  
Дата: 23.01.19 13:19
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>При чем уже большинство инсертов пролетает бодро, раз 10-30 секунд он почему то виснет на несколько секунд..


Может, действительно, диск фризится. Попробуй ioping на диске посмотреть.

H>Ну дык читателей у меня сейчас совсем нет..


А "редкое удаление старых записей"?
Best regards, Буравчик
Re[4]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 13:33
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>А "редкое удаление старых записей"?

Да, совсем забыл. Удаление происходит из того же потока\клиента, что и инсерты, раз в три минуты, по условию с датой (последним полем), все делиты пролетают быстро, ну относительно быстро, до секунды.

Б>Может, действительно, диск фризится. Попробуй ioping на диске посмотреть.

Эмм... Windows
Re[4]: MySql\простенькая табличка, тормозит insert
От: Буравчик Россия  
Дата: 23.01.19 13:35
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>Меня вот теперь очень интересует, что означает этот 'waiting for handler commit', гугление что-то ничего внятного по этому вопросу не дало.


Если правильно понял, это новый stage для Performance Schema.

Про Performance Schema:
https://dev.mysql.com/doc/refman/8.0/en/performance-schema.html
https://habr.com/ru/post/126358/

По идее, с помощью этого можно докопаться до самых низкоуровневых причин Вашей проблемы, но я не подскажу как.
Best regards, Буравчик
Re[5]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 13:49
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Если правильно понял, это новый stage для Performance Schema.

Б>Про Performance Schema:
Б>https://dev.mysql.com/doc/refman/8.0/en/performance-schema.html
Б>https://habr.com/ru/post/126358/
Б>По идее, с помощью этого можно докопаться до самых низкоуровневых причин Вашей проблемы, но я не подскажу как.

Спасибо. Да, тут надо глубоко зарываться..
Re: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 23.01.19 15:52
Оценка:
H>Куда еше можно копнуть?

Диск — дрова?

  Скрытый текст


upd: на всякий случай, это после рестарта в тот же день, стата вроде сбрасывается.
Отредактировано 24.01.2019 0:59 Hayabusa . Предыдущая версия .
Re[2]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 24.01.19 01:48
Оценка:
Здравствуйте, Hayabusa, Вы писали:
H>Диск — дрова?

Ну дайте коммент что ли по этим дровам, мускуль перезапускался часа за 2-3 до поста.
Re[3]: MySql\простенькая табличка, тормозит insert
От: BlackEric http://black-eric.lj.ru
Дата: 24.01.19 07:45
Оценка:
Здравствуйте, Hayabusa, Вы писали:

И что за причина перезапуска? Что в логах?
Скорее всего у вас кривое железо. Я бы начал с замены диска под бд.
https://github.com/BlackEric001
Re[4]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 24.01.19 11:48
Оценка:
Здравствуйте, BlackEric, Вы писали:
BE>И что за причина перезапуска? Что в логах?
BE>Скорее всего у вас кривое железо. Я бы начал с замены диска под бд.

Перезапускался из за изменений в my.ini
Что за лог имеется ввиду, slow-лог?
По железу да — не понятно, что там за виртуальный диск, и какая часть скорости от реальной отдана моей wps.
Re[6]: MySql\простенькая табличка, тормозит insert
От: Буравчик Россия  
Дата: 25.01.19 06:24
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>Спасибо. Да, тут надо глубоко зарываться..


Сделай хотя бы
select event_name, source, sum(timer_wait) timer_wait 
from events_waits_history_long 
group by event_name, source 
order by 3 desc 
limit 30;
Best regards, Буравчик
Re[7]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 08:29
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Сделай хотя бы

Б>
Б>select event_name, source, sum(timer_wait) timer_wait 
Б>from events_waits_history_long 
Б>group by event_name, source 
Б>order by 3 desc 
Б>limit 30;
Б>


В sql8 нет таблички events_waits_history_long.
что есть — https://dev.mysql.com/doc/refman/8.0/en/sys-schema-views.html
Re[7]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 09:27
Оценка:
Здравствуйте, Буравчик, Вы писали:

А это не поможет?

  Скрытый текст
Re[8]: MySql\простенькая табличка, тормозит insert
От: Буравчик Россия  
Дата: 25.01.19 16:30
Оценка: 3 (1)
Здравствуйте, Hayabusa, Вы писали:

H>Здравствуйте, Буравчик, Вы писали:


H>А это не поможет?


Да, похоже на проблемы с диском.
Судя по картинке бывают какие-то нереальные задержки при доступе к файлам.

Написал жалкое подобие ioping для windows, попробуй (если питон установлен):
  Скрытый текст
import time

INTERVAL = 1  # seconds
STRING_LEN = 100
FILENAME = "C:\testOutputFile.txt"

message = '*' * STRING_LEN


def operation():
    start_time = time.time()
    
    with open(FILENAME, 'wb', buffering=0) as f:
            s = '%5d : %s\n' % (i, message)
            f.write(s.encode())
            f.flush()
        
    elapsed_time = time.time() - start_time
    elapsed_time *= 1000  # milliseconds now
    
    return elapsed_time

    
# warming

print('warming...')
for i in range(5):
    operation()
    time.sleep(INTERVAL)
    print(i)

i = 0
stat_sum = 0
stat_max = -1

print('measure...')
while True:

    elapsed_time = operation()

    i+=1
    stat_sum += elapsed_time
    stat_max = max(elapsed_time, stat_max)
    
    print("%5d : last=%.3fms avg=%.3fms max=%.3fms" % (i, elapsed_time, stat_sum/i, stat_max))
    
    time.sleep(INTERVAL)
Best regards, Буравчик
Re: MySql\простенькая табличка, тормозит insert
От: Somescout  
Дата: 25.01.19 17:14
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>Куда еше можно копнуть?


Может попробовать сымитировать нагрузку на заведомо нормальном железе, чтобы исключить аппаратные проблемы?
ARI ARI ARI... Arrivederci!
Re[2]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 17:30
Оценка:
Здравствуйте, Somescout, Вы писали:

S>Может попробовать сымитировать нагрузку на заведомо нормальном железе, чтобы исключить аппаратные проблемы?


Да там и нагрузки то нет никакой. Ставлю сервер mysql на своем ноуте — все работает как часы.
Похоже все таки беда с диском.
Re[5]: MySql\простенькая табличка, тормозит insert
От: Pavel Dvorkin Россия  
Дата: 25.01.19 17:41
Оценка:
Здравствуйте, Hayabusa, Вы писали:

Б>>Может, действительно, диск фризится. Попробуй ioping на диске посмотреть.

H>Эмм... Windows

Попробуй вот это погонять.

https://www.resplendence.com/latencymon
https://www.resplendence.com/whysoslow
With best regards
Pavel Dvorkin
Re[5]: MySql\простенькая табличка, тормозит insert
От: Somescout  
Дата: 25.01.19 17:42
Оценка:
Здравствуйте, Hayabusa, Вы писали:

Б>>Может, действительно, диск фризится. Попробуй ioping на диске посмотреть.

H>Эмм... Windows

diskspd (https://aka.ms/diskspd)

Попробуйте что-то вроде таких параметров:

diskspd –b8K –d30 –o4 –t8 –h –r –w25 –L –Z1G –c20G <drive>:\iotest.dat


Можно ещё в Resource Monitor посмотреть на среднюю задержку при обращении к файлам базы.
ARI ARI ARI... Arrivederci!
Отредактировано 25.01.2019 17:48 Somescout . Предыдущая версия .
Re[9]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 17:44
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Да, похоже на проблемы с диском.

Б>Судя по картинке бывают какие-то нереальные задержки при доступе к файлам.
Б>Написал жалкое подобие ioping для windows, попробуй (если питон установлен):

Спасибо! Питон поставил, вот что проскочило только что

48 : last=0.000ms avg=0.324ms max=15.546ms
49 : last=0.000ms avg=0.317ms max=15.546ms
50 : last=0.000ms avg=0.311ms max=15.546ms
51 : last=5578.146ms avg=109.680ms max=5578.146ms
52 : last=0.000ms avg=107.571ms max=5578.146ms
53 : last=0.000ms avg=105.541ms max=5578.146ms
54 : last=0.000ms avg=103.587ms max=5578.146ms
55 : last=0.000ms avg=101.703ms max=5578.146ms


Понаблюдаю сейчас еще.
Re[2]: MySql\простенькая табличка, тормозит insert
От: Somescout  
Дата: 25.01.19 17:47
Оценка:
Здравствуйте, Hayabusa, Вы писали:

H>Диск — дрова?


  Скрытый текст
Image: 95680ed8392e741f72cd170b0d9389a3.png


Не сказал бы. Тут сложно судить без разделения по перцентилям, но среднее время не настолько плохое, чтобы вставка длилась секунды — десятки секунд.
ARI ARI ARI... Arrivederci!
Re[5]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 17:51
Оценка:
Да вот уже помогли с ioping самописным
http://rsdn.org/forum/db/7358488.1
Автор: Hayabusa
Дата: 25.01.19

Похоже да, дело в диске..

  Скрытый текст

16 : last=0.000ms avg=0.000ms max=0.000ms
17 : last=15.546ms avg=0.914ms max=15.546ms
18 : last=0.000ms avg=0.864ms max=15.546ms
...
49 : last=0.000ms avg=0.317ms max=15.546ms
50 : last=0.000ms avg=0.311ms max=15.546ms
51 : last=5578.146ms avg=109.680ms max=5578.146ms
52 : last=0.000ms avg=107.571ms max=5578.146ms
...
80 : last=0.000ms avg=69.921ms max=5578.146ms
81 : last=3078.043ms avg=107.058ms max=5578.146ms
82 : last=0.000ms avg=105.753ms max=5578.146ms
83 : last=0.000ms avg=104.479ms max=5578.146ms
84 : last=15.730ms avg=103.422ms max=5578.146ms
85 : last=0.000ms avg=102.205ms max=5578.146ms
...
106 : last=0.000ms avg=81.957ms max=5578.146ms
107 : last=12.653ms avg=81.310ms max=5578.146ms
108 : last=0.000ms avg=80.557ms max=5578.146ms
...
112 : last=0.000ms avg=77.680ms max=5578.146ms
113 : last=0.000ms avg=76.992ms max=5578.146ms
114 : last=15.718ms avg=76.455ms max=5578.146ms
115 : last=0.000ms avg=75.790ms max=5578.146ms
...
139 : last=0.000ms avg=62.704ms max=5578.146ms
140 : last=0.000ms avg=62.256ms max=5578.146ms
141 : last=6843.771ms avg=110.352ms max=6843.771ms
142 : last=0.000ms avg=109.575ms max=6843.771ms
...
148 : last=0.000ms avg=105.132ms max=6843.771ms
149 : last=17.476ms avg=104.544ms max=6843.771ms
150 : last=593.860ms avg=107.806ms max=6843.771ms
151 : last=0.000ms avg=107.092ms max=6843.771ms
...
164 : last=0.000ms avg=98.603ms max=6843.771ms
165 : last=5749.870ms avg=132.853ms max=6843.771ms
166 : last=0.000ms avg=132.053ms max=6843.771ms
...
205 : last=0.000ms avg=107.083ms max=6843.771ms
206 : last=0.000ms avg=106.563ms max=6843.771ms
207 : last=3140.682ms avg=121.220ms max=6843.771ms
208 : last=0.000ms avg=120.638ms max=6843.771ms
209 : last=0.000ms avg=120.060ms max=6843.771ms
210 : last=0.000ms avg=119.489ms max=6843.771ms
211 : last=0.000ms avg=118.922ms max=6843.771ms
212 : last=0.000ms avg=118.361ms max=6843.771ms
213 : last=15.445ms avg=117.878ms max=6843.771ms
214 : last=0.000ms avg=117.327ms max=6843.771ms
...
218 : last=0.000ms avg=115.175ms max=6843.771ms
219 : last=3000.035ms avg=128.348ms max=6843.771ms
220 : last=0.000ms avg=127.764ms max=6843.771ms
221 : last=0.000ms avg=127.186ms max=6843.771ms
222 : last=15.636ms avg=126.684ms max=6843.771ms
223 : last=0.000ms avg=126.115ms max=6843.771ms
...
228 : last=0.000ms avg=123.350ms max=6843.771ms
229 : last=749.887ms avg=126.086ms max=6843.771ms
230 : last=0.000ms avg=125.538ms max=6843.771ms
231 : last=578.068ms avg=127.497ms max=6843.771ms
232 : last=0.000ms avg=126.947ms max=6843.771ms
...
244 : last=0.000ms avg=120.704ms max=6843.771ms
245 : last=0.000ms avg=120.211ms max=6843.771ms
246 : last=578.065 ms avg=122.072ms max=6843.771ms
247 : last=0.000ms avg=121.578ms max=6843.771ms

Re[3]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 17:53
Оценка:
Здравствуйте, Somescout, Вы писали:
S>Не сказал бы. Тут сложно судить без разделения по перцентилям, но среднее время не настолько плохое, чтобы вставка длилась секунды — десятки секунд.

Ну вставка же не каждая долго длится. Я логи не веду по таймингам, но так на вскидку тормоза возникают частенько, из 10-20 вставок в минуту одна-две могут встать на несколько секунд.
Re[10]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 18:01
Оценка:
Ну в общем да, тысячная итерация, уже максимальный пинг 9900мс, думаю дело можно закрывать
Re: MySql\простенькая табличка, тормозит insert
От: Ромашка Украина  
Дата: 25.01.19 19:01
Оценка:
Здравствуйте, Hayabusa, Вы писали:
H>Куда еше можно копнуть?

Попробуй добавить auto increment primary key. Или вообще хоть какой-нибудь primary key.


Всё, что нас не убивает, ещё горько об этом пожалеет.
Re[2]: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 25.01.19 19:48
Оценка:
Здравствуйте, Ромашка, Вы писали:
Р>Попробуй добавить auto increment primary key. Или вообще хоть какой-нибудь primary key.

Неа, ничего не изменилось.
Re: MySql\простенькая табличка, тормозит insert
От: Hayabusa Россия  
Дата: 28.01.19 14:55
Оценка:
Всё, проблема решилась, написали админу VPS, перебросили там куда то на другой диск нашу впс, все проблемы как кот слизал
 
Подождите ...
Wait...
Пока на собственное сообщение не было ответов, его можно удалить.