Назад | Перейти на главную страницу

Серьезная проблема с производительностью записи

[Извините, я пытался остаться ненадолго, но это было невозможно]

Я использую Linux 2.6.22.19 с Linux-vserver 2.3.0.34 на Fujitsu Siemens Primergy RX200 S3 в целях развития. Intel (R) Xeon (R) 5140 @ 2.33Ghz с 4GB RAM (где в основном 500MB все еще свободны). На сервере есть два с возможностью горячей замены по 250 ГБ, которые используются в зеркальной конфигурации RAID:

dev:~# mpt-status --newstyle
ioc:0 vol_id:0 type:IM raidlevel:RAID-1 num_disks:2 size(GB):231 state: OPTIMAL flags: ENABLED
ioc:0 phys_id:0 scsi_id:1 vendor:ATA      product_id:WDC WD2500JS-55N revision:2E01 size(GB):232 state: ONLINE flags: NONE sync_state: 100 ASC/ASCQ:0xff/0xff SMART ASC/ASCQ:0xff/0xff
ioc:0 phys_id:1 scsi_id:8 vendor:ATA      product_id:WDC WD2500JS-55N revision:2E01 size(GB):232 state: ONLINE flags: NONE sync_state: 100 ASC/ASCQ:0xff/0xff SMART ASC/ASCQ:0xff/0xff
scsi_id:0 100%
scsi_id:1 100%

я бегу LVM и ext3.

Мы используем эту машину примерно с июля / августа 2007 года, и, помимо сломанной оперативной памяти, которая была исправлена ​​в тот же день, проблем не было. И, в принципе, все было лучше, чем на той машине, которая была у нас раньше.

Тем не менее, проблемы с производительностью были впервые замечены примерно в августе 2008 года, и только недавно у меня возникла хоть какая-то уверенность в том, что это проблема. В настоящее время работает в среднем семь виртуальных серверов (три машины MySQL, два кота, три Apache, Hudson, CruiseControl, MediaWiki, Samba и т. Д.). Но чтобы не создать ложного впечатления, мы небольшая компания с точки зрения разработчиков и других людей, имеющих доступ к серверу, так что здесь не так много всего (просмотр MediaWiki, автоматизация Hudson запускается вечером, большинство приложений Apache / PHP имеют много статический контент).

После того, как я установил munin, я начал видеть интересные вещи, особенно ночью. Так как внутри каждого сервера было find при запуске (одновременно и везде) нагрузка выросла до нереальных цифр вроде 15, 17 или 20.

Но в конечном итоге проблема осталась не только на ночь (я начал отключать поисковые задания, они все равно не использовались), но и в течение дня, особенно когда мы недавно начали проект, когда нам приходилось работать с базой данных с файл дампа MySQL размером 500 МБ.

Первый раз импортировал файл дампа в рабочее время (mysql < dump.sql; на одном из наших vserver'ов, где был запущен экземпляр MySQL), синхронизированный вывод был:

real    71m28.630s
user    0m15.477s
sys     0m10.185s

Поскольку я не обращал внимания и был на собрании, мои коллеги просто спрашивали меня, что происходит с сервером, потому что он был ужасно медленным.

Я переделал тест ночью, установил ванильный Debian MySQL на хосте (не внутри гостя; выключил их все) и набрал следующие числа:

real    48m33.067s
user    0m15.397s
sys     0m13.517s

и я все еще был похож Да, хорошо, это файл дампа размером 500 МБ; сброс в пространство InnoDB занимает около 1 ГБ, это довольно много данных. Я провел несколько тестов, например, записал одну строку в файл с vim во время такого теста и захвата его с помощью strace:

   0.000048 write(1, "\33[?25l\"foo\" \33[78;7H\33[K", 22) = 22
   0.000033 stat64("foo", 0xbfda1f04) = -1 ENOENT (No such file or directory)
   0.000033 open("foo", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4
   0.000035 write(4, "thios isthis ia a testa\n", 24) = 24
   0.000144 fsync(4)            = 0
7737.631089 stat64("foo", {st_mode=S_IFREG|0664, st_size=24, ...}) = 0
   0.000084 close(4)            = 0
   0.000117 write(1, "\33[78;7H[New] 1L, 24C written", 28) = 28
   0.000051 lseek(3, 0, SEEK_SET) = 0
   0.000022 write(3, "b0VIM 7.0\0\0\0\0\20\0\0\0\0\0\0\0\0\0\0!\21\0\0mark"..., 4096) = 4096
   0.000052 select(1, [0], NULL, [0], {0, 0}) = 1 (in [0], left {0, 0})

Для меня это было невероятным числом фактов. Похоже, что системный вызов stat64 был вынужден дождаться завершения операции дампа. Не говоря уже о том, что обслуживание страниц в MediaWiki во время такого дампа тоже занимает минуты.

Как бы то ни было, я договорился с нашей хостинговой компанией о временных рамках тестирования для тестирования на нашем производственном сервере в ночное время, и я получил совершенно другую картину:

real    7m4.063s
user    0m2.690s
sys     0m30.500s

Я был потрясен. У меня также есть одобрение Amazon EC2 для тестирования, и я получил еще меньшие числа (около 5 минут на инстансе m1.large, где данные MySQL были записаны в том EBS, чтобы оставаться постоянным).

Кроме того, при импорте данных каждая другая операция становится настолько медленной, что все становится непригодным для использования, а нагрузка быстро возрастает до 5 или 7 (хотя, похоже, что происходит не так уж много; похоже, что процессы начинают блокировать друг друга для теперь причина).

Затем я начал делать Бонни ++ тесты, которые выглядели так (у меня был тестовый запуск в прошлом году, который я почти забыл). Так вот Октябрь 2008 г.:

Version  1.03       ------Sequential Output------ --Sequential Input- --Random-
                    -Per Chr- --Block-- -Rewrite- -Per Chr- --Block-- --Seeks--
Machine        Size K/sec %CP K/sec %CP K/sec %CP K/sec %CP K/sec %CP  /sec %CP
vserver-host     8G 12332  21 12600   3 10290   2 48519  74 52431   6 235.8   0
                    ------Sequential Create------ --------Random Create--------
                    -Create-- --Read--- -Delete-- -Create-- --Read--- -Delete--
              files  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP
                 16 +++++ +++ +++++ +++ +++++ +++ +++++ +++ +++++ +++ +++++ +++
vserver-host,8G,12332,21,12600,3,10290,2,48519,74,52431,6,235.8,0,16,+++++,+++,+++++,+++,+++++,+++,+++++,+++,+++++,+++,+++++,+++

а вот текущий из Апрель 2009 г.:

Version  1.03       ------Sequential Output------ --Sequential Input- --Random-
                    -Per Chr- --Block-- -Rewrite- -Per Chr- --Block-- --Seeks--
Machine        Size K/sec %CP K/sec %CP K/sec %CP K/sec %CP K/sec %CP  /sec %CP
vserver-host     8G  9705  16  7268   1  4823   1 29620  45 41336   5  73.1   0
                    ------Sequential Create------ --------Random Create--------
                    -Create-- --Read--- -Delete-- -Create-- --Read--- -Delete--
              files  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP
                 16 11678  15 +++++ +++ +++++ +++ +++++ +++ +++++ +++ 27739  31
vserver-host,8G,9705,16,7268,1,4823,1,29620,45,41336,5,73.1,0,16,11678,15,+++++,+++,+++++,+++,+++++,+++,+++++,+++,27739,31

Я не знаю, где настроить, что бы избавиться от проблем, так как я еще не совсем уверен, где / в чем настоящая проблема. Думаю, я начал не видеть леса за деревьями.

Обновление 1:

Спасибо за отзыв. Сначала я выбрал то, что могу легко протестировать, не планируя время обслуживания.

Сначала я протестировал дамп MySQL против /dev/null:

dev01:~$ time mysqldump -u root -h db01 database-p >/dev/null
Enter password:

real    0m18.871s
user    0m12.713s
sys     0m0.512s

Загрузка системы была еле заметной:

 10:27:18 up 77 days,  9:10,  7 users,  load average: 0.16, 0.75, 0.67
[...]
 10:27:33 up 77 days,  9:10,  7 users,  load average: 0.52, 0.79, 0.69

Так же sar вывод во время этого теста ничего особенного не выявил:

12:11:45 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
12:11:46 PM    dev8-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:11:46 PM  dev254-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:11:46 PM  dev254-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

12:11:46 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
12:11:47 PM    dev8-0      5.00      0.00    200.00     40.00      0.18     36.00     20.00     10.00
12:11:47 PM  dev254-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:11:47 PM  dev254-1     25.00      0.00    200.00      8.00      0.74     29.60      4.00     10.00

Затем я запустил тесты при выгрузке в файл:

dev01:~$ time mysqldump -u root -h db01 database -p >foo.sql

real    1m7.527s
user    0m13.497s
sys     0m2.724s

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

Однако нагрузка была довольно интересной ...

 10:30:49 up 77 days,  9:14,  7 users,  load average: 0.76, 0.89, 0.75
 10:30:57 up 77 days,  9:14,  7 users,  load average: 1.34, 1.01, 0.79
 10:31:05 up 77 days,  9:14,  7 users,  load average: 2.13, 1.19, 0.85
 10:31:13 up 77 days,  9:14,  7 users,  load average: 2.68, 1.32, 0.89
 10:31:21 up 77 days,  9:14,  7 users,  load average: 3.79, 1.60, 0.99
 10:31:29 up 77 days,  9:14,  7 users,  load average: 4.05, 1.69, 1.02
 10:31:37 up 77 days,  9:14,  7 users,  load average: 4.82, 1.93, 1.10
 10:31:45 up 77 days,  9:15,  7 users,  load average: 4.54, 1.97, 1.12
 10:31:53 up 77 days,  9:15,  7 users,  load average: 4.89, 2.08, 1.16
 10:31:57 up 77 days,  9:15,  7 users,  load average: 5.30, 2.22, 1.21
 10:32:01 up 77 days,  9:15,  7 users,  load average: 5.12, 2.23, 1.22
 10:32:05 up 77 days,  9:15,  7 users,  load average: 5.03, 2.26, 1.24
 10:32:13 up 77 days,  9:15,  7 users,  load average: 4.62, 2.22, 1.23

... как это было sar ...

12:16:47 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
12:16:48 PM    dev8-0    116.00      0.00  21712.00    187.17    134.04    559.31      8.62    100.00
12:16:48 PM  dev254-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:16:48 PM  dev254-1   3369.00      0.00  26952.00      8.00   3271.74    481.27      0.30    100.00

12:16:48 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
12:16:49 PM    dev8-0    130.00      0.00  17544.00    134.95    143.78    752.89      7.69    100.00
12:16:49 PM  dev254-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:16:49 PM  dev254-1   1462.00      0.00  11696.00      8.00   2749.12   1407.78      0.68    100.00

12:16:49 PM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
12:16:50 PM    dev8-0    128.00      0.00  18400.00    143.75    143.68   1593.91      7.84    100.40
12:16:50 PM  dev254-0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:16:50 PM  dev254-1    810.00      0.00   6480.00      8.00   1598.99   4911.94      1.24    100.40

Во время этих тестов я быстро загорелся vim сделать простые тесты записи. Загрузка vim сам по себе тоже был вялым, но мне не удалось извлечь эту информацию должным образом из strace. Только ожидающие stat64 звонок снова был хорошо виден:

0.000050 stat64("bla", 0xbf98caf4) = -1 ENOENT (No such file or directory)
0.000038 open("bla", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4
0.000053 write(4, "fooo\n", 5) = 5
0.000051 fsync(4)            = 0
5.385200 stat64("bla", {st_mode=S_IFREG|0664, st_size=5, ...}) = 0
0.000073 close(4)            = 0

Я добавлю дополнительные тесты файловой системы как можно скорее.

Обновление 2 / Решение:

Основываясь на отзывах Михая об устройствах MTP и конфигурации RAID, я немного углубился в эту тему. Через lspci Я получил информацию о контроллере RAID:

dev:~$ sudo lspci|grep -i lsi
05:05.0 SCSI storage controller: LSI Logic / Symbios Logic SAS1068 PCI-X Fusion-MPT SAS (rev 01)

Вдали от синего дал выстрел в http://www.ask.com/web?q=linux+problem+performance+SAS1068 и нашел проблема с производительностью записи с LSI Logic SAS1068. Описание ошибки далее связано с блогом, в котором говорится о Проблема с производительностью DELL PE860, которая также использует SAS1068.

В статье упоминается использование LSIUtil, доступный на lsi.com. В статье также подробно рассказывается о lsiutil меню, в котором описано, как включить кеширование записи.

Неудивительно, что это сильно влияет на производительность. Перед активация:

dev:~# time (dd if=/dev/zero of=bigfile count=1024 bs=1M; sync)
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB) copied, 180.902 seconds, 5.9 MB/s

real    3m8.472s
user    0m0.004s
sys     0m3.340s

После включения кеша записи:

dev:~# time (dd if=/dev/zero of=bigfile count=1024 bs=1M; sync)
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB) copied, 43.7899 seconds, 24.5 MB/s

real    0m46.413s
user    0m0.000s
sys     0m3.124s

Это как день и ночь, черное и белое. Иногда чувствовать себя глупо - это нормально. Я, вероятно, должен знать, что RAID-контроллер поставляется с отключенным кэшированием записи по умолчанию.

Обновление 3:

Скорее случайно я нашел плагин munin под названием diskstat который дает подробные графики ввода-вывода, чтения / записи / ожидания и т. д. для всех блочных устройств. Также есть очень хороший и подробный пост в блоге автора под названием Графическое отображение статистики дискового ввода-вывода Linux с помощью Munin.

Для меня это было невероятным числом фактов. Похоже, что системный вызов stat64 был вынужден дождаться завершения операции дампа.


Это ключ, который вы ищете. Держу пари, что виноват ext3. По умолчанию в ext3 любой fsync, запускаемый любым приложением под любой учетной записью пользователя, переносит весь журнал на диск. Это особенно раздражает, если вы работаете с базами данных, которые часто вызывают вызов fsync (). Это еще более раздражает при работе с устройствами RAID, которые не поддерживают барьеры записи (не знаю, поддерживают ли их устройства MPT, извините).

Если вы достаточно уверены в стабильности вашего ИБП и сервера, попробуйте смонтировать эту файловую систему с помощью data=writeback вариант монтирования вместо значения по умолчанию data=ordered. Вы пожертвуете надежностью перед лицом сбоя сервера, но если ваша производительность все равно упадет, это не большая потеря.

Однако долгосрочным решением может стать переход на лучшую файловую систему. В настоящее время я бы рекомендовал XFS. Пользуюсь им годами без особых проблем. Единственный недостаток заключается в том, что его нельзя уменьшить так, как можно уменьшить ext2 / 3, но его можно расширить.

  • Попробуйте сделать дамп mysql /dev/null. Это покажет вам, отвечает ли за это пишущая или читающая часть.

  • Попробуйте записать дамп на отдельный логический том / файловую систему или RAM-диск.

  • Проверить journalling в файловой системе.

  • Проверить noatime/atime статус в файловой системе

  • Файловая система заполняется? Обычно производительность снижается, когда объем данных достигает определенного порога.

Вот несколько хороших предложений из других плакатов об исключении программного обеспечения и настройке производительности RAID. Стоит упомянуть, что если ваша рабочая нагрузка связана с большим объемом записи, то выбор оборудования с кешем записи с резервным питанием от батареи, вероятно, будет правильным решением, если вы подумываете о замене своего комплекта.

Пахнет так, будто вы просто заполняете емкость ввода-вывода. Сначала убедитесь, что один из ваших дисков не умирает (переназначение секторов может плохо сказаться на вводе-выводе), и запустите sar -d 1 0 и посмотрите на %util номера для физических дисков. Если это около 100%, я бы просто добавил больше шпинделей, поместив их в RAID-10. Вы не получите удвоенной производительности, но это даст вам больше удовольствия. Диски на 250 ГБ в наши дни не так уж и дороги.

О, и чтобы еще немного улучшить мою работу и поставить стену текста в битву против вашей стены текста, я написал руководство для отслеживания проблем с производительностью: http://www.anchor.com.au/hosting/development/HuntingThePerformanceWumpus охватывает все, что вам нужно знать об отслеживании проблем с производительностью.