Oracle Linux 6.7 上的 NFS 性能问题：NFS 上的共享库减慢系统速度

Question

我目前正在寻找一些运行 Oracle Linux 6.6（内核 2.6）和 6.7（内核 3.8）的具有相同内存和 CPU 数量的 VMWare 虚拟机上的一些性能问题。这些机器通过 NFS4 挂载相同的共享，其中包含一些共享库，这些库包含在使用 LD_LIBRARY_PATH 的构建中。两个系统都使用相同的挂载选项（默认），这显然意味着 6.7 的“硬”和 6.6 的“软”。从 6.7 开始，我们观察到编译过程的性能下降了 5 倍，而 CPU 空闲大约 80%，但也没有观察到高 io-wait（顶级报告 ~0.4%wa）。

尝试重现该问题时，我很快发现，只要通过 LD_LIBRARY_PATH 包含来自 NFS 挂载的共享库，在 6.7 上不仅编译而且几乎所有命令（例如“ls”）都慢得多。

我用一个简单的“时间”开始了我的调查：

在 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 的情况下，strace 输出中的“open”调用如下所示：

$ 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.000020 相比高达 0.01）。

所以我开始研究 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 上的长时间打开，但我真的不知道如何使用安装选项等来解决这个问题。

更多实验表明，即使从具有最新操作系统（CentOS 7、Ubuntu 16.04）的 Docker 容器内部安装 NFS，我这样做是为了排除 nfsutils 等问题，6.7 主机上的性能始终显示相同的缓慢性能使用 NFS4 时。NFS3 在 6.7 上的性能与 6.6 一样好。

在这一点上，我预计底层主机上的内核（模块）或 vmware-tools 会导致问题，但我缺少如何进一步挖掘的想法。

这是一个已知问题吗？ 我错过了一些可能的罪魁祸首吗？ 你将如何进一步挖掘？ 有没有办法分析 NFS 客户端？ 如何排除 vmware 驱动程序有问题？

当然：有没有人给我一个简单的解决方案？

编辑：今天早上我确实在一个有点不同的方向进行了挖掘：使用 tcpdump 我检查了 NFS 流量（再次），看起来 6.7 上没有缓存。每次访问（不存在的）共享库总是会导致实际的 NFS 流量，因为 LD_LIBRARY_PATH 不包含大多数库通常会返回 reply ok 52 getattr ERROR: No such file or directory. 在 6.6 上，只有第一个会导致实际流量。了解到这一点后，我能够通过将 NFS 路径从 LD_LIBRARY_PATH 移动到带有编译过程所需库的额外 ld.so.conf 文件中来解决“ls”等标准命令的潜在性能问题。但是，这仍然只是一种解决方法，现在的问题似乎是 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 开始，它实际上包含 6.7 上的 3 个文件，但它似乎没有缓存非-存在共享库路径，所以性能没有改变。对于不存在的文件，我希望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

有谁知道这些标志（即大写、bm0、bm1、...）是什么意思？

消毒 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在 6.6 上设置为 600 和在 6.7 上设置为 0的差异，但更改它也没有达到预期的效果。

不过，我确实找到了另一个有用的命令：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）。

干杯!

Answer 1

您在 CentOS 6.6 安装上使用fs-cache或 吗？nscd您可以发布ps ax两台机器的 a 以及 的输出吗/proc/mounts/？