Высокая средняя нагрузка, низкая загрузка процессора - почему?

78

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

Стек программного обеспечения на этом сервере выглядит следующим образом:

  • Солярис 10
  • Java 1.6
  • WebLogic 10.3.5 (8 доменов)

Приложения, запущенные на этом сервере, взаимодействуют с базой данных Oracle на другом сервере.

Этот сервер имеет 32 ГБ оперативной памяти и 10 процессоров (я думаю).

Бег prstat -Zдает что-то вроде этого:

   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP
  3836 ducm0101 2119M 2074M cpu348  58    0   8:41:56 0.5% java/225
 24196 ducm0101 1974M 1910M sleep   59    0   4:04:33 0.4% java/209
  6765 ducm0102 1580M 1513M cpu330   1    0   1:21:48 0.1% java/291
 16922 ducm0102 2115M 1961M sleep   58    0   6:37:08 0.0% java/193
 18048 root     3048K 2440K sleep   59    0   0:06:02 0.0% sa_comm/4
 26619 ducm0101 2588M 2368M sleep   59    0   8:21:17 0.0% java/231
 19904 ducm0104 1713M 1390M sleep   59    0   1:15:29 0.0% java/151
 27809 ducm0102 1547M 1426M sleep   59    0   0:38:19 0.0% java/186
  2409 root       15M   11M sleep   59    0   0:00:00 0.0% pkgserv/3
 27204 root       58M   54M sleep   59    0   9:11:38 0.0% stat_daemon/1
 27256 root       12M 8312K sleep   59    0   7:16:40 0.0% kux_vmstat/1
 29367 root      297M  286M sleep   59    0  11:02:13 0.0% dsmc/2
 22128 root       13M 6768K sleep   59    0   0:10:51 0.0% sendmail/1
 22133 smmsp      13M 1144K sleep   59    0   0:01:22 0.0% sendmail/1
 22003 root     5896K  240K sleep   59    0   0:00:01 0.0% automountd/2
 22074 root     4776K 1992K sleep   59    0   0:00:19 0.0% sshd/1
 22005 root     6184K 2728K sleep   59    0   0:00:31 0.0% automountd/2
 27201 root     6248K  344K sleep   59    0   0:00:01 0.0% mount_stat/1
 20964 root     2912K  160K sleep   59    0   0:00:01 0.0% ttymon/1
 20947 root     1784K  864K sleep   59    0   0:02:22 0.0% utmpd/1
 20900 root     3048K  608K sleep   59    0   0:00:03 0.0% ttymon/1
 20979 root       77M   18M sleep   59    0   0:14:13 0.0% inetd/4
 20849 daemon   2856K  864K sleep   59    0   0:00:03 0.0% lockd/2
 17794 root       80M 1232K sleep   59    0   0:06:19 0.0% svc.startd/12
 17645 root     3080K  728K sleep   59    0   0:00:12 0.0% init/1
 17849 root       13M 6800K sleep   59    0   0:13:04 0.0% svc.configd/15
 20213 root       84M   81M sleep   59    0   0:47:17 0.0% nscd/46
 20871 root     2568K  600K sleep   59    0   0:00:04 0.0% sac/1
  3683 ducm0101 1904K 1640K sleep   56    0   0:00:00 0.0% startWebLogic.s/1
 23937 ducm0101 1904K 1640K sleep   59    0   0:00:00 0.0% startWebLogic.s/1
 20766 daemon   5328K 1536K sleep   59    0   0:00:36 0.0% nfsmapid/3
 20141 daemon   5968K 3520K sleep   59    0   0:01:14 0.0% kcfd/4
 20093 ducm0101 2000K  376K sleep   59    0   0:00:01 0.0% pfksh/1
 20797 daemon   3256K  240K sleep   59    0   0:00:01 0.0% statd/1
  6181 root     4864K 2872K sleep   59    0   0:01:34 0.0% syslogd/17
  7220 ducm0104 1268M 1101M sleep   59    0   0:36:35 0.0% java/138
 27597 ducm0102 1904K 1640K sleep   59    0   0:00:00 0.0% startWebLogic.s/1
 27867 root       37M 4568K sleep   59    0   0:13:56 0.0% kcawd/7
 12685 ducm0101 4080K  208K sleep   59    0   0:00:01 0.0% vncconfig/1
ZONEID    NPROC  SWAP   RSS MEMORY      TIME  CPU ZONE
    42      135   22G   19G    59%  87:27:59 1.2% dsuniucm01

Total: 135 processes, 3167 lwps, load averages: 54.48, 62.50, 63.11

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

Бег vmstat 15дает что-то вроде этого:

 kthr      memory            page            disk          faults      cpu
 r b w   swap  free  re  mf pi po fr de sr s0 s1 s4 sd   in   sy   cs us sy id
 0 0 0 32531400 105702272 317 1052 126 0 0 0 0 13 13 -0 8 9602 107680 10964 1 1 98
 0 0 0 15053368 95930224 411 2323 0 0 0 0 0 0  0  0  0 23207 47679 29958 3 2 95
 0 0 0 14498568 95801960 3072 3583 0 2 2 0 0 3 3  0 21 22648 66367 28587 4 4 92
 0 0 0 14343008 95656752 3080 2857 0 0 0 0 0 3 3  0 18 22338 44374 29085 3 4 94
 0 0 0 14646016 95485472 1726 3306 0 0 0 0 0 0 0  0  0 24702 47499 33034 3 3 94

Я понимаю, что процессор в основном простаивает, никакие процессы не ожидают выполнения в очереди, происходит небольшая перестановка.

Бег iostat 15дает это:

   tty        sd0           sd1           sd4           ssd0           cpu
 tin tout kps tps serv  kps tps serv  kps tps serv  kps tps serv   us sy wt id
   0  676 324  13    8  322  13    8    0   0    0  159   8    0    1  1  0 98
   1 1385   0   0    0    0   0    0    0   0    0    0   0    0    3  4  0 94
   0  584  89   6   24   89   6   25    0   0    0  332  19    0    2  1  0 97
   0  296   0   0    0    0   0    0    0   0    0    0   0    0    2  2  0 97
   1 1290  43   5   24   43   5   22    0   0    0  297  20    1    3  3  0 94

Бег netstat -i 15дает следующее:

    input   aggr26    output       input  (Total)    output
packets errs  packets errs  colls  packets errs  packets errs  colls
1500233798 0     1489316495 0     0      3608008314 0     3586173708 0     0
10646   0     10234   0     0      26206   0     25382   0     0
11227   0     10670   0     0      28562   0     27448   0     0
10353   0     9998    0     0      29117   0     28418   0     0
11443   0     12003   0     0      30385   0     31494   0     0

Что мне не хватает?

Spiff
источник
Я не дома с Solaris, поэтому я передам это кому-нибудь еще, но я бы начал смотреть на ваш конфиг веб-сервера. Возможно, что-то искусственно ограничивает производительность таким образом, чтобы оставить много потоков в очереди выполнения. (Не уверен, что это может быть или даже если это возможно, хотя). Слава за хорошо написанный вопрос, хотя.
SmallClanger
4
10 процессоров (я думаю) , возможно, проблема. Вы должны более точно знать, какое оборудование вы используете, прежде чем продолжить исследование. Используйте psrinfo -vдля отображения фактического количества процессоров.
Jlliagre
Я никогда не слышал об этой команде, но, похоже, что при ее запуске около 250 виртуальных процессоров. Это вообще имеет смысл? В этом случае средняя нагрузка 50 будет незначительной?
Spiff
Я думаю, что это также может произойти, когда ваш диск заполнен. У меня было это сегодня с 1% свободного места, /и нагрузка продолжала увеличиваться, пока не закончилось 19.00без видимой причины. Освобождение свободного пространства решило проблему (вскоре после того, как она появилась); Также может быть совпадением.
nh2

Ответы:

40

После некоторых дальнейших исследований выясняется, что проблема производительности в основном связана с большим количеством сетевых вызовов между двумя системами (Oracle SSXA и UCM). Вызовы быстрые, но много и сериализованы, отсюда и низкая загрузка ЦП (в основном ожидающая ввода-вывода), высокая загрузка (много вызовов, ожидающих обработки) и особенно длительное время ответа (из-за небольшого времени отклика).

Спасибо за ваше понимание этой проблемы!

Spiff
источник
4
как вы это подтвердили и выяснили? Мы видим ту же проблему и хотели бы проверить, есть ли у нас такая же проблема
hobgoblin
32

Когда вы говорите «Среднее значение высокой нагрузки», я предполагаю, что вы подразумеваете, что prstat показывает «среднее значение нагрузки» в нижней части выходных данных

Total: 135 processes, 3167 lwps, load averages: 54.48, 62.50, 63.11

Эти числа похожи на те, что указаны в top, и, вероятно, означают средний размер очереди запущенного процесса. Это не процент использования процессорного времени, а то, сколько «вещей» изводит процессор за время его работы. По общему признанию, они выглядят довольно высокими, но все это зависит от приложения, которое вы запускаете; процессы могут на самом деле не делать много, как только они получают свой слот. Смотрите здесь для хорошего объяснения относительно топ.

Я не знаком с WebLogic, но заметил, что, как правило, с Apache Tomcat можно создавать много потоков Java одновременно для того, что выглядит как небольшое количество запросов. Это может быть причиной высоких показателей загрузки. Убедитесь, что вы используете пул соединений, где это уместно, для подключения к бэкэнду и рассмотрите возможность увеличения числа незанятых потоков, доступных вашему приложению для обработки соединений (не знаете, как это сделать в WebLogic; у Tomcat есть пул потоков для каждого соединителя или общий пул потоков исполнителя). Если вы этого не сделаете, то для обработки запросов могут появляться новые темы.

Что касается производительности, вам нужно определить, какая часть вашего приложения страдает. Это обработка, которая происходит на стороне WebLogic / Java, доступ к базе данных, поиск DNS (если они выполняются по какой-то причине ...), проблемы с сетью или что-то в ОС.

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

Для Java я бы предложил установить Java Melody . Он может предоставить много информации о том, что делает ваша программа, и помочь определить, где она проводит время. Я использовал его только с Tomcat, но должен нормально работать с любым контейнером / сервлетом Java EE.

Существует несколько способов настройки Java, поэтому ознакомьтесь с их рекомендациями по производительности (я уверен, что это возможно) и убедитесь, что вы устанавливаете правильный размер кучи и т. Д., Подходящий для вашей программы. Java Melody может помочь вам отследить размер кучи Java, которую вы потребляете, а также то, как тяжело работает сборщик мусора / как часто он прерывает вашу программу для очистки объектов.

Я надеюсь, что это было полезно. Если вы предоставите дополнительную информацию, я смогу обновить этот ответ и отточить его в соответствии с вашими потребностями.

webtoe
источник
1
Спасибо за ваш ответ, если бы мой представитель был достаточно высок, я бы проголосовал за него. Из моего опыта код или запросы SQL обычно являются виновником. Я сделал несколько прогонов профилирования и не смог найти ни одной горячей точки, поэтому я начал смотреть на более фундаментальные факторы. Я буду исследовать еще немного и обновлю вопрос, как я найду больше.
Spiff
4
Я также проверил бы вывод mpstat 1 5 для просмотра статистики по процессорам и просмотра столбцов csw и syscl. Из вышеприведенного vmstat видно, что вы делаете довольно много системных вызовов и переключений контекста, что, по-видимому, подтверждает подозрение webtoe о том, что у вас много потоков (Solaris называет их процессами LWPs-LightWeight), постоянно беспокоящими ЦП. Никто из них не делает очень много, когда работает, но многие тратят время на ожидание бега, отсюда средняя нагрузка.
Eirescot
25

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

См. Http://en.wikipedia.org/wiki/Load_(computing) «Linux также включает [в свою среднюю загрузку] процессы в непрерывных состояниях сна (обычно ожидающих активности диска)»

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

Похоже, что, по крайней мере, в моем случае, иногда потоки / процессы, ожидающие ввода-вывода, отображаются в средней загрузке, но не вызывают увеличения в столбце «ожидание». Но они все еще связаны с I / O.

Вы можете сказать, что это имеет место со следующим кодом, если вы запускаете его в jruby (просто выполняет 100 потоков с большим количеством операций ввода-вывода каждый):

100.times { Thread.new { loop { File.open('big', 'w') do |f| f.seek 10_000_000_000; f.puts 'a'; end}}}

Что дает максимальный результат, как это:

top - 17:45:32 up 38 days,  2:13,  3 users,  load average: 95.18, 50.29, 23.83
Tasks: 181 total,   1 running, 180 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.5%us, 11.3%sy,  0.0%ni, 85.1%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  32940904k total, 23239012k used,  9701892k free,   983644k buffers
Swap: 34989560k total,        0k used, 34989560k free,  5268548k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
31866 packrd    18   0 19.9g  12g  11m S 117.0 41.3   4:43.85 java
  912 root      11  -5     0    0    0 S  2.0  0.0   1:40.46 kjournald

Таким образом, вы можете видеть, что у него много простаивающих процессоров, 0,0% ва, но очень высокая средняя загрузка.

iostat аналогично показывает диск в основном в режиме ожидания:

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
       9.62    0.00    8.75    0.00    0.00   81.62

Device:         rrqm/s   wrqm/s   r/s   w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00    49.00  0.00  6.40     0.00   221.60    69.25     0.01    0.81   0.66   0.42
sda1              0.00    49.00  0.00  6.40     0.00   221.60    69.25     0.01    0.81   0.66   0.42
sda2              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

см. также http://linuxgazette.net/141/misc/lg/tracking_load_average_issues.html

В качестве дополнительного примечания следует, что это также означает, что (по крайней мере, в этом случае - при запуске CentOS) среднее значение нагрузки включает в себя каждый поток отдельно.

rogerdpack
источник
2
«Средняя нагрузка также включает в себя вещи, ожидающие активности диска» в Linux , в то время как этот вопрос изначально был о Solaris, который, похоже, включает в себя только выполнение и выполнение задач (то есть ожидание ЦП) в средней нагрузке . Одна из версий этого вопроса для Linux заключается в следующем .
Николай
7

Была такая же проблема сегодня. После некоторых исследований и диагностики я понял, что на моем маленьком VPS заканчивается диск .

В типе shell / prompt (Linux / Unix)

df -h

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

PJunior
источник
я полагаю, вы тогда обменивались, так что это стало причиной?
rogerdpack
4

Другим полезным инструментом, который поможет в этой ситуации, является nmon.

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

Если это содержимое, которое нельзя кэшировать, я бы рекомендовал разместить несколько серверов за балансировщиком нагрузки, например haproxy, в режиме tcp для распределения нагрузки.

Дэниел Бейкер
источник
2

Просто добавьте к этому некоторые специфические инструменты Solaris, которые не были упомянуты и которые полезны при отладке таких проблем, это «intrstat», «mpstat» и «lockstat». Испытывая аналогичную проблему на хосте, работающем с большими нагрузками ETL, mpstat обнаружил большое количество прерываний, связанных с большим количеством операций ввода-вывода, что намекало на проблему.

В то время на T4-4 с mpstat мы видели, как vcpus передает более 30000 прерываний в течение короткого цикла мониторинга, после чего производительность начинает падать. В этом случае единственным обходным решением было добавить больше ресурсов процессора, однако впоследствии была проведена работа по улучшению кода.

Брендан Грегг много писал о производительности, особенно о вводе / выводе за последние годы, и его стоит поискать, если вы хотите узнать больше.

Rowley
источник