Мне сложно понять причину высокого iowait на моем сервере.
top:
%Cpu(s): : 30.0 us, 5.4 sy, 0.0 ni, 53.9 id, 10.1 wa, 0.0 hi, 0.7 si, 0.0 st
iostat:
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
sda 0.00 1.00 0.00 0.80 0.00 7.20 18.00 0.00 0.25 0.00 0.25 0.25 0.02
iotop:
Total DISK READ : 0.00 B/s | Total DISK WRITE : 0.00 B/s
Actual DISK READ: 0.00 B/s | Actual DISK WRITE: 0.00 B/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
4807 be/4 daemon 0.00 B/s 0.00 B/s 0.00 % 21.66 % httpd -k restart
4522 be/4 daemon 0.00 B/s 0.00 B/s 0.00 % 10.76 % httpd -k restart
4547 be/4 daemon 0.00 B/s 0.00 B/s 0.00 % 7.87 % httpd -k restart
4603 be/4 daemon 0.00 B/s 0.00 B/s 0.00 % 7.66 % httpd -k restart
4652 be/4 daemon 0.00 B/s 0.00 B/s 0.00 % 5.36 % httpd -k restart
4671 be/4 daemon 0.00 B/s 0.00 B/s 0.00 % 4.83 % httpd -k restart
поэтому похоже, что вся активность ввода-вывода генерируется httpd, но на sda нет активности, и на сервере больше нет жестких или сетевых дисков.
Я пробовал strace на httpd:
Process 4975 attached
accept4(4, {sa_family=AF_INET6, sin6_port=htons(60547), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28], SOCK_CLOEXEC) = 9
getsockname(9, {sa_family=AF_INET6, sin6_port=htons(8080), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
fcntl(9, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(9, "GET /category/toys/ HTTP/1.0\r"..., 8000) = 287
stat("/srv/www/website/category/toys/", 0x7ffff11072d0) = -1 ENOENT (No such file or directory)
lstat("/srv", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/srv/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/srv/www/website", {st_mode=S_IFDIR|0755, st_size=20480, ...}) = 0
lstat("/srv/www/website/category", 0x7ffff11072d0) = -1 ENOENT (No such file or directory)
stat("/srv/www/website/index.php", {st_mode=S_IFREG|0644, st_size=39274, ...}) = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={6000000, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x7f4329cbc270, [PROF], SA_RESTORER|SA_RESTART, 0x7f432a7bd650}, {0x7f4329cbc270, [PROF], SA_RESTORER|SA_RESTART, 0x7f432a7bd650}, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
getcwd("/", 4095) = 2
chdir("/srv/www/website") = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={1000000, 0}}, NULL) = 0
fcntl(7, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=1, len=1}) = 0
getcwd("/srv/www/website", 4096) = 17
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 10
connect(10, {sa_family=AF_LOCAL, sun_path="/tmp/memcached2.sock"}, 110) = 0
sendto(10, "get memc.sess.key.ee3e1a44ced404"..., 52, MSG_NOSIGNAL, NULL, 0) = 52
recvfrom(10, "VALUE memc.sess.key.ee3e1a44ced4"..., 8196, MSG_NOSIGNAL, NULL, NULL) = 175
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 11
connect(11, {sa_family=AF_LOCAL, sun_path="/tmp/memcached.sock"}, 110) = 0
sendto(11, "get 389768020cec2648767316c7233f"..., 38, MSG_NOSIGNAL, NULL, 0) = 38
recvfrom(11, "VALUE 389768020cec2648767316c723"..., 8196, MSG_NOSIGNAL, NULL, NULL) = 8196
recvfrom(11, "\0\"\345\22\315\00230:\374\16u\205\315\360\23\375\00050\376\0009\353\0\250\342\n\213\353Si"..., 8196, MSG_NOSIGNAL, NULL, NULL) = 8196
recvfrom(11, "px#f =\7body><tr@\v\0d \4\1ul \4\1li\304\36\2"..., 8196, MSG_NOSIGNAL, NULL, NULL) = 4629
sendto(11, "quit\r\n", 6, MSG_NOSIGNAL, NULL, 0) = 6
shutdown(11, SHUT_WR) = 0
shutdown(11, SHUT_RD) = 0
close(11) = 0
writev(9, [{"HTTP/1.1 200 OK\r\nDate: Mon, 11 M"..., 246}, {"<!DOCTYPE html> <html lang=\"en\">"..., 107113}], 2) = 107359
chdir("/") = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
sendto(10, "set memc.sess.key.ee3e1a44ced404"..., 175, MSG_NOSIGNAL, NULL, 0) = 175
recvfrom(10, "STORED\r\n", 8196, MSG_NOSIGNAL, NULL, NULL) = 8
sendto(10, "quit\r\n", 6, MSG_NOSIGNAL, NULL, 0) = 6
shutdown(10, SHUT_WR) = 0
shutdown(10, SHUT_RD) = 0
close(10) = 0
fcntl(7, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
writev(9, [{"<!-- static content | last modif"..., 60}], 1) = 60
times({tms_utime=40554, tms_stime=8627, tms_cutime=0, tms_cstime=0}) = 456014999
shutdown(9, SHUT_WR) = 0
poll([{fd=9, events=POLLIN}], 1, 2000) = 1 ([{fd=9, revents=POLLIN|POLLHUP}])
read(9, "", 512) = 0
close(9) = 0
read(5, 0x7ffff1107697, 1) = -1 EAGAIN (Resource temporarily unavailable)
accept4(4,
он делает довольно много lstats для всей структуры каталогов, несмотря на правило перезаписи, чтобы направлять все запросы на index.php, но возможно ли, что эти простые lstats ответственны за такой огромный iowait? Он также имеет некоторую связь с серверами memcached через сокет unix, но, насколько я читал, связь сокета unix не считается iowait.
Сервер выполняет около 200 запросов в секунду только с динамическим контентом, но весь этот контент буферизуется в ОЗУ (без подкачки, чтобы быть уверенным и 64 ГБ оперативной памяти), и он ничего не читает с диска, так почему iowait такой высокий?
Как я могу диагностировать эту проблему? Есть ли способ измерить несколько вызовов процессов httpd, которые увеличивают iowait, когда почти не используется блочное устройство?
Обновление 1: Сервер находится в сети 1GE, скорость ~ 10 Мбит / с без ошибок.
Обновление 2: strace -c -f -p:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
46.39 0.006063 1 10330 poll
26.66 0.003485 0 10212 71 recvfrom
7.98 0.001043 1 880 sendto
5.03 0.000658 2 294 109 connect
2.39 0.000313 1 294 socket
2.10 0.000274 1 338 close
1.45 0.000189 1 341 43 read
1.44 0.000188 4 43 accept4
1.40 0.000183 0 509 fcntl
1.26 0.000165 3 52 writev
0.83 0.000109 1 193 shutdown
0.55 0.000072 1 84 chdir
0.42 0.000055 0 168 setitimer
0.41 0.000053 1 73 stat
0.33 0.000043 1 43 getsockname
0.25 0.000033 0 116 rt_sigaction
0.24 0.000032 0 72 getcwd
0.21 0.000028 0 109 getsockopt
0.21 0.000027 0 60 lstat
0.16 0.000021 0 106 setsockopt
0.11 0.000014 0 43 times
0.08 0.000010 0 42 rt_sigprocmask
0.05 0.000007 7 1 select
0.02 0.000003 1 5 access
0.02 0.000002 0 6 brk
0.00 0.000000 0 1 open
0.00 0.000000 0 1 mmap
0.00 0.000000 0 1 munmap
------ ----------- ----------- --------- --------- ----------------
100.00 0.013070 24417 223 total
это результат команды strace -c, запущенной около одной минуты, но я все еще не могу найти ничего, что могло бы сгенерировать такой высокий iowait ...
Обновление 3:
Я изменил конфигурацию httpd и переместил RewriteRules из каталога в область VirtualHost, чтобы я мог отключить FollowSymLinks и сохранил несколько дополнительных вызовов lstat для каждого запроса из:
stat("/srv/www/website/category/toys/", 0x7ffff11072d0) = -1 ENOENT (No such file or directory)
lstat("/srv", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/srv/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/srv/www/website", {st_mode=S_IFDIR|0755, st_size=20480, ...}) = 0
lstat("/srv/www/website/category", 0x7ffff11072d0) = -1 ENOENT (No such file or directory)
stat("/srv/www/website/index.php", {st_mode=S_IFREG|0644, st_size=39274,
чтобы просто:
stat("/srv/www/website/index.php", {st_mode=S_IFREG|0644, st_size=39274, ...}) = 0
lstat("/srv/www/website/index.php", {st_mode=S_IFREG|0644, st_size=39274, ...}) = 0
но влияние на ввод-вывод отсутствует. Я также заметил, что примерно через 10 секунд после перезапуска httpd (HTTP-запросы обслуживаются все это время) iowait находится на уровне 0-1%, а затем поднимается - может быть, это может быть ключом к разгадке?
Обновление 4
Я изменил Мин запасных серверов с 280 до 64, а iowait был уменьшен до 1%. Это может быть связано с табло, как упоминал Кэмерон Керр, или с некоторым взаимодействием между родителями и детьми, но насколько я прочитал «Apache httpd сначала пытается создать табло полностью в памяти», и мои экземпляры apache не используют табло на основе файлов.
Кто-нибудь знает, почему количество резервных процессов prefork так сильно влияет на iowait (20% против 2% для 280 против 64 резервных процессов)?