mount -t nfs -o vers=4.2,timeo=600,retrans=3,proto=tcp,lock,soft localhost:/s_test /mnt
mount -t nfs -o vers=4.2,timeo=600,retrans=3,proto=tcp,lock,hard localhost:/s_test /mnt
从代码层面分析上面的挂载参数 hard 和soft的打印信息,以及定时器重传的规律,例如每次重传的时间,timeo的时间设置等等。
mount | grep nfs #查看mount 挂载参数
dmesg | less #查看日志信息
执行bpftrace查看这个函数的调用栈:
sudo bpftrace -e 'kprobe:xprt_set_retrans_timeout_rtt { printf("Caller: %s\n", kstack); }'
发现执行的时候,好像并没有执行xprt_set_retrans_timeout_rtt这个函数?
查看call_timeout调用栈:
Caller:
call_timeout+1
rpc_async_schedule+18
process_one_work+418
worker_thread+83
kthread+262
ret_from_fork+31
查看xprt_adjust_timeout调用栈:
Caller:
xprt_adjust_timeout+1
__rpc_execute+124
rpc_async_schedule+18
process_one_work+418
worker_thread+83
kthread+262
ret_from_fork+31
分析代码以内核4.19为例:
nfs_init_timeout_values
switch (proto)
case XPRT_TRANSPORT_TCP://TCP用线性增长
to->to_increment = timeo * HZ / 10; // 默认使用初始值作为增量
to->to_exponential = 0; // 禁用指数退避
case: XPRT_TRANSPORT_UDP // UDP 协议使用指数退避
to->to_exponential = 1;; // 使用用指数退避
rpc_async_schedule
__rpc_execute
xprt_adjust_timeout
if (to->to_exponential) //判断是否设置为指数增长
req->rq_timeout <<= 1; // 指数退避:超时时间翻倍
else
req->rq_timeout += to->to_increment; // 线性增长:增加固定增量
__rpc_add_timer
//打印: "RPC: %5u setting alarm for %u ms"
rpc_set_queue_timer(queue, task->u.tk_wait.expires); //添加定时器到队列里面
list_add(&task->u.tk_wait.timer_list, &queue->timer_list.list);//添加任务到任务链表
call_timeout
if (RPC_IS_SOFT(task)) //判断是否为参数是否为soft
//打印: "not responding, still trying或not responding, timed out"也就是说在这段代码中,首先根据挂载参数判断是否是-tcp,
如果是tcp 则to->to_increment = timeo * HZ / 10; // 默认使用初始值作为increment增量
to->to_exponential = 0; // 禁用指数退避
也就是这这个增量值就使用默认初始timeo作为增量,比如你timeo =600, 那么每次增加的增量也是600, 然后不使用指数增长,即设置to->to_exponential = 0;
通过if (to->to_exponential) 判断是采用线性增长还是指数增长。
是线性增长:req->rq_timeout += to->to_increment;
客户端发起写操作 echo something > /mnt/file 会触发nfs4_open
由于修改了内核代码,当收到 OPEN 请求时,服务器进入无限循环,已实现超时重传的效果
--- a/fs/nfsd/nfs4proc.c
+++ b/fs/nfsd/nfs4proc.c
@@ -46,6 +46,7 @@
#include "acl.h"
#include "pnfs.h"
#include "trace.h"
+#include <linux/delay.h>
#ifdef CONFIG_NFSD_V4_SECURITY_LABEL
#include <linux/security.h>
@@ -356,6 +356,11 @@ nfsd4_open(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
struct nfsd_net *nn = net_generic(net, nfsd_net_id);
bool reclaim = false;
+ while (1) {
+ printk("%s:%d, sleep\n", __func__, __LINE__);
+ msleep(20 * 1000);
+ }
+
dprintk("NFSD: nfsd4_open filename %.*s op_openowner %p\n",
(int)open->op_fname.len, open->op_fname.data,
open->op_openowner);结果:服务器永远不回复 OPEN 响应,客户端阻塞在 OPEN 阶段
挂载 并且打开调试开关
mount -t nfs -o vers=4.2,timeo=600,retrans=3,proto=tcp,lock,hard localhost:/s_test /mnt
echo 0xFFFF > /proc/sys/sunrpc/nfs_debug # NFSDBG_ALL
echo 0x7fff > /proc/sys/sunrpc/rpc_debug # RPCDBG_ALL
echo somthing > /mnt/file & #nfs写入mount -t nfs -o vers=3,timeo=600,retrans=3,proto=tcp,lock,hard localhost:/tmp/s_test /mnt
通过 dmesg | less 查看日志:
[ 204.970305] RPC: 50 setting alarm for 60000 ms
[ 267.374370] RPC: 50 setting alarm for 120000 ms
[ 390.277365] RPC: 50 setting alarm for 180000 ms
[ 570.475071] nfs: server localhost not responding, still trying可以看到打印的时间,每次重传的时间可以刚好对应上。
然后根据挂载参数timeo=600,retrans=3 来分析一下setting alarm for xxxx ms
基础超时时间为60000ms,第一次重传时间为60000 + 60000ms,第二次重传时间为 120000 + 60000 ms,
第三次重传未出现?可能是当时没捕捉到,再去验证一下。