В настоящее время я выслеживаю некоторые проблемы с производительностью на некоторых виртуальных машинах VMWare с тем же объемом памяти и процессором, работающих под управлением Oracle Linux 6.6 (ядро 2.6) и 6.7 (ядро 3.8). Машины монтируют один и тот же общий ресурс через NFS4, который содержит некоторые общие библиотеки, включенные в сборку с помощью LD_LIBRARY_PATH. Обе системы используют одни и те же параметры монтирования (по умолчанию), что явно означает «жесткий» для 6.7 и «мягкий» для 6.6. Начиная с версии 6.7, мы заметили, что производительность нашего процесса компиляции упала в 5 раз, в то время как процессоры простаивали около 80%, но при этом не наблюдалось большого io-ожидания (верхние отчеты ~ 0,4% wa).
Пытаясь воспроизвести проблему, я вскоре обнаружил, что не только компиляция, но и почти любая команда, например «ls», выполнялась намного медленнее в 6.7, как только разделяемые библиотеки из монтирования NFS были включены через LD_LIBRARY_PATH.
Я начал свое расследование с простого «времени»:
В 6.6: без установки LD_LIBRARY_PATH и PATH:
$ time for i in $(seq 0 1000); do ls done;
... ls output
real 0m2.917s
user 0m0.288s
sys 0m1.012s
с LD_LIBRARY_PATH и PATH, настроенными для включения каталогов в NFS
$ time for i in $(seq 0 1000); do ls done;
... ls output
real 0m2.766s
user 0m0.184s
sys 0m1.051s
На 6.7 без LD_LIBRARY_PATH
$ time for i in $(seq 0 1000); do ls done;
...
real 0m5.144s
user 0m0.280s
sys 0m1.172s
и с LD_LIBRARY_PATH
$ time for i in $(seq 0 1000); do ls done;
...
real 1m27.329s
user 0m0.537s
sys 0m1.792s
Огромные накладные расходы вызвали у меня любопытство, и с помощью strace я обнаружил, что разрешение некоторых разделяемых библиотек в общей папке NFS занимает очень много времени:
Опять же, без установки LD_LIBRARY_PATH вызовы "open" в выводе strace выглядят так:
$ strace -T ls 2>&1|vim - # keep only the "open" calls
open("/etc/ld.so.cache", O_RDONLY) = 3 <0.000014>
open("/lib64/libselinux.so.1", O_RDONLY) = 3 <0.000013>
open("/lib64/librt.so.1", O_RDONLY) = 3 <0.000016>
open("/lib64/libcap.so.2", O_RDONLY) = 3 <0.000014>
open("/lib64/libacl.so.1", O_RDONLY) = 3 <0.000014>
open("/lib64/libc.so.6", O_RDONLY) = 3 <0.000016>
open("/lib64/libdl.so.2", O_RDONLY) = 3 <0.000014>
open("/lib64/libpthread.so.0", O_RDONLY) = 3 <0.000014>
open("/lib64/libattr.so.1", O_RDONLY) = 3 <0.000014>
open("/proc/filesystems", O_RDONLY) = 3 <0.000032>
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3 <0.000014>
open(".", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3 <0.001255>
с LD_LIBRARY_PATH это выглядит так:
open("/usr/local/lib/librt.so.1", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000013>
open("/lib64/librt.so.1", O_RDONLY) = 3 <0.000018>
open("/oracle/current/lib/libcap.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) <0.006196>
open("/opt/development/opt/gcc/gcc-5.3.0/lib64/libcap.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) <0.002042>
open("/usr/local/lib/libcap.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000035>
open("/lib64/libcap.so.2", O_RDONLY) = 3 <0.000039>
open("/oracle/current/lib/libacl.so.1", O_RDONLY) = -1 ENOENT (No such file or directory) <0.009304>
open("/opt/development/opt/gcc/gcc-5.3.0/lib64/libacl.so.1", O_RDONLY) = -1 ENOENT (No such file or directory) <0.009107>
open("/usr/local/lib/libacl.so.1", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000023>
open("/lib64/libacl.so.1", O_RDONLY) = 3 <0.000027>
open("/oracle/current/lib/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) <0.009520>
open("/opt/development/opt/gcc/gcc-5.3.0/lib64/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) <0.007850>
open("/usr/local/lib/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000024>
open("/lib64/libc.so.6", O_RDONLY) = 3 <0.000030>
open("/oracle/current/lib/libdl.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) <0.006916>
open("/opt/development/opt/gcc/gcc-5.3.0/lib64/libdl.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) <0.013979>
open("/usr/local/lib/libdl.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000023>
open("/lib64/libdl.so.2", O_RDONLY) = 3 <0.000030>
open("/oracle/current/lib/libpthread.so.0", O_RDONLY) = -1 ENOENT (No such file or directory) <0.015317>
open("/opt/development/opt/gcc/gcc-5.3.0/lib64/libpthread.so.0", O_RDONLY) = -1 ENOENT (No such file or directory) <0.014230>
open("/usr/local/lib/libpthread.so.0", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000014>
open("/lib64/libpthread.so.0", O_RDONLY) = 3 <0.000019>
open("/oracle/current/lib/libattr.so.1", O_RDONLY) = -1 ENOENT (No such file or directory) <0.015212>
open("/opt/development/opt/gcc/gcc-5.3.0/lib64/libattr.so.1", O_RDONLY) = -1 ENOENT (No such file or directory) <0.011979>
open("/usr/local/lib/libattr.so.1", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000014>
open("/lib64/libattr.so.1", O_RDONLY) = 3 <0.000018>
open("/proc/filesystems", O_RDONLY) = 3 <0.000025>
open(".", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3 <0.000014>
Помимо совершения большего количества вызовов, что то же самое в 6.6, на 6.7 некоторые (неудачные) открытия занимают очень много времени на 6.7 (до 0,01 по сравнению с ~ 0,000020).
Итак, я начал исследовать NFS. И nfsstat действительно показывает удивительно разные статистические данные для обеих систем:
На 6.7
$ nfsstat
Client rpc stats:
calls retrans authrefrsh
1314991 0 1315849
Client nfs v4:
null read write commit open open_conf
0 0% 3782 0% 1589 0% 1 0% 561257 42% 53 0%
open_noat open_dgrd close setattr fsinfo renew
0 0% 0 0% 4750 0% 383 0% 7 0% 4094 0%
setclntid confirm lock lockt locku access
2 0% 2 0% 80 0% 0 0% 80 0% 538017 40%
getattr lookup lookup_root remove rename link
172506 13% 20536 1% 2 0% 112 0% 541 0% 2 0%
symlink create pathconf statfs readlink readdir
0 0% 9 0% 5 0% 2057 0% 164 0% 942 0%
server_caps delegreturn getacl setacl fs_locations rel_lkowner
12 0% 2968 0% 0 0% 0 0% 0 0% 80 0%
secinfo exchange_id create_ses destroy_ses sequence get_lease_t
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
reclaim_comp layoutget getdevinfo layoutcommit layoutreturn getdevlist
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
(null)
0 0%
На 6.6
$ nfsstat
Client rpc stats:
calls retrans authrefrsh
637725 0 637781
Client nfs v4:
null read write commit open open_conf
0 0% 23782 3% 13127 2% 48 0% 41244 6% 406 0%
open_noat open_dgrd close setattr fsinfo renew
0 0% 0 0% 31228 4% 14668 2% 7 0% 27319 4%
setclntid confirm lock lockt locku access
1 0% 1 0% 8493 1% 2 0% 8459 1% 175320 27%
getattr lookup lookup_root remove rename link
134732 21% 112688 17% 2 0% 1007 0% 6728 1% 4 0%
symlink create pathconf statfs readlink readdir
11 0% 129 0% 5 0% 7624 1% 143 0% 11507 1%
server_caps delegreturn getacl setacl fs_locations rel_lkowner
12 0% 12732 1% 0 0% 0 0% 0 0% 6335 0%
secinfo exchange_id create_ses destroy_ses sequence get_lease_t
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
reclaim_comp layoutget getdevinfo layoutcommit layoutreturn getdevlist
0 0% 0 0% 0 0% 0 0% 0 0% 0 0%
(null)
0 0%
которые, похоже, подтверждают длительное время открытия в 6.7, но я действительно не знаю, как решить эту проблему с помощью параметров монтирования и т. д.
Дополнительные эксперименты показали, что даже при монтировании NFS из контейнера Docker с современной ОС (CentOS 7, Ubuntu 16.04), что я сделал, чтобы исключить проблемы с nfsutils и т. Д., Производительность на узлах 6.7 всегда показывала одинаковую низкую производительность. при использовании NFS4. С NFS3 производительность на 6.7 не хуже, чем на 6.6.
На данный момент я ожидаю, что либо ядро (-module), либо vmware-tools на базовом хосте вызовут проблему, но мне не хватает идей, как копать дальше.
Это известная проблема? Я пропустил некоторых возможных виновников? Как бы вы копали дальше? Есть ли способ профилировать NFS-клиент? Как я могу исключить драйверы vmware как проблему?
И конечно: Есть у кого-нибудь простое решение для меня?
РЕДАКТИРОВАТЬ: Сегодня утром я копал в несколько другом направлении: с помощью tcpdump я проверил трафик NFS (снова), и похоже, что в 6.7 не происходит кеширования. Каждый доступ к (несуществующей) разделяемой библиотеке всегда вызывает фактический трафик NFS, так как LD_LIBRARY_PATH не содержит большинство библиотек, обычно возвращает reply ok 52 getattr ERROR: No such file or directory. На 6.6 только первый вызывает реальный трафик. Узнав это, я смог решить основную проблему производительности для стандартных команд, таких как «ls», переместив пути NFS из LD_LIBRARY_PATH в дополнительный файл ld.so.conf с библиотеками, необходимыми для нашего процесса компиляции. Однако это все еще обходной путь, и теперь проблема, похоже, в том, что в клиенте NFS не происходит кеширования. Поэтому я снова попытался активировать кеш файловой системы на NFS, как было предложено Вот, но все же каждое «открытие» вызывает трафик NFS, и компиляция по-прежнему недопустимо медленная.
По просьбе shodanshok:
На 6.6
server:/share /mnt nfs4 rw,relatime,vers=4,rsize=1048576,wsize=1048576,namlen=255,soft,proto=tcp,port=0,timeo=600,retrans=2,sec=sys,clientaddr=<clientip>,minorversion=0,local_lock=none,addr=<serverip> 0 0
На 6.7 (после активации fsc)
server:/share /mnt nfs4 ro,relatime,vers=4.0,rsize=1048576,wsize=1048576,namlen=255,soft,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=<clientip>,fsc,local_lock=none,addr=<serverip> 0 0
Ни одна из машин не использует nscd. Однако некоторое время назад я установил cachefilesd на обеих машинах, чтобы посмотреть, поможет ли это с производительностью, но этого не произошло. В настоящее время кеш на 6.6 даже не активен (/ var / cache / fscache / * пуст), и, начиная с использования fsc сегодня утром в параметрах монтирования, он фактически содержит 3 файла на 6.7, но, похоже, он не кеширует не- существующий путь к разделяемой библиотеке, поэтому производительность не изменилась. Для несуществующих файлов я ожидал acregminи т. д., чтобы оказать влияние, но хотя их (по умолчанию) значения - мне кажутся разумными, они, похоже, не имеют никакого эффекта.
Вывод mountstats
Stats for server:/share mounted on /mnt:
NFS mount options: rw,vers=4.0,rsize=1048576,wsize=1048576,namlen=255,acregmin=3,acregmax=60,acdirmin=30,acdirmax=60,soft,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=10.114.160.159,fsc,local_lock=none
NFS server capabilities: caps=0xfff7,wtmult=512,dtsize=32768,bsize=0,namlen=255
NFSv4 capability flags: bm0=0xfdffafff,bm1=0xf9be3e,acl=0x0,pnfs=notconfigured
NFS security flavor: 1 pseudoflavor: 0
Кто-нибудь знает, что означают эти флаги (например, caps, bm0, bm1, ...)?
Выход Sanitized ps ax: на 6.6
PID TTY STAT TIME COMMAND
1 ? Ss 0:01 /sbin/init
2 ? S 0:00 [kthreadd]
3 ? S 0:05 [ksoftirqd/0]
6 ? S 0:00 [migration/0]
7 ? S 0:10 [watchdog/0]
37 ? S< 0:00 [cpuset]
38 ? S< 0:00 [khelper]
39 ? S< 0:00 [netns]
40 ? S 0:06 [sync_supers]
41 ? S 0:00 [bdi-default]
42 ? S< 0:00 [kintegrityd]
43 ? S< 0:00 [kblockd]
50 ? S 0:49 [kworker/1:1]
51 ? S< 0:00 [xenbus_frontend]
52 ? S< 0:00 [ata_sff]
53 ? S 0:00 [khubd]
54 ? S< 0:00 [md]
55 ? S 0:01 [khungtaskd]
56 ? S 0:04 [kswapd0]
57 ? SN 0:00 [ksmd]
58 ? S 0:00 [fsnotify_mark]
59 ? S< 0:00 [crypto]
64 ? S< 0:00 [kthrotld]
66 ? S< 0:00 [kpsmoused]
240 ? S 0:00 [scsi_eh_0]
241 ? S 0:00 [scsi_eh_1]
248 ? S< 0:00 [mpt_poll_0]
249 ? S< 0:00 [mpt/0]
250 ? S 0:00 [scsi_eh_2]
313 ? S< 0:00 [kdmflush]
325 ? S 0:00 [kjournald]
445 ? S<s 0:00 /sbin/udevd -d
706 ? S< 0:00 [vmmemctl]
815 ? S< 0:00 [kdmflush]
865 ? S 0:08 [kjournald]
907 ? S 0:00 [kauditd]
1091 ? S 0:11 [flush-252:2]
1243 ? S 26:05 /usr/sbin/vmtoolsd
1311 ? Ssl 0:03 /sbin/rsyslogd -i /var/run/syslogd.pid -c 5
1334 ? Ss 0:06 cachefilesd -f /etc/cachefilesd.conf
1361 ? Ss 6:55 irqbalance --pid=/var/run/irqbalance.pid
1377 ? Ss 0:02 rpcbind
1397 ? Ss 0:00 rpc.statd
1428 ? S< 0:00 [rpciod]
1433 ? Ss 0:00 rpc.idmapd
1507 ? S< 0:00 [nfsiod]
1508 ? S 0:00 [nfsv4.0-svc]
1608 ? Ss 0:00 xinetd -stayalive -pidfile /var/run/xinetd.pid
1783 ? Ss 0:11 crond
1796 ? Ss 0:00 /usr/sbin/atd
1807 ? Ss 0:01 rhnsd
1989 ? S 99:05 /usr/lib/vmware-tools/sbin64/vmtoolsd -n vmusr
4879 ? S 0:00 /bin/sh /etc/xrdp/startwm.sh
4904 ? Ss 0:02 /bin/dbus-daemon --fork --print-pid 5 --print- address 7 --session
4924 ? S 60:14 /usr/lib/vmware-tools/sbin64/vmtoolsd -n vmusr
и в 6.7:
PID TTY STAT TIME COMMAND
1 ? Ss 0:01 /sbin/init
3 ? S 0:10 [ksoftirqd/0]
5 ? S< 0:00 [kworker/0:0H]
8 ? S 0:19 [migration/0]
11 ? S 0:02 [watchdog/0]
47 ? S< 0:00 [cpuset]
48 ? S< 0:00 [khelper]
49 ? S 0:00 [kdevtmpfs]
50 ? S< 0:00 [netns]
51 ? S 0:00 [bdi-default]
52 ? S< 0:00 [kintegrityd]
53 ? S< 0:00 [crypto]
54 ? S< 0:00 [kblockd]
62 ? S< 0:00 [ata_sff]
63 ? S 0:00 [khubd]
64 ? S< 0:00 [md]
66 ? S 0:00 [khungtaskd]
67 ? S 0:36 [kswapd0]
68 ? SN 0:00 [ksmd]
69 ? S 0:00 [fsnotify_mark]
80 ? S< 0:00 [kthrotld]
84 ? S< 0:00 [deferwq]
151 ? S< 0:00 [ttm_swap]
273 ? S 0:00 [scsi_eh_0]
274 ? S 0:00 [scsi_eh_1]
281 ? S< 0:00 [mpt_poll_0]
282 ? S< 0:00 [mpt/0]
283 ? S 0:00 [scsi_eh_2]
374 ? S< 0:00 [kdmflush]
387 ? S 0:00 [kjournald]
480 ? S<s 0:00 /sbin/udevd -d
872 ? S< 0:00 [kworker/2:1H]
1828 ? S< 0:00 [kdmflush]
1834 ? S< 0:00 [kdmflush]
1837 ? S< 0:00 [kdmflush]
1840 ? S< 0:00 [kdmflush]
1881 ? S 0:00 [kjournald]
1882 ? S 0:03 [kjournald]
1883 ? S 0:03 [kjournald]
1884 ? S 3:14 [kjournald]
1926 ? S 0:00 [kauditd]
2136 ? S 1:37 [flush-252:1]
2137 ? S 0:02 [flush-252:2]
2187 ? S 5:04 /usr/sbin/vmtoolsd
2214 ? S 0:00 /usr/lib/vmware-vgauth/VGAuthService -s
2264 ? Sl 1:54 ./ManagementAgentHost
2327 ? Ssl 0:00 /sbin/rsyslogd -i /var/run/syslogd.pid -c 5
2368 ? Ss 0:00 rpcbind
2390 ? Ss 0:00 rpc.statd
2425 ? S< 0:00 [rpciod]
2430 ? Ss 0:00 rpc.idmapd
2456 ? Ss 0:00 dbus-daemon --system
2473 ? S 0:00 [kworker/7:2]
2501 ? S< 0:00 [nfsiod]
2504 ? S 0:00 [nfsv4.0-svc]
2519 ? Ss 0:00 /usr/sbin/acpid
2531 ? Ssl 0:02 hald
2532 ? S 0:00 hald-runner
2564 ? S 0:00 hald-addon-input: Listening on /dev/input/ event1 /dev/input/event0
2580 ? S 0:00 hald-addon-acpi: listening on acpid socket /var/run/acpid.socket
2618 ? Ss 0:00 /usr/sbin/sshd
2629 ? Ss 0:00 xinetd -stayalive -pidfile /var/run/xinetd.pid
2778 ? S 0:00 qmgr -l -t fifo -u
2811 ? S 0:56 /usr/bin/python /usr/sbin/osad --pid-file /var/run/osad.pid
2887 ? S< 0:00 [dm_bufio_cache]
3008 ? Ss 0:00 rhnsd
3117 ? S 9:44 /usr/lib/vmware-tools/sbin64/vmtoolsd -n vmusr
3195 ? S 0:00 /usr/libexec/polkit-1/polkitd
3825 ? S< 0:17 [loop0]
3828 ? S< 0:21 [loop1]
3830 ? S< 0:00 [kdmflush]
3833 ? S< 0:00 [kcopyd]
3834 ? S< 0:00 [dm-thin]
6876 ? S 0:00 (unlinkd)
19358 ? S 0:00 [flush-0:19]
24484 ? S< 0:00 /sbin/udevd -d
24921 ? S< 0:00 /sbin/udevd -d
26201 ? Ss 0:00 cachefilesd -f /etc/cachefilesd.conf
29311 ? S< 0:00 [kdmflush]
29316 ? S 0:00 [jbd2/dm-6-8]
29317 ? S< 0:00 [ext4-dio-unwrit]
Несколько дней назад я был уверен, что обнаружил проблему при сравнении вывода sysctl -a на обеих системах показали разницу в fs.nfs.idmap_cache_timeout который установлен на 600 на 6.6 и на 0 на 6.7, но его изменение также не дало желаемого эффекта.
Но я нашел еще одну полезную команду: rpcdebug -m nfs -s all выводит много отладочной информации относительно кеширования в системный журнал (/var/log/messages в моем случае). Большинство записей при выполнении моей ls выглядят следующим образом
Feb 27 10:45:16 host kernel: NFS: nfs_lookup_revalidate(//opt) is valid
Feb 27 10:45:16 host kernel: NFS: nfs_lookup_revalidate(opt/gcc) is valid
Feb 27 10:45:16 host kernel: NFS: nfs_lookup_revalidate(gcc/gcc-5.3.0) is valid
Feb 27 10:45:16 host kernel: NFS: nfs_lookup_revalidate(gcc-5.3.0/lib64) is valid
и из этих блоков несколько экземпляров в секунду (это даже с lookupcache=all).
Ура!
Кстати, будьте осторожны, используя soft крепления:
С мягко смонтированными файловыми системами вам нужно беспокоиться о повреждении данных из-за неполной записи, потере доступа к текстовому сегменту замененного процесса и о том, что мягко смонтированные файловые системы будут более устойчивыми к изменениям во времени ответа сервера.
Чтобы гарантировать целостность данных, все файловые системы, смонтированные для чтения и записи, должны быть жестко смонтированы.
С помощью hard,intr рекомендуется для всех файловых систем, смонтированных по NFS.
Ты используешь fs-cache или nscd на вашей установке CentOS 6.6? Вы можете опубликовать ps ax обеих машин, а также выпуск /proc/mounts/ ?