我在 Linux 5.10.0-13 上设置了一个 NFSv4 服务器和一个客户端,它们都运行 Debian 11.3。它基本上可以正常工作,即,我可以看到具有正确权限的所有文件,并且可以打开、修改等。但是,打开文件会导致 5 秒的延迟。
服务器导出如下目录/etc/exports
:
/path/to gss/krb5(rw,sync,fsid=0,crossmnt,no_subtree_check)
/path/to/NFS gss/krb5(rw,sync,no_subtree_check)
NFS4 导出使用以下类型的条目进行/etc/fstab
挂载:
server:/NFS /path/to/nfs nfs4 defaults,auto,sec=krb5,proto=tcp,port=2049,nolock 0 3
以下数据是指打开一个文件并在显示后立即emacs
关闭。emacs
分析后strace
我发现相应的openat()
系统调用花费了相当稳定的 5.1 秒!其他openat(), stat(), ...
与 NFS 相关的系统调用在几微秒内执行。这是我在执行例如时始终看到的ls
,感觉与本地文件系统没有什么不同。这是与所讨论文件相关的系统调用的摘录,前面是系统调用所花费的时间:
0.000014 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = -1 ENOTDIR (Ist kein Verzeichnis)
0.000005 readlinkat(AT_FDCWD, "/path/to/nfs/file", 0x7fff202f6880, 1024) = -1 EINVAL (Das Argument ist ungültig)
0.000006 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 14
0.000005 readlinkat(AT_FDCWD, "/path/to/nfs/file", 0x7fff202f64d0, 1024) = -1 EINVAL (Das Argument ist ungültig)
0.000005 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 14
5.108682 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_CLOEXEC) = 14
0.000006 faccessat(AT_FDCWD, "/path/to/nfs/file", W_OK) = 0
0.000005 stat("/path/to/nfs/file", {st_mode=S_IFREG|0640, st_size=2192, ...}) = 0
0.000007 faccessat(AT_FDCWD, "/path/to/nfs/file,v", F_OK) = -1 ENOENT (Datei oder Verzeichnis nicht gefunden)
0.000009 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = -1 ENOTDIR (Ist kein Verzeichnis)
0.000008 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = -1 ENOTDIR (Ist kein Verzeichnis)
0.000008 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = -1 ENOTDIR (Ist kein Verzeichnis)
0.000008 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = -1 ENOTDIR (Ist kein Verzeichnis)
0.000008 openat(AT_FDCWD, "/path/to/nfs/file", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = -1 ENOTDIR (Ist kein Verzeichnis)
0.000012 stat("/path/to/nfs/file", {st_mode=S_IFREG|0640, st_size=2192, ...}) = 0
0.000015 write(14, "/path/to/nfs/file"..., 90) = 90
在 wireshark 中我看到以下内容:
No. Time Source Destination Protocol Length Info
7 0.623097 client.ip server.ip NFS 276 V4 Call (Reply In 8) GETATTR FH: 0xecf8d891
8 0.624231 server.ip client.ip NFS 376 V4 Reply (Call In 7) GETATTR
9 0.624239 client.ip server.ip TCP 72 951 → 2049 [ACK] Seq=601 Ack=917 Win=4176 Len=0 TSval=1071244404 TSecr=3950562910
10 0.624696 client.ip server.ip NFS 344 V4 Call (Reply In 11) OPEN DH: 0xecf8d891/
11 0.625669 server.ip client.ip NFS 452 V4 Reply (Call In 10) OPEN StateID: 0xb42f
12 0.625693 client.ip server.ip TCP 72 951 → 2049 [ACK] Seq=873 Ack=1297 Win=4176 Len=0 TSval=1071244405 TSecr=3950562911
13 5.742166 client.ip server.ip NFS 340 V4 Call (Reply In 14) CLOSE StateID: 0xb42f
14 5.743331 server.ip client.ip NFS 232 V4 Reply (Call In 13) SEQUENCE | PUTFH Status: NFS4ERR_STALE
15 5.743359 client.ip server.ip TCP 72 951 → 2049 [ACK] Seq=1141 Ack=1457 Win=4176 Len=0 TSval=1071249523 TSecr=3950568029
我不知道这种NFS4ERR_STALE
情况是否暗示了这个问题。根据 RFC7530,它表示文件系统对象已被删除。好吧,延迟中的文件openat()
肯定没有被删除。所以,我不确定它指的是什么。然而,它还显示了 12 和 13 之间的 5.1 秒延迟。
我必须承认,我不太明白我在这里看到的内容。但是,我也看到其他程序也存在同样的延迟,也就是说,这不是 的怪癖emacs
。保存libreoffice
甚至会冻结,直到另一个程序访问该文件。
由于我看到某些环境中存在问题krb5p
,因此我将其减少到krb5
,但这并没有改变任何东西。
客户端和服务器都运行gssproxy
。在客户端上,我看到了的调试条目nfsidmap
,设置后sysctl sunrpc.rpc_debug=0xFFFF
,我看到了以下场景emacs
:
[423544.865600] RPC: gss_get_mic_v2
[423544.865628] RPC: xs_tcp_send_request(200) = 0
[423544.867049] RPC: xs_data_ready...
[423544.867309] RPC: gss_verify_mic_v2
[423545.373665] RPC: gss_get_mic_v2
[423545.373691] RPC: xs_tcp_send_request(200) = 0
[423545.374692] RPC: xs_data_ready...
[423545.374748] RPC: gss_verify_mic_v2
[423545.375009] RPC: gss_get_mic_v2
[423545.375025] RPC: xs_tcp_send_request(268) = 0
[423545.375909] RPC: xs_data_ready...
[423545.375957] RPC: gss_verify_mic_v2
[423550.467227] RPC: gss_get_mic_v2
[423550.467307] RPC: xs_tcp_send_request(216) = 0
[423550.468395] RPC: xs_data_ready...
[423550.468513] RPC: gss_verify_mic_v2
[423550.468621] RPC: gss_get_mic_v2
[423550.468646] RPC: gss_get_mic_v2
[423550.468689] RPC: xs_tcp_send_request(264) = 0
[423550.469403] RPC: xs_data_ready...
[423550.469541] RPC: gss_verify_mic_v2
[423550.469564] RPC: gss_verify_mic_v2
[423550.472794] RPC: gss_get_mic_v2
[423550.472849] RPC: xs_tcp_send_request(208) = 0
[423550.473758] RPC: xs_data_ready...
[423550.473903] RPC: gss_verify_mic_v2
[423550.474234] RPC: gss_get_mic_v2
[423550.474290] RPC: xs_tcp_send_request(200) = 0
[423550.475147] RPC: xs_data_ready...
[423550.475257] RPC: gss_verify_mic_v2
我不知道如何准确解释这个日志,但它也清楚地显示了 5 秒的延迟,在我看来,所有 RPC 调用都在 100 毫秒内处理。
知道发生了什么事吗?或者至少如何进一步查明问题?
答案1
我已经解决了这个问题,因为我的第二个站点的 VPN 不久前坏了。NFS 服务器使用的 Kerberos 从属服务器的 DNS 服务器指向另一个站点,即通过慢速 VPN。仍然令人困惑,因为 VPN 并没有那么慢,而且我没有看到 5 秒的延迟,例如在登录期间,但在将 DNS 更改为本地从属服务器后,问题就消失了。
同时,我推出了新的服务器,并且运行没有问题。