Я установил сервер NFSv4 и клиент под управлением Debian 11.3 в Linux 5.10.0-13. В основном это работает, т. Е. Я вижу все файлы с правильными разрешениями и могу открывать, изменять и т. Д. Однако открытие файла вызывает 5-секундную задержку.
Сервер экспортирует такие каталоги в /etc/экспорт:
/путь/к gss/krb5(rw,sync,fsid=0,crossmnt,no_subtree_check)
/path/to/NFS gss/krb5(rw,sync,no_subtree_check)
Экспорт NFS4 монтируется с использованием этого типа /etc/fstab вход:
сервер:/NFS/путь/к/nfs nfs4 по умолчанию,авто,sec=krb5,proto=tcp,port=2049,nolock 0 3
Следующие данные относятся к открытию файла в емакс и закрыть емакс как только появится.
Анализ стрейс Я вижу, что соответствующий открыть() системный вызов занимает вполне стабильно 5,1 секунды! Другой openat(), stat(), ... системные вызовы, относящиеся к NFS, выполняются в течение микросекунд. Это то, что я постоянно вижу, когда делаю, например. лс, который ничем не отличается от локальной файловой системы. Это выдержка из системных вызовов, относящихся к рассматриваемому файлу, с добавлением времени, затраченного на системный вызов:
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 (Аргумент не указан)
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 (Аргумент не указан)
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 запись(14, "/путь/к/nfs/файлу"..., 90) = 90
В wirehark вижу следующее:
№ Время Источник Назначение Длина протокола Информация
7 0.623097 client.ip server.ip Вызов NFS 276 V4 (ответ в 8) GETATTR FH: 0xecf8d891
8 0.624231 server.ip client.ip Ответ NFS 376 V4 (вызов 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 (ответ в 11) OPEN DH: 0xecf8d891/
11 0.625669 server.ip client.ip Ответ NFS 452 V4 (вызов 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 (ответ в 14) CLOSE StateID: 0xb42f
14 5.743331 server.ip client.ip Ответ NFS 232 V4 (вызов 13) ПОСЛЕДОВАТЕЛЬНОСТЬ | Статус PUTFH: 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 это указывает на то, что объект файловой системы был удален. Ну и файл в задержке открыть() точно не удаляется. Итак, я не уверен, к чему это относится. Однако он также показывает задержку в 5,1 секунды между 12 и 13.
Должен признаться, что я не совсем понимаю, что я здесь вижу. Однако я наблюдаю такие же задержки и с другими программами, т.е. это не причуда емакс. Сохранение в либреофис может даже зависнуть, пока к файлу не обратится другая программа.
Поскольку я где-то видел, что есть проблемы с крб5п в некоторых средах я уменьшил до крб5, но это ничего не изменило.
И клиент, и сервер работают gssproxy. На клиенте я вижу отладочные записи нфсидмап, а после настройки sysctl sunrpc.rpc_debug = 0xFFFF Я вижу следующее для емакс сценарий:
[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 мс.
Любые идеи, что происходит, или, по крайней мере, как еще больше определить проблему?
