Kerberized NFS4 開啟檔案需要 5 秒

Kerberized NFS4 開啟檔案需要 5 秒

我設定了一個 NFSv4 伺服器和一個客戶端,它們都在 Linux 5.10.0-13 上運行 Debian 11.3。它基本上可以工作,即我看到所有具有正確權限的文件,並且可以打開、修改等。

伺服器匯出如下目錄/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 相關的系統呼叫在微秒內執行。這是我在執行 eg 時一貫看到的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 更改為本地從屬後,問題消失了。

同時,我推出了新伺服器,它運行沒有問題。

相關內容