Анализ производительности Linux за 60 000 миллисекунд
Вольный перевод с источника
Хотя в эпоху облаков уже и не так важно заниматься именно траблшутингом отдельных линуксостов, но я всё ж считаю, что это важно и нужно уметь, поэтому и перевёл эту статью. Статья старая, 2015 года, поэтому будут упоминваться инструменты, которые не используются в данный момент.
Вы заходите на Linux-сервер с проблемой производительности: что вы проверяете в первую минуту?
У нас в Netflix есть массивное Linux-облако EC2 и множество инструментов анализа производительности для мониторинга и исследования его работы. К ним относятся Atlas для мониторинга всего облака и Vector для анализа экземпляров по требованию. Хотя эти инструменты помогают нам решить большинство проблем, иногда нам нужно войти в экземпляр и запустить некоторые стандартные инструменты производительности Linux.
Первые 60 секунд: Резюме
В этом посте команда Netflix Performance Engineering покажет вам первые 60 секунд оптимизированного исследования производительности в командной строке, используя стандартные инструменты Linux, которые должны быть у вас под рукой. За 60 секунд вы можете получить представление об использовании системных ресурсов и запущенных процессах, выполнив следующие десять команд. Ищите ошибки и метрики насыщенности, так как их легко интерпретировать, а затем - использование ресурсов. Насыщенность - это когда на ресурс приходится больше нагрузки, чем он может выдержать, и может проявляться либо в длине очереди запросов, либо во времени ожидания.
uptime
dmesg | tail
vmstat 1
mpstat -P ALL 1
pidstat 1
iostat -xz 1
free -m
sar -n DEV 1
sar -n TCP,ETCP 1
top
Некоторые из этих команд требуют установки пакета sysstat. Метрики, выводимые этими командами, помогут вам выполнить что-то Метода USE: методологии поиска узких мест в производительности. Она включает в себя проверку показателей использования, насыщения и ошибок для всех ресурсов (процессоров, памяти, дисков и т. д.). Также обратите внимание на то, когда вы проверили и оправдали ресурс, следовательно в процессе исключения это сужает круг целей для изучения и направляет последующие исследования.
В следующих разделах кратко описаны эти команды с примерами из рабочей системы. Дополнительные сведения об этих инструментах см. на их man-страницах.
1. uptime
$ uptime
23:51:26 up 21:31, 1 user, load average: 30.02, 26.43, 19.02
Это быстрый способ просмотреть средние значения нагрузки (Load Average), которые указывают на количество задач (процессов), желающих запуститься. В системах Linux эти цифры включают процессы, желающие работать на процессоре, а также процессы, заблокированные при непрерывном вводе-выводе (обычно дисковый ввод-вывод). Это дает общее представление о загрузке ресурсов (или спросе на них), но не может быть правильно понято без других инструментов. Стоит только бегло взглянуть.
Три числа представляют собой экспоненциально затухающие средние значения скользящей суммы с константой в 1 минуту, 5 минут и 15 минут. Эти три числа дают нам некоторое представление о том, как меняется нагрузка с течением времени. Например, если вас попросили проверить проблемный сервер, а значение за 1 минуту намного меньше значения за 15 минут, то, возможно, вы вошли в систему слишком поздно и пропустили проблему.
В приведенном выше примере средние значения нагрузки показывают недавнее увеличение: значение за 1 минуту достигло 30, в то время как за 15 минут - 19. То, что цифры так велики, означает много чего: вероятно, потребность в процессоре; vmstat или mpstat подтвердят это, это команды 3 и 4 в данной последовательности.
2. dmesg | tail
$ dmesg | tail
[1880957.563150] perl invoked oom-killer: gfp_mask=0x280da, order=0, oom_score_adj=0
[...]
[1880957.563400] Out of memory: Kill process 18694 (perl) score 246 or sacrifice child
[1880957.563408] Killed process 18694 (perl) total-vm:1972392kB, anon-rss:1953348kB, file-rss:0kB
[2320864.954447] TCP: Possible SYN flooding on port 7001. Dropping request. Check SNMP counters.
Здесь отображаются последние 10 системных сообщений, если таковые имеются. Ищите ошибки, которые могут вызвать проблемы с производительностью. Пример выше включает в себя oom-killer и TCP, отбрасывающий запрос.
Не пропустите этот шаг! dmesg всегда стоит проверить.
3. vmstat 1
$ vmstat 1
procs ---------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
34 0 0 200889792 73708 591828 0 0 0 5 6 10 96 1 3 0 0
32 0 0 200889920 73708 591860 0 0 0 592 13284 4282 98 1 1 0 0
32 0 0 200890112 73708 591860 0 0 0 0 9501 2154 99 1 0 0 0
32 0 0 200889568 73712 591856 0 0 0 48 11900 2459 99 0 0 0 0
32 0 0 200890208 73712 591860 0 0 0 0 15898 4840 98 1 1 0 0
^C
Сокращение от virtual memory stat, vmstat(8) - это общедоступный инструмент (впервые созданный для BSD несколько десятилетий назад). Он печатает сводку ключевых статистических данных сервера в каждой строке.
vmstat был запущен с аргументом 1, чтобы вывести односекундные сводки. В первой строке вывода (в этой версии vmstat) есть несколько столбцов, которые показывают среднее значение с момента загрузки, а не предыдущую секунду. Пока что пропустите первую строку, если не хотите выучить и запомнить, какой столбец какой.
Столбцы для проверки:
- r: Количество процессов, работающих на процессоре и ожидающих своей очереди. Это лучший сигнал, чем средние значения нагрузки, для определения насыщенности процессора, поскольку он не включает ввод-вывод. Интерпретация: значение "r", превышающее количество CPU, означает насыщение.
- free: Свободная память в килобайтах. Если цифр слишком много для подсчета, значит, у вас достаточно свободной памяти. Команда "free -m", включенная как команда 7, лучше объясняет состояние свободной памяти.
si, so: Ввод и вывод подкачки. Если эти значения ненулевые, то память закончилась. - us, sy, id, wa, st: Это разбивка процессорного времени в среднем по всем процессорам. Это время пользователя, системное время (ядра), время простоя, ожидание ввода-вывода и время кражи (другими гостями или с помощью Xen, собственного изолированного домена драйвера гостя).
Разбивка процессорного времени подтверждает, что процессоры заняты, путем сложения пользовательского и системного времени. Постоянная степень ожидания ввода-вывода указывает на узкое место на диске; именно здесь процессоры простаивают, потому что задачи блокируются в ожидании ожидающего ввода-вывода с диска. Вы можете рассматривать ожидание ввода/вывода как еще одну форму простоя процессора, которая дает представление о причинах его простоя.
Системное время необходимо для обработки ввода-вывода. Высокое среднее значение системного времени, превышающее 20 %, может быть интересно для дальнейшего изучения: возможно, ядро обрабатывает ввод-вывод неэффективно.
В приведенном выше примере процессорное время почти полностью приходится на пользовательский уровень, что указывает на использование на уровне приложений. Процессоры также используются в среднем более чем на 90 %. Это не обязательно проблема; проверьте степень насыщения с помощью столбца "r".
4. mpstat -P ALL 1
$ mpstat -P ALL 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
07:38:49 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
07:38:50 PM all 98.47 0.00 0.75 0.00 0.00 0.00 0.00 0.00 0.00 0.78
07:38:50 PM 0 96.04 0.00 2.97 0.00 0.00 0.00 0.00 0.00 0.00 0.99
07:38:50 PM 1 97.00 0.00 1.00 0.00 0.00 0.00 0.00 0.00 0.00 2.00
07:38:50 PM 2 98.00 0.00 1.00 0.00 0.00 0.00 0.00 0.00 0.00 1.00
07:38:50 PM 3 96.97 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 3.03
[...]
Эта команда выводит разбивку процессорного времени по процессорам, которую можно использовать для проверки дисбаланса. Один горячий процессор может свидетельствовать об однопоточном приложении.
5. pidstat 1
$ pidstat 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
07:41:02 PM UID PID %usr %system %guest %CPU CPU Command
07:41:03 PM 0 9 0.00 0.94 0.00 0.94 1 rcuos/0
07:41:03 PM 0 4214 5.66 5.66 0.00 11.32 15 mesos-slave
07:41:03 PM 0 4354 0.94 0.94 0.00 1.89 8 java
07:41:03 PM 0 6521 1596.23 1.89 0.00 1598.11 27 java
07:41:03 PM 0 6564 1571.70 7.55 0.00 1579.25 28 java
07:41:03 PM 60004 60154 0.94 4.72 0.00 5.66 9 pidstat
07:41:03 PM UID PID %usr %system %guest %CPU CPU Command
07:41:04 PM 0 4214 6.00 2.00 0.00 8.00 15 mesos-slave
07:41:04 PM 0 6521 1590.00 1.00 0.00 1591.00 27 java
07:41:04 PM 0 6564 1573.00 10.00 0.00 1583.00 28 java
07:41:04 PM 108 6718 1.00 0.00 0.00 1.00 0 snmp-pass
07:41:04 PM 60004 60154 1.00 4.00 0.00 5.00 9 pidstat
^C
Pidstat немного похож на сводку top по каждому процессу, но вместо очистки экрана он печатает сводку в развернутом виде. Это может быть полезно для наблюдения за закономерностями во времени, а также для записи увиденного (copy-n-paste) в протокол вашего расследования.
В приведенном выше примере два java-процесса ответственны за потребление ЦП. Столбец %CPU - это общее значение для всех процессоров; 1591 % показывает, что этот java-процесс потребляет почти 16 процессоров.
6. iostat -xz 1
$ iostat -xz 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
73.96 0.00 3.73 0.03 0.06 22.21
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
xvda 0.00 0.23 0.21 0.18 4.52 2.08 34.37 0.00 9.98 13.80 5.42 2.44 0.09
xvdb 0.01 0.00 1.02 8.94 127.97 598.53 145.79 0.00 0.43 1.78 0.28 0.25 0.25
xvdc 0.01 0.00 1.02 8.86 127.79 595.94 146.50 0.00 0.45 1.82 0.30 0.27 0.26
dm-0 0.00 0.00 0.69 2.32 10.47 31.69 28.01 0.01 3.23 0.71 3.98 0.13 0.04
dm-1 0.00 0.00 0.00 0.94 0.01 3.78 8.00 0.33 345.84 0.04 346.81 0.01 0.00
dm-2 0.00 0.00 0.09 0.07 1.35 0.36 22.50 0.00 2.55 0.23 5.62 1.78 0.03
[...]
^C
Это отличный инструмент для понимания блочных устройств (дисков), как применяемой рабочей нагрузки, так и результирующей производительности. Ищите:
- r/s, w/s, rkB/s, wkB/s: Это количество операций чтения, записи, чтения Кбайт и записи Кбайт в секунду на устройство. Используйте их для характеристики рабочей нагрузки. Проблема с производительностью может быть вызвана просто чрезмерной нагрузкой.
- await: среднее время выполнения операций ввода-вывода в миллисекундах. Это время, которое страдает приложение, поскольку оно включает в себя как время ожидания в очереди, так и время обслуживания. Большее, чем ожидалось, среднее время может быть индикатором насыщения устройства или проблем с ним.
- avgqu-sz: среднее количество запросов, поступающих на устройство. Значения больше 1 могут свидетельствовать о насыщении (хотя обычно устройства могут работать с запросами параллельно, особенно виртуальные устройства, которые обслуживают несколько внутренних дисков).
- %util: Использование устройства. На самом деле это процент загруженности, показывающий, сколько времени в секунду устройство выполняло работу. Значения, превышающие 60 %, обычно указывают на низкую производительность (которую следует ожидать), хотя это зависит от устройства. Значения, близкие к 100 %, обычно указывают на насыщение.
Если устройство хранения представляет собой логическое дисковое устройство, расположенное перед многими внутренними дисками, то 100 %-ное использование может означать, что некоторые операции ввода-вывода обрабатываются 100 % времени, однако внутренние диски могут быть далеко не насыщены и способны обрабатывать гораздо больше работы.
Имейте в виду, что плохая производительность дискового ввода-вывода не обязательно является проблемой приложения.
7. free -m
$ free -m
total used free shared buffers cached
Mem: 245998 24545 221453 83 59 541
-/+ buffers/cache: 23944 222053
Swap: 0 0 0
Правые два столбца показывают:
- буферы: Для буферного кэша, используемого для ввода-вывода блочных устройств.
- кэш: Для кэша страниц, используемого файловыми системами.
Мы просто хотим проверить, что их размер не близок к нулю, что может привести к увеличению дискового ввода-вывода (подтвердите с помощью iostat) и ухудшению производительности. Приведенный выше пример выглядит нормально, в каждом из них много Мбайт.
Параметр "-/+ буферы/кэш" обеспечивает менее запутанные значения для используемой и свободной памяти. Linux использует свободную память для дискового кэша, но может быстро вернуть ее, если она нужна приложениям. Поэтому в некотором смысле кэш-память должна быть включена в колонку свободной памяти, что и делает эта строка. Существует даже сайт посвященный этой путанице.
Это может дополнительно запутать, если используется ZFS в Linux, как мы делаем для некоторых сервисов, поскольку ZFS имеет свой собственный кэш файловой системы, который не отражается должным образом в столбцах free -m. Может показаться, что в системе мало свободной памяти, в то время как на самом деле эта память доступна для использования из кэша ZFS по мере необходимости.
8. sar -n DEV 1
$ sar -n DEV 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
12:16:48 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
12:16:49 AM eth0 18763.00 5032.00 20686.42 478.30 0.00 0.00 0.00 0.00
12:16:49 AM lo 14.00 14.00 1.36 1.36 0.00 0.00 0.00 0.00
12:16:49 AM docker0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
12:16:49 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
12:16:50 AM eth0 19763.00 5101.00 21999.10 482.56 0.00 0.00 0.00 0.00
12:16:50 AM lo 20.00 20.00 3.25 3.25 0.00 0.00 0.00 0.00
12:16:50 AM docker0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
^C
Используйте этот инструмент для проверки пропускной способности сетевого интерфейса: rxkB/s и txkB/s, как меры рабочей нагрузки, а также для проверки достижения какого-либо предела. В приведенном выше примере скорость приема данных eth0 достигает 22 Мбайт/с, что составляет 176 Мбит/с (что намного меньше, скажем, предела в 1 Гбит/с).
В этой версии также есть %ifutil для использования устройства (максимум в обоих направлениях для полного дуплекса), для измерения которого мы также используем инструмент Брендана nicstat. Как и в случае с nicstat, этот параметр трудно настроить правильно, и, похоже, в данном примере он не работает (0.00).
9. sar -n TCP,ETCP 1
$ sar -n TCP,ETCP 1
Linux 3.13.0-49-generic (titanclusters-xxxxx) 07/14/2015 _x86_64_ (32 CPU)
12:17:19 AM active/s passive/s iseg/s oseg/s
12:17:20 AM 1.00 0.00 10233.00 18846.00
12:17:19 AM atmptf/s estres/s retrans/s isegerr/s orsts/s
12:17:20 AM 0.00 0.00 0.00 0.00 0.00
12:17:20 AM active/s passive/s iseg/s oseg/s
12:17:21 AM 1.00 0.00 8359.00 6039.00
12:17:20 AM atmptf/s estres/s retrans/s isegerr/s orsts/s
12:17:21 AM 0.00 0.00 0.00 0.00 0.00
^C
Это обобщенная информация о некоторых ключевых показателях TCP. К ним относятся:
- active/s: Количество локально инициированных TCP-соединений в секунду (например, через connect()).
- passive/s: Количество удаленно инициированных TCP-соединений в секунду (например, через accept()).
- retrans/s: Количество ретрансляций TCP в секунду.
Активный и пассивный счетчики часто полезны в качестве грубой меры нагрузки на сервер: количество новых принятых соединений (пассивное) и количество последующих соединений (активное). Можно считать, что активное соединение - это исходящее, а пассивное - входящее, но это не совсем так (например, рассмотрим соединение localhost - localhost).
Ретрансляции являются признаком проблем с сетью или сервером; это может быть ненадежная сеть (например, общедоступный Интернет) или перегрузка сервера, который отбрасывает пакеты. В приведенном выше примере показано только одно новое TCP-соединение в секунду.
10. top
$ top
top - 00:15:40 up 21:56, 1 user, load average: 31.09, 29.87, 29.92
Tasks: 871 total, 1 running, 868 sleeping, 0 stopped, 2 zombie
%Cpu(s): 96.8 us, 0.4 sy, 0.0 ni, 2.7 id, 0.1 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem: 25190241+total, 24921688 used, 22698073+free, 60448 buffers
KiB Swap: 0 total, 0 used, 0 free. 554208 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
20248 root 20 0 0.227t 0.012t 18748 S 3090 5.2 29812:58 java
4213 root 20 0 2722544 64640 44232 S 23.5 0.0 233:35.37 mesos-slave
66128 titancl+ 20 0 24344 2332 1172 R 1.0 0.0 0:00.07 top
5235 root 20 0 38.227g 547004 49996 S 0.7 0.2 2:02.74 java
4299 root 20 0 20.015g 2.682g 16836 S 0.3 1.1 33:14.42 java
1 root 20 0 33620 2920 1496 S 0.0 0.0 0:03.82 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.02 kthreadd
3 root 20 0 0 0 0 S 0.0 0.0 0:05.35 ksoftirqd/0
5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H
6 root 20 0 0 0 0 S 0.0 0.0 0:06.94 kworker/u256:0
8 root 20 0 0 0 0 S 0.0 0.0 2:38.05 rcu_sched
Команда top включает в себя многие метрики, которые мы проверяли ранее. Ее удобно выполнять, чтобы проверить, не выглядит ли что-то дико отличным от предыдущих команд, что указывает на переменную нагрузку.
Недостатком команды top является то, что с ее помощью сложнее увидеть закономерности во времени, которые могут быть более очевидны в таких инструментах, как vmstat и pidstat, которые обеспечивают скользящий вывод. Свидетельства периодических проблем также могут быть потеряны, если вы не приостановите вывод достаточно быстро (Ctrl-S для паузы, Ctrl-Q для продолжения), и экран очистится.
Последующий анализ
Есть еще много команд и методологий, которые можно применить для более глубокого анализа. Посмотрите учебник Брендана по инструментам производительности Linux с Velocity 2015, в котором рассматривается более 40 команд, охватывающих наблюдаемость, бенчмаркинг, настройку, статическую настройку производительности, профилирование и трассировку.
