On Tue, 2018-11-20 at 13:07 -0500, Chuck Lever wrote:
> > On Nov 20, 2018, at 1:02 PM, Anna Schumaker <schumaker.anna@xxxxxxxxx>
> > wrote:
> >
> > Hi Chuck,
> >
> > On Mon, 2018-11-19 at 10:46 -0500, Chuck Lever wrote:
> > > Place the associated RPC transaction's XID in the upper 32 bits of
> > > each RDMA segment's rdma_offset field. These bits are currently
> > > always zero.
> > >
> > > There are two reasons to do this:
> > >
> > > - The R_key only has 8 bits that are different from registration to
> > > registration. The XID adds more uniqueness to each RDMA segment to
> > > reduce the likelihood of a software bug on the server reading from
> > > or writing into memory it's not supposed to.
> > >
> > > - On-the-wire RDMA Read and Write operations do not otherwise carry
> > > any identifier that matches them up to an RPC. The XID in the
> > > upper 32 bits will act as an eye-catcher in network captures.
> > >
> > > Suggested-by: Tom Talpey <ttalpey@xxxxxxxxxxxxx>
> > > Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
> > > ---
> > > net/sunrpc/xprtrdma/frwr_ops.c | 3 ++-
> > > net/sunrpc/xprtrdma/rpc_rdma.c | 6 +++---
> > > net/sunrpc/xprtrdma/xprt_rdma.h | 2 +-
> > > 3 files changed, 6 insertions(+), 5 deletions(-)
> > >
> > > diff --git a/net/sunrpc/xprtrdma/frwr_ops.c
> > > b/net/sunrpc/xprtrdma/frwr_ops.c
> > > index 49b314d..3b260d2 100644
> > > --- a/net/sunrpc/xprtrdma/frwr_ops.c
> > > +++ b/net/sunrpc/xprtrdma/frwr_ops.c
> > > @@ -344,7 +344,7 @@
> > > */
> > > static struct rpcrdma_mr_seg *
> > > frwr_op_map(struct rpcrdma_xprt *r_xprt, struct rpcrdma_mr_seg *seg,
> > > - int nsegs, bool writing, struct rpcrdma_mr **out)
> > > + int nsegs, bool writing, u32 xid, struct rpcrdma_mr **out)
> > > {
> > > struct rpcrdma_ia *ia = &r_xprt->rx_ia;
> > > bool holes_ok = ia->ri_mrtype == IB_MR_TYPE_SG_GAPS;
> > > @@ -398,6 +398,7 @@
> > > if (unlikely(n != mr->mr_nents))
> > > goto out_mapmr_err;
> > >
> > > + ibmr->iova |= ((u64)cpu_to_be32(xid)) << 32;
> >
> > My mount command hangs once we make this change (I got bored and killed it
> > after
> > about 5 minutes). This is with NFS over soft-RoCE in a kvm virtual machine,
> > and
> > I see the behavior with all NFS versions.
> >
> > I hope this helps!
>
> OK. Can you capture ftrace output to show us where the hang occurs?
> I use this on the NFS client:
>
> # trace-cmd record -e sunrpc -e rpcrdma
> ^C
> # trace-cmd report | less (or > /tmp/trace.log)
The trace is attached! I started the mount and walked away for a while. When I
came back, it reported "mount.nfs: Connection timed out".
I hope this helps!
Anna
>
> Thanks!
>
>
> > Anna
> >
> > > key = (u8)(ibmr->rkey & 0x000000FF);
> > > ib_update_fast_reg_key(ibmr, ++key);
> > >
> > > diff --git a/net/sunrpc/xprtrdma/rpc_rdma.c
> > > b/net/sunrpc/xprtrdma/rpc_rdma.c
> > > index 9f53e02..89a2db2 100644
> > > --- a/net/sunrpc/xprtrdma/rpc_rdma.c
> > > +++ b/net/sunrpc/xprtrdma/rpc_rdma.c
> > > @@ -357,7 +357,7 @@ static bool rpcrdma_results_inline(struct rpcrdma_xprt
> > > *r_xprt,
> > >
> > > do {
> > > seg = r_xprt->rx_ia.ri_ops->ro_map(r_xprt, seg, nsegs,
> > > - false, &mr);
> > > + false, rqst->rq_xid, &mr);
> > > if (IS_ERR(seg))
> > > return PTR_ERR(seg);
> > > rpcrdma_mr_push(mr, &req->rl_registered);
> > > @@ -415,7 +415,7 @@ static bool rpcrdma_results_inline(struct rpcrdma_xprt
> > > *r_xprt,
> > > nchunks = 0;
> > > do {
> > > seg = r_xprt->rx_ia.ri_ops->ro_map(r_xprt, seg, nsegs,
> > > - true, &mr);
> > > + true, rqst->rq_xid, &mr);
> > > if (IS_ERR(seg))
> > > return PTR_ERR(seg);
> > > rpcrdma_mr_push(mr, &req->rl_registered);
> > > @@ -473,7 +473,7 @@ static bool rpcrdma_results_inline(struct rpcrdma_xprt
> > > *r_xprt,
> > > nchunks = 0;
> > > do {
> > > seg = r_xprt->rx_ia.ri_ops->ro_map(r_xprt, seg, nsegs,
> > > - true, &mr);
> > > + true, rqst->rq_xid, &mr);
> > > if (IS_ERR(seg))
> > > return PTR_ERR(seg);
> > > rpcrdma_mr_push(mr, &req->rl_registered);
> > > diff --git a/net/sunrpc/xprtrdma/xprt_rdma.h
> > > b/net/sunrpc/xprtrdma/xprt_rdma.h
> > > index a13ccb6..2ae1ee2 100644
> > > --- a/net/sunrpc/xprtrdma/xprt_rdma.h
> > > +++ b/net/sunrpc/xprtrdma/xprt_rdma.h
> > > @@ -472,7 +472,7 @@ struct rpcrdma_memreg_ops {
> > > struct rpcrdma_mr_seg *
> > > (*ro_map)(struct rpcrdma_xprt *,
> > > struct rpcrdma_mr_seg *, int, bool,
> > > - struct rpcrdma_mr **);
> > > + u32, struct rpcrdma_mr **);
> > > int (*ro_send)(struct rpcrdma_ia *ia,
> > > struct rpcrdma_req *req);
> > > void (*ro_reminv)(struct rpcrdma_rep *rep,
>
> --
> Chuck Lever
>
>
>
cpus=2
mount.nfs-1325 [001] 450.672000: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936439832000
kworker/u4:3-1199 [000] 450.672048: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936439832000: ADDR_RESOLVED (0/0)
kworker/u4:3-1199 [000] 450.672155: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936439832000: ROUTE_RESOLVED (2/0)
mount.nfs-1325 [001] 450.672228: xprtrdma_createmrs: r_xprt=0xffff936439832000: created 11 MRs
mount.nfs-1325 [001] 450.672310: xprtrdma_create: peer=[192.168.100.215]:20049 r_xprt=0xffff936439832000
kworker/1:0-638 [001] 450.672392: xprtrdma_destroy: peer=[192.168.100.215]:20049 r_xprt=0xffff936439832000
mount.nfs-1325 [001] 450.672431: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/u4:3-1199 [000] 450.672443: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ADDR_RESOLVED (0/0)
kworker/u4:3-1199 [000] 450.672453: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ROUTE_RESOLVED (2/0)
mount.nfs-1325 [001] 450.672485: xprtrdma_createmrs: r_xprt=0xffff936438713000: created 11 MRs
mount.nfs-1325 [001] 450.672553: xprtrdma_create: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
mount.nfs-1325 [001] 450.672587: rpc_task_begin: task:16529@10 flags=0680 state=0004 status=0 action=(nil)f
mount.nfs-1325 [001] 450.672588: rpc_task_run_action: task:16529@10 flags=0680 state=0005 status=0 action=call_start
mount.nfs-1325 [001] 450.672589: rpc_request: task:16529@10 nfsv4 NULL (sync)
mount.nfs-1325 [001] 450.672589: rpc_task_run_action: task:16529@10 flags=0680 state=0005 status=0 action=call_reserve
mount.nfs-1325 [001] 450.672590: rpc_task_run_action: task:16529@10 flags=0680 state=0005 status=0 action=call_reserveresult
mount.nfs-1325 [001] 450.672590: rpc_task_run_action: task:16529@10 flags=0680 state=0005 status=0 action=call_refresh
mount.nfs-1325 [001] 450.672591: rpc_task_run_action: task:16529@10 flags=0680 state=0005 status=0 action=call_refreshresult
mount.nfs-1325 [001] 450.672591: rpc_task_run_action: task:16529@10 flags=0680 state=0005 status=0 action=call_allocate
mount.nfs-1325 [001] 450.672592: xprtrdma_allocate: task:16529@10 req=0xffff936438a80000 (56, 32)
mount.nfs-1325 [001] 450.672592: rpc_task_run_action: task:16529@10 flags=0680 state=0005 status=0 action=call_encode
mount.nfs-1325 [001] 450.672594: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 450.672594: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 450.672595: rpc_task_sleep: task:16529@10 flags=0680 state=001d status=0 timeout=18000 queue=xprt_pending
kworker/1:0-638 [001] 450.672767: xprtrdma_post_recv: cqe=0xffff936438a8e200
kworker/1:0-638 [001] 450.672768: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 1 new recvs, 1 active (rc 0)
kworker/1:1-38 [001] 450.673400: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ESTABLISHED (9/0)
kworker/1:0-638 [001] 450.673421: rpc_task_wakeup: task:16529@10 flags=0680 state=001f status=-11 timeout=18000 queue=xprt_pending
mount.nfs-1325 [001] 450.673425: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=-11 action=xprt_connect_status
mount.nfs-1325 [001] 450.673426: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 450.673427: rpc_connect_status: task:16529@10 status=-11
mount.nfs-1325 [001] 450.673438: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 450.673438: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 450.673438: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 450.673439: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 450.673439: rpc_task_run_action: task:16529@10 flags=0680 state=001d status=0 action=call_transmit
mount.nfs-1325 [001] 450.673441: xprtrdma_marshal: task:16529@10 xid=0x08c9d05d: hdr=28 xdr=40/0/0 inline/inline
mount.nfs-1325 [001] 450.673444: xprtrdma_post_send: req=0xffff936438a80000, 2 SGEs, status=0
mount.nfs-1325 [001] 450.673466: xprt_transmit: peer=[192.168.100.215]:20049 xid=0x08c9d05d status=0
mount.nfs-1325 [001] 450.673467: rpc_task_run_action: task:16529@10 flags=0e80 state=0015 status=0 action=call_transmit_status
mount.nfs-1325 [001] 450.673468: rpc_task_sleep: task:16529@10 flags=0e80 state=0015 status=0 timeout=36000 queue=xprt_pending
kworker/1:1H-177 [001] 450.673788: xprtrdma_wc_receive: cqe=0xffff936438a8e200 52 bytes: SUCCESS (0/0x0)
kworker/1:1H-177 [001] 450.673790: xprt_lookup_rqst: peer=[192.168.100.215]:20049 xid=0x08c9d05d status=0
kworker/1:1H-177 [001] 450.673791: xprtrdma_reply: task:16529@10 xid=0x08c9d05d, 64 credits, rep=0xffff936438a8e200 -> req=0xffff936438a80000
kworker/1:1H-177 [001] 450.673792: xprtrdma_post_recv: cqe=0xffff936438a8fa00
kworker/1:1H-177 [001] 450.673792: xprtrdma_post_recv: cqe=0xffff936438a8f000
kworker/1:1H-177 [001] 450.673793: xprtrdma_post_recv: cqe=0xffff936438a8f400
kworker/1:1H-177 [001] 450.673794: xprtrdma_post_recv: cqe=0xffff936438a8e800
kworker/1:1H-177 [001] 450.673794: xprtrdma_post_recv: cqe=0xffff936438a8e400
kworker/1:1H-177 [001] 450.673795: xprtrdma_post_recv: cqe=0xffff9364396ba800
kworker/1:1H-177 [001] 450.673796: xprtrdma_post_recv: cqe=0xffff936438d61600
kworker/1:1H-177 [001] 450.673797: xprtrdma_post_recv: cqe=0xffff936438d60000
kworker/1:1H-177 [001] 450.673797: xprtrdma_post_recv: cqe=0xffff936438d61a00
kworker/1:1H-177 [001] 450.673797: xprtrdma_post_recv: cqe=0xffff936438d60c00
kworker/1:1H-177 [001] 450.673797: xprtrdma_post_recv: cqe=0xffff936438d61000
kworker/1:1H-177 [001] 450.673798: xprtrdma_post_recv: cqe=0xffff936438d61400
kworker/1:1H-177 [001] 450.673798: xprtrdma_post_recv: cqe=0xffff936438d60800
kworker/1:1H-177 [001] 450.673799: xprtrdma_post_recv: cqe=0xffff936438d60400
kworker/1:1H-177 [001] 450.673799: xprtrdma_post_recv: cqe=0xffff936438d60600
kworker/1:1H-177 [001] 450.673800: xprtrdma_post_recv: cqe=0xffff936438d61800
kworker/1:1H-177 [001] 450.673800: xprtrdma_post_recv: cqe=0xffff936438d60e00
kworker/1:1H-177 [001] 450.673800: xprtrdma_post_recv: cqe=0xffff936438d61e00
kworker/1:1H-177 [001] 450.673801: xprtrdma_post_recv: cqe=0xffff936438d60a00
kworker/1:1H-177 [001] 450.673801: xprtrdma_post_recv: cqe=0xffff936438d61200
kworker/1:1H-177 [001] 450.673802: xprtrdma_post_recv: cqe=0xffff936438d60200
kworker/1:1H-177 [001] 450.673802: xprtrdma_post_recv: cqe=0xffff936438d61c00
kworker/1:1H-177 [001] 450.673813: xprtrdma_post_recv: cqe=0xffff936438d62e00
kworker/1:1H-177 [001] 450.673814: xprtrdma_post_recv: cqe=0xffff936438d63e00
kworker/1:1H-177 [001] 450.673814: xprtrdma_post_recv: cqe=0xffff936438d62a00
kworker/1:1H-177 [001] 450.673814: xprtrdma_post_recv: cqe=0xffff936438d63200
kworker/1:1H-177 [001] 450.673815: xprtrdma_post_recv: cqe=0xffff936438d62200
kworker/1:1H-177 [001] 450.673815: xprtrdma_post_recv: cqe=0xffff936438d63c00
kworker/1:1H-177 [001] 450.673816: xprtrdma_post_recv: cqe=0xffff936438d63600
kworker/1:1H-177 [001] 450.673816: xprtrdma_post_recv: cqe=0xffff936438d62000
kworker/1:1H-177 [001] 450.673816: xprtrdma_post_recv: cqe=0xffff936438d63a00
kworker/1:1H-177 [001] 450.673817: xprtrdma_post_recv: cqe=0xffff936438d62c00
kworker/1:1H-177 [001] 450.673817: xprtrdma_post_recv: cqe=0xffff936438d63000
kworker/1:1H-177 [001] 450.673817: xprtrdma_post_recv: cqe=0xffff936438d63400
kworker/1:1H-177 [001] 450.673818: xprtrdma_post_recv: cqe=0xffff936438d62800
kworker/1:1H-177 [001] 450.673818: xprtrdma_post_recv: cqe=0xffff936438d62400
kworker/1:1H-177 [001] 450.673819: xprtrdma_post_recv: cqe=0xffff936438d62600
kworker/1:1H-177 [001] 450.673819: xprtrdma_post_recv: cqe=0xffff936438d63800
kworker/1:1H-177 [001] 450.673820: xprtrdma_post_recv: cqe=0xffff936438d64600
kworker/1:1H-177 [001] 450.673821: xprtrdma_post_recv: cqe=0xffff936438d65800
kworker/1:1H-177 [001] 450.673821: xprtrdma_post_recv: cqe=0xffff936438d64e00
kworker/1:1H-177 [001] 450.673821: xprtrdma_post_recv: cqe=0xffff936438d65e00
kworker/1:1H-177 [001] 450.673821: xprtrdma_post_recv: cqe=0xffff936438d64a00
kworker/1:1H-177 [001] 450.673822: xprtrdma_post_recv: cqe=0xffff936438d65200
kworker/1:1H-177 [001] 450.673822: xprtrdma_post_recv: cqe=0xffff936438d64200
kworker/1:1H-177 [001] 450.673823: xprtrdma_post_recv: cqe=0xffff936438d65c00
kworker/1:1H-177 [001] 450.673823: xprtrdma_post_recv: cqe=0xffff936438d65600
kworker/1:1H-177 [001] 450.673824: xprtrdma_post_recv: cqe=0xffff936438d64000
kworker/1:1H-177 [001] 450.673824: xprtrdma_post_recv: cqe=0xffff936438d65a00
kworker/1:1H-177 [001] 450.673824: xprtrdma_post_recv: cqe=0xffff936438d64c00
kworker/1:1H-177 [001] 450.673824: xprtrdma_post_recv: cqe=0xffff936438d65000
kworker/1:1H-177 [001] 450.673825: xprtrdma_post_recv: cqe=0xffff936438d65400
kworker/1:1H-177 [001] 450.673826: xprtrdma_post_recv: cqe=0xffff936438d64800
kworker/1:1H-177 [001] 450.673835: xprtrdma_post_recv: cqe=0xffff936438d64400
kworker/1:1H-177 [001] 450.673836: xprtrdma_post_recv: cqe=0xffff936438d67c00
kworker/1:1H-177 [001] 450.673837: xprtrdma_post_recv: cqe=0xffff936438d67600
kworker/1:1H-177 [001] 450.673837: xprtrdma_post_recv: cqe=0xffff936438d66000
kworker/1:1H-177 [001] 450.673837: xprtrdma_post_recv: cqe=0xffff936438d67a00
kworker/1:1H-177 [001] 450.673838: xprtrdma_post_recv: cqe=0xffff936438d66c00
kworker/1:1H-177 [001] 450.673838: xprtrdma_post_recv: cqe=0xffff936438d67000
kworker/1:1H-177 [001] 450.673839: xprtrdma_post_recv: cqe=0xffff936438d67400
kworker/1:1H-177 [001] 450.673839: xprtrdma_post_recv: cqe=0xffff936438d66800
kworker/1:1H-177 [001] 450.673839: xprtrdma_post_recv: cqe=0xffff936438d66400
kworker/1:1H-177 [001] 450.673840: xprtrdma_post_recv: cqe=0xffff936438d66600
kworker/1:1H-177 [001] 450.673842: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 64 new recvs, 64 active (rc 0)
kworker/1:1H-177 [001] 450.673843: xprtrdma_defer_cmp: task:16529@10 xid=0x08c9d05d rep=0xffff936438a8e200
kworker/1:1H-177 [001] 450.673845: xprtrdma_fixup: task:16529@10 base=0xffff936438a8211c len=24 hdrlen=24
kworker/1:1H-177 [001] 450.673846: xprt_complete_rqst: peer=[192.168.100.215]:20049 xid=0x08c9d05d status=24
kworker/1:1H-177 [001] 450.673846: rpc_task_wakeup: task:16529@10 flags=0e80 state=0006 status=0 timeout=36000 queue=xprt_pending
mount.nfs-1325 [001] 450.673850: rpc_task_run_action: task:16529@10 flags=0e80 state=0005 status=0 action=xprt_timer
mount.nfs-1325 [001] 450.673851: rpc_task_run_action: task:16529@10 flags=0e80 state=0005 status=0 action=call_status
mount.nfs-1325 [001] 450.673852: xprt_ping: peer=[192.168.100.215]:20049 status=0
mount.nfs-1325 [001] 450.673852: rpc_task_run_action: task:16529@10 flags=0e80 state=0005 status=0 action=call_decode
mount.nfs-1325 [001] 450.673853: rpc_task_run_action: task:16529@10 flags=0e80 state=0005 status=0 action=rpc_exit_task
mount.nfs-1325 [001] 450.673864: rpc_stats_latency: task:16529@10 xid=0x08c9d05d nfsv4 NULL backlog=856 rtt=348 execute=1277
mount.nfs-1325 [001] 450.673866: xprtrdma_rpc_done: task:16529@10 req=0xffff936438a80000 rep=0xffff936438a8e200
mount.nfs-1325 [001] 450.674826: xprtrdma_cb_setup: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 1 reqs
mount.nfs-1325 [001] 450.674894: rpc_task_begin: task:16530@10 flags=5280 state=0004 status=0 action=(nil)f
mount.nfs-1325 [001] 450.674895: rpc_task_run_action: task:16530@10 flags=5280 state=0005 status=0 action=call_start
mount.nfs-1325 [001] 450.674895: rpc_request: task:16530@10 nfsv4 EXCHANGE_ID (sync)
mount.nfs-1325 [001] 450.674896: rpc_task_run_action: task:16530@10 flags=5280 state=0005 status=0 action=call_reserve
mount.nfs-1325 [001] 450.674896: rpc_task_run_action: task:16530@10 flags=5280 state=0005 status=0 action=call_reserveresult
mount.nfs-1325 [001] 450.674896: rpc_task_run_action: task:16530@10 flags=5280 state=0005 status=0 action=call_refresh
mount.nfs-1325 [001] 450.674898: rpc_task_run_action: task:16530@10 flags=5280 state=0005 status=0 action=call_refreshresult
mount.nfs-1325 [001] 450.674903: rpc_task_run_action: task:16530@10 flags=5280 state=0005 status=0 action=call_allocate
mount.nfs-1325 [001] 450.674904: xprtrdma_allocate: task:16530@10 req=0xffff936438a80000 (2740, 4380)
mount.nfs-1325 [001] 450.674904: rpc_task_run_action: task:16530@10 flags=5280 state=0005 status=0 action=call_encode
mount.nfs-1325 [001] 450.674906: rpc_task_run_action: task:16530@10 flags=5280 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 450.674906: rpc_task_run_action: task:16530@10 flags=5280 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 450.674907: rpc_task_run_action: task:16530@10 flags=5280 state=001d status=0 action=call_transmit
mount.nfs-1325 [001] 450.674908: xprtrdma_mr_map: mr=0xffff93643876cb00 0@0x0000000000000000:0x00000000
mount.nfs-1325 [001] 450.674910: xprtrdma_reply_chunk: task:16530@10 mr=0xffff93643876cb00 4380@0xffffd37d38bec100:0x00001a61 (last)
mount.nfs-1325 [001] 450.674912: xprtrdma_marshal: task:16530@10 xid=0x09c9d05d: hdr=48 xdr=232/0/0 inline/reply chunk
mount.nfs-1325 [001] 450.674914: xprtrdma_post_send: req=0xffff936438a80000, 2 SGEs, status=0
mount.nfs-1325 [001] 450.674928: xprt_transmit: peer=[192.168.100.215]:20049 xid=0x09c9d05d status=0
mount.nfs-1325 [001] 450.674929: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_transmit_status
mount.nfs-1325 [001] 450.674930: rpc_task_sleep: task:16530@10 flags=5a80 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/1:1H-177 [001] 450.676094: xprtrdma_wc_receive: cqe=0xffff936438d66600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676095: xprtrdma_wc_receive: cqe=0xffff936438d66400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676095: xprtrdma_wc_receive: cqe=0xffff936438d66800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676095: xprtrdma_wc_receive: cqe=0xffff936438d67400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676096: xprtrdma_wc_receive: cqe=0xffff936438d67000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676096: xprtrdma_wc_receive: cqe=0xffff936438d66c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676096: xprtrdma_wc_receive: cqe=0xffff936438d67a00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676096: xprtrdma_wc_receive: cqe=0xffff936438d66000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676096: xprtrdma_wc_receive: cqe=0xffff936438d67600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676097: xprtrdma_wc_receive: cqe=0xffff936438d67c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676097: xprtrdma_wc_receive: cqe=0xffff936438d64400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676097: xprtrdma_wc_receive: cqe=0xffff936438d64800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676097: xprtrdma_wc_receive: cqe=0xffff936438d65400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676097: xprtrdma_wc_receive: cqe=0xffff936438d65000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676097: xprtrdma_wc_receive: cqe=0xffff936438d64c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676098: xprtrdma_wc_receive: cqe=0xffff936438d65a00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676098: xprtrdma_wc_receive: cqe=0xffff936438d64000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676098: xprtrdma_wc_receive: cqe=0xffff936438d65600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676098: xprtrdma_wc_receive: cqe=0xffff936438d65c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676099: xprtrdma_wc_receive: cqe=0xffff936438d64200 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676099: xprtrdma_wc_receive: cqe=0xffff936438d65200 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676099: xprtrdma_wc_receive: cqe=0xffff936438d64a00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676099: xprtrdma_wc_receive: cqe=0xffff936438d65e00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676099: xprtrdma_wc_receive: cqe=0xffff936438d64e00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676099: xprtrdma_wc_receive: cqe=0xffff936438d65800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676100: xprtrdma_wc_receive: cqe=0xffff936438d64600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676100: xprtrdma_wc_receive: cqe=0xffff936438d63800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676100: xprtrdma_wc_receive: cqe=0xffff936438d62600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676100: xprtrdma_wc_receive: cqe=0xffff936438d62400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676101: xprtrdma_wc_receive: cqe=0xffff936438d62800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676101: xprtrdma_wc_receive: cqe=0xffff936438d63400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676101: xprtrdma_wc_receive: cqe=0xffff936438d63000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676101: xprtrdma_wc_receive: cqe=0xffff936438d62c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676101: xprtrdma_wc_receive: cqe=0xffff936438d63a00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676102: xprtrdma_wc_receive: cqe=0xffff936438d62000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676102: xprtrdma_wc_receive: cqe=0xffff936438d63600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676102: xprtrdma_wc_receive: cqe=0xffff936438d63c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676102: xprtrdma_wc_receive: cqe=0xffff936438d62200 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676102: xprtrdma_wc_receive: cqe=0xffff936438d63200 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676103: xprtrdma_wc_receive: cqe=0xffff936438d62a00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676103: xprtrdma_wc_receive: cqe=0xffff936438d63e00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676103: xprtrdma_wc_receive: cqe=0xffff936438d62e00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676103: xprtrdma_wc_receive: cqe=0xffff936438d61c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676103: xprtrdma_wc_receive: cqe=0xffff936438d60200 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676104: xprtrdma_wc_receive: cqe=0xffff936438d61200 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676104: xprtrdma_wc_receive: cqe=0xffff936438d60a00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676104: xprtrdma_wc_receive: cqe=0xffff936438d61e00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676104: xprtrdma_wc_receive: cqe=0xffff936438d60e00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676104: xprtrdma_wc_receive: cqe=0xffff936438d61800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676105: xprtrdma_wc_receive: cqe=0xffff936438d60600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676105: xprtrdma_wc_receive: cqe=0xffff936438d60400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676105: xprtrdma_wc_receive: cqe=0xffff936438d60800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676105: xprtrdma_wc_receive: cqe=0xffff936438d61400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676105: xprtrdma_wc_receive: cqe=0xffff936438d61000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676106: xprtrdma_wc_receive: cqe=0xffff936438d60c00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676106: xprtrdma_wc_receive: cqe=0xffff936438d61a00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676106: xprtrdma_wc_receive: cqe=0xffff936438d60000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676106: xprtrdma_wc_receive: cqe=0xffff936438d61600 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676106: xprtrdma_wc_receive: cqe=0xffff9364396ba800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676107: xprtrdma_wc_receive: cqe=0xffff936438a8e400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676107: xprtrdma_wc_receive: cqe=0xffff936438a8e800 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676107: xprtrdma_wc_receive: cqe=0xffff936438a8f400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676107: xprtrdma_wc_receive: cqe=0xffff936438a8f000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 450.676108: xprtrdma_wc_receive: cqe=0xffff936438a8fa00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:0-638 [001] 453.714146: rpc_task_begin: task:16531@4 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:3-1199 [000] 453.714197: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:3-1199 [000] 453.714199: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=call_start
kworker/u4:3-1199 [000] 453.714201: rpc_request: task:16531@4 nfsv4 SEQUENCE (async)
kworker/u4:3-1199 [000] 453.714201: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:3-1199 [000] 453.714202: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:3-1199 [000] 453.714203: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:3-1199 [000] 453.714205: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:3-1199 [000] 453.714206: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:3-1199 [000] 453.714207: rpc_task_run_action: task:16531@4 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:3-1199 [000] 453.714210: rpc_task_run_action: task:16531@4 flags=5281 state=001d status=0 action=call_bind
kworker/u4:3-1199 [000] 453.714210: rpc_task_run_action: task:16531@4 flags=5281 state=001d status=0 action=call_connect
kworker/u4:3-1199 [000] 453.714210: rpc_task_run_action: task:16531@4 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:3-1199 [000] 453.714237: xprt_transmit: peer=[192.168.100.215]:2049 xid=0xa6601c7c status=0
kworker/u4:3-1199 [000] 453.714238: rpc_task_run_action: task:16531@4 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:3-1199 [000] 453.714240: rpc_task_sleep: task:16531@4 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 453.714606: xprt_lookup_rqst: peer=[192.168.100.215]:2049 xid=0xa6601c7c status=0
kworker/u5:0-277 [001] 453.714610: xprt_complete_rqst: peer=[192.168.100.215]:2049 xid=0xa6601c7c status=80
kworker/u5:0-277 [001] 453.714611: rpc_task_wakeup: task:16531@4 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 453.714618: xs_stream_read_request: peer=[192.168.100.215]:2049 xid=0xa6601c7c copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 453.714619: xs_stream_read_data: peer=[192.168.100.215]:2049 err=-11 total=92
kworker/u4:3-1199 [000] 453.714657: rpc_task_run_action: task:16531@4 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:3-1199 [000] 453.714658: rpc_task_run_action: task:16531@4 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:3-1199 [000] 453.714659: rpc_task_run_action: task:16531@4 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:3-1199 [000] 453.714660: rpc_task_run_action: task:16531@4 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:3-1199 [000] 453.714664: rpc_stats_latency: task:16531@4 xid=0xa6601c7c nfsv4 SEQUENCE backlog=68 rtt=395 execute=520
kworker/1:0-638 [001] 467.054930: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: DISCONNECTED (10/0)
kworker/1:0-638 [001] 467.054939: rpc_task_wakeup: task:16530@10 flags=5a80 state=0016 status=-11 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 467.054968: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
mount.nfs-1325 [001] 467.055071: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=xprt_timer
mount.nfs-1325 [001] 467.055072: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=call_status
mount.nfs-1325 [001] 467.055074: rpc_call_status: task:16530@10 status=-11
mount.nfs-1325 [001] 467.055075: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_encode
mount.nfs-1325 [001] 467.055084: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 467.055085: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 467.055088: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=0 timeout=18000 queue=xprt_pending
kworker/1:0-638 [001] 467.055102: xprtrdma_reconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/1:0-638 [001] 467.055113: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
kworker/1:0-638 [001] 467.055143: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/u4:0-7 [001] 467.055166: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ADDR_RESOLVED (0/0)
kworker/u4:0-7 [001] 467.055177: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ROUTE_RESOLVED (2/0)
kworker/1:0-638 [001] 467.055919: xprtrdma_post_recv: cqe=0xffff936438a8fa00
kworker/1:0-638 [001] 467.055921: xprtrdma_post_recv: cqe=0xffff936438a8f000
kworker/1:0-638 [001] 467.055922: xprtrdma_post_recv: cqe=0xffff936438a8f400
kworker/1:0-638 [001] 467.055925: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 3 new recvs, 3 active (rc 0)
kworker/1:1-38 [001] 467.056885: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ESTABLISHED (9/0)
kworker/1:0-638 [001] 467.056942: rpc_task_wakeup: task:16530@10 flags=5a80 state=001e status=-11 timeout=18000 queue=xprt_pending
mount.nfs-1325 [001] 467.056950: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=xprt_connect_status
mount.nfs-1325 [001] 467.056951: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 467.056953: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 467.056954: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 467.056955: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 467.056955: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 467.056956: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 467.056956: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_transmit
mount.nfs-1325 [001] 467.056964: xprtrdma_mr_map: mr=0xffff93643876cd00 0@0x0000000000000000:0x00000000
mount.nfs-1325 [001] 467.056967: xprtrdma_reply_chunk: task:16530@10 mr=0xffff93643876cd00 4380@0xffffd37d38bec100:0x000019b1 (last)
mount.nfs-1325 [001] 467.056969: xprtrdma_marshal: task:16530@10 xid=0x09c9d05d: hdr=48 xdr=232/0/0 inline/reply chunk
mount.nfs-1325 [001] 467.056974: xprtrdma_post_send: req=0xffff936438a80000, 2 SGEs, status=0
mount.nfs-1325 [001] 467.057004: xprt_transmit: peer=[192.168.100.215]:20049 xid=0x09c9d05d status=0
mount.nfs-1325 [001] 467.057007: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_transmit_status
mount.nfs-1325 [001] 467.057008: rpc_task_sleep: task:16530@10 flags=5a80 state=0015 status=0 timeout=36000 queue=xprt_pending
kworker/1:0-638 [001] 467.057014: xprtrdma_mr_recycle: mr=0xffff93643876cb00 4380@0xffffd37d38bec100:0x00001a61
kworker/1:0-638 [001] 467.057015: xprtrdma_mr_unmap: mr=0xffff93643876cb00 4380@0xffffd37d38bec100:0x00001a61
kworker/1:1H-177 [001] 467.061154: xprtrdma_wc_receive: cqe=0xffff936438a8f400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 467.061156: xprtrdma_wc_receive: cqe=0xffff936438a8f000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 467.061157: xprtrdma_wc_receive: cqe=0xffff936438a8fa00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:0-638 [001] 469.074788: rpc_task_begin: task:16532@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 469.074801: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 469.074804: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 469.074808: rpc_request: task:16532@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 469.074809: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 469.074812: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 469.074813: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 469.074817: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 469.074818: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 469.074820: rpc_task_run_action: task:16532@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 469.074826: rpc_task_run_action: task:16532@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 469.074827: rpc_task_run_action: task:16532@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 469.074828: rpc_task_run_action: task:16532@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 469.074921: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xcda13197 status=0
kworker/u4:0-7 [001] 469.074924: rpc_task_run_action: task:16532@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 469.074927: rpc_task_sleep: task:16532@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 469.075331: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xcda13197 status=0
kworker/u5:0-277 [001] 469.075338: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xcda13197 status=80
kworker/u5:0-277 [001] 469.075341: rpc_task_wakeup: task:16532@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 469.075349: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xcda13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 469.075352: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 469.075358: rpc_task_run_action: task:16532@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 469.075359: rpc_task_run_action: task:16532@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 469.075360: rpc_task_run_action: task:16532@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 469.075364: rpc_task_run_action: task:16532@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 469.075372: rpc_stats_latency: task:16532@3 xid=0xcda13197 nfsv4 SEQUENCE backlog=48 rtt=502 execute=588
kworker/1:0-638 [001] 483.480434: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: DISCONNECTED (10/0)
kworker/1:0-638 [001] 483.480443: rpc_task_wakeup: task:16530@10 flags=5a80 state=0016 status=-11 timeout=36000 queue=xprt_pending
kworker/u5:0-277 [001] 483.480473: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
mount.nfs-1325 [001] 483.480488: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=xprt_timer
mount.nfs-1325 [001] 483.480489: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=call_status
mount.nfs-1325 [001] 483.480491: rpc_call_status: task:16530@10 status=-11
mount.nfs-1325 [001] 483.480492: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_encode
mount.nfs-1325 [001] 483.480503: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 483.480504: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 483.480506: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=-11 timeout=36000 queue=xprt_sending
kworker/u5:0-277 [001] 483.480609: rpc_task_wakeup: task:16530@10 flags=5a80 state=001f status=-11 timeout=36000 queue=xprt_sending
mount.nfs-1325 [001] 483.480613: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 483.480614: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 483.480615: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 483.480616: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 483.480616: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 483.480617: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 483.480618: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 485.715244: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: TIMEWAIT_EXIT (15/0)
kworker/1:0-638 [001] 488.488644: xprtrdma_reconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/1:0-638 [001] 488.488673: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
kworker/1:0-638 [001] 488.488716: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/u4:3-1199 [000] 488.488833: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ADDR_RESOLVED (0/0)
kworker/u4:3-1199 [000] 488.489015: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ROUTE_RESOLVED (2/0)
kworker/1:0-638 [001] 488.489737: xprtrdma_post_recv: cqe=0xffff936438a8fa00
kworker/1:0-638 [001] 488.489739: xprtrdma_post_recv: cqe=0xffff936438a8f000
kworker/1:0-638 [001] 488.489740: xprtrdma_post_recv: cqe=0xffff936438a8f400
kworker/1:0-638 [001] 488.489743: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 3 new recvs, 3 active (rc 0)
kworker/1:1-38 [001] 488.491028: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ESTABLISHED (9/0)
kworker/1:0-638 [001] 488.491101: rpc_task_wakeup: task:16530@10 flags=5a80 state=001e status=-11 timeout=54000 queue=xprt_pending
mount.nfs-1325 [001] 488.491117: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=xprt_connect_status
mount.nfs-1325 [001] 488.491118: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 488.491120: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 488.491121: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 488.491122: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 488.491124: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 488.491169: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 488.491170: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_transmit
mount.nfs-1325 [001] 488.491179: xprtrdma_mr_map: mr=0xffff93643876ca00 0@0x0000000000000000:0x00000000
mount.nfs-1325 [001] 488.491183: xprtrdma_reply_chunk: task:16530@10 mr=0xffff93643876ca00 4380@0xffffd37d38bec100:0x00001859 (last)
mount.nfs-1325 [001] 488.491185: xprtrdma_marshal: task:16530@10 xid=0x09c9d05d: hdr=48 xdr=232/0/0 inline/reply chunk
mount.nfs-1325 [001] 488.491195: xprtrdma_post_send: req=0xffff936438a80000, 2 SGEs, status=0
mount.nfs-1325 [001] 488.491247: xprt_transmit: peer=[192.168.100.215]:20049 xid=0x09c9d05d status=0
mount.nfs-1325 [001] 488.491251: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_transmit_status
mount.nfs-1325 [001] 488.491253: rpc_task_sleep: task:16530@10 flags=5a80 state=0015 status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 488.491270: xprtrdma_mr_recycle: mr=0xffff93643876cd00 4380@0xffffd37d38bec100:0x000019b1
kworker/1:0-638 [001] 488.491272: xprtrdma_mr_unmap: mr=0xffff93643876cd00 4380@0xffffd37d38bec100:0x000019b1
kworker/1:1H-177 [001] 488.495153: xprtrdma_wc_receive: cqe=0xffff936438a8f400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 488.495155: xprtrdma_wc_receive: cqe=0xffff936438a8f000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 488.495156: xprtrdma_wc_receive: cqe=0xffff936438a8fa00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:0-638 [001] 499.795668: rpc_task_begin: task:16533@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 499.795679: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 499.795682: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 499.795684: rpc_request: task:16533@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 499.795685: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 499.795686: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 499.795687: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 499.795690: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 499.795690: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 499.795692: rpc_task_run_action: task:16533@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 499.795696: rpc_task_run_action: task:16533@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 499.795696: rpc_task_run_action: task:16533@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 499.795697: rpc_task_run_action: task:16533@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 499.795755: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xcea13197 status=0
kworker/u4:0-7 [001] 499.795757: rpc_task_run_action: task:16533@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 499.795759: rpc_task_sleep: task:16533@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 499.795973: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xcea13197 status=0
kworker/u5:0-277 [001] 499.795979: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xcea13197 status=80
kworker/u5:0-277 [001] 499.795981: rpc_task_wakeup: task:16533@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 499.795985: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xcea13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 499.795987: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 499.795991: rpc_task_run_action: task:16533@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 499.795992: rpc_task_run_action: task:16533@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 499.795993: rpc_task_run_action: task:16533@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 499.795995: rpc_task_run_action: task:16533@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 499.796000: rpc_stats_latency: task:16533@3 xid=0xcea13197 nfsv4 SEQUENCE backlog=34 rtt=275 execute=334
kworker/1:0-638 [001] 504.813320: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: DISCONNECTED (10/0)
kworker/1:0-638 [001] 504.813326: rpc_task_wakeup: task:16530@10 flags=5a80 state=0016 status=-11 timeout=54000 queue=xprt_pending
kworker/u5:0-277 [001] 504.813351: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
mount.nfs-1325 [001] 504.813362: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=xprt_timer
mount.nfs-1325 [001] 504.813363: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=call_status
mount.nfs-1325 [001] 504.813364: rpc_call_status: task:16530@10 status=-11
mount.nfs-1325 [001] 504.813365: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_encode
mount.nfs-1325 [001] 504.813372: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 504.813373: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 504.813375: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=-11 timeout=54000 queue=xprt_sending
kworker/u5:0-277 [001] 504.813453: rpc_task_wakeup: task:16530@10 flags=5a80 state=001f status=-11 timeout=54000 queue=xprt_sending
mount.nfs-1325 [001] 504.813456: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 504.813458: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 504.813458: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 504.813459: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 504.813459: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 504.813460: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 504.813461: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 507.049181: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: TIMEWAIT_EXIT (15/0)
kworker/1:0-638 [001] 514.942848: xprtrdma_reconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/1:0-638 [001] 514.942881: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
kworker/1:0-638 [001] 514.942931: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/u4:3-1199 [000] 514.943088: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ADDR_RESOLVED (0/0)
kworker/u4:3-1199 [000] 514.943293: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ROUTE_RESOLVED (2/0)
kworker/1:0-638 [001] 514.944169: xprtrdma_post_recv: cqe=0xffff936438a8fa00
kworker/1:0-638 [001] 514.944171: xprtrdma_post_recv: cqe=0xffff936438a8f000
kworker/1:0-638 [001] 514.944172: xprtrdma_post_recv: cqe=0xffff936438a8f400
kworker/1:0-638 [001] 514.944175: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 3 new recvs, 3 active (rc 0)
kworker/1:1-38 [001] 514.945742: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ESTABLISHED (9/0)
kworker/1:0-638 [001] 514.945815: rpc_task_wakeup: task:16530@10 flags=5a80 state=001e status=-11 timeout=54000 queue=xprt_pending
mount.nfs-1325 [001] 514.945834: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=xprt_connect_status
mount.nfs-1325 [001] 514.945835: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 514.945837: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 514.945838: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 514.945839: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 514.945840: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 514.945841: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 514.945842: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_transmit
mount.nfs-1325 [001] 514.945852: xprtrdma_mr_map: mr=0xffff93643876c900 0@0x0000000000000000:0x00000000
mount.nfs-1325 [001] 514.945855: xprtrdma_reply_chunk: task:16530@10 mr=0xffff93643876c900 4380@0xffffd37d38bec100:0x0000172d (last)
mount.nfs-1325 [001] 514.945858: xprtrdma_marshal: task:16530@10 xid=0x09c9d05d: hdr=48 xdr=232/0/0 inline/reply chunk
mount.nfs-1325 [001] 514.945866: xprtrdma_post_send: req=0xffff936438a80000, 2 SGEs, status=0
mount.nfs-1325 [001] 514.945868: xprt_transmit: peer=[192.168.100.215]:20049 xid=0x09c9d05d status=0
mount.nfs-1325 [001] 514.945924: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_transmit_status
mount.nfs-1325 [001] 514.945927: rpc_task_sleep: task:16530@10 flags=5a80 state=0015 status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 514.945942: xprtrdma_mr_recycle: mr=0xffff93643876ca00 4380@0xffffd37d38bec100:0x00001859
kworker/1:0-638 [001] 514.945944: xprtrdma_mr_unmap: mr=0xffff93643876ca00 4380@0xffffd37d38bec100:0x00001859
kworker/1:1H-177 [001] 514.951282: xprtrdma_wc_receive: cqe=0xffff936438a8f400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 514.951325: xprtrdma_wc_receive: cqe=0xffff936438a8f000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 514.951326: xprtrdma_wc_receive: cqe=0xffff936438a8fa00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/0:1-630 [000] 515.156271: rpc_task_begin: task:16534@4 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:3-1199 [000] 515.156286: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:3-1199 [000] 515.156289: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=call_start
kworker/u4:3-1199 [000] 515.156293: rpc_request: task:16534@4 nfsv4 SEQUENCE (async)
kworker/u4:3-1199 [000] 515.156294: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:3-1199 [000] 515.156297: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:3-1199 [000] 515.156298: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:3-1199 [000] 515.156303: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:3-1199 [000] 515.156304: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:3-1199 [000] 515.156306: rpc_task_run_action: task:16534@4 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:3-1199 [000] 515.156313: rpc_task_run_action: task:16534@4 flags=5281 state=001d status=0 action=call_bind
kworker/u4:3-1199 [000] 515.156314: rpc_task_run_action: task:16534@4 flags=5281 state=001d status=0 action=call_connect
kworker/u4:3-1199 [000] 515.156315: rpc_task_run_action: task:16534@4 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:3-1199 [000] 515.156366: xprt_transmit: peer=[192.168.100.215]:2049 xid=0xa7601c7c status=0
kworker/u4:3-1199 [000] 515.156369: rpc_task_run_action: task:16534@4 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:3-1199 [000] 515.156372: rpc_task_sleep: task:16534@4 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 515.156913: xprt_lookup_rqst: peer=[192.168.100.215]:2049 xid=0xa7601c7c status=0
kworker/u5:0-277 [001] 515.156925: xprt_complete_rqst: peer=[192.168.100.215]:2049 xid=0xa7601c7c status=80
kworker/u5:0-277 [001] 515.156929: rpc_task_wakeup: task:16534@4 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 515.156953: xs_stream_read_request: peer=[192.168.100.215]:2049 xid=0xa7601c7c copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 515.156957: xs_stream_read_data: peer=[192.168.100.215]:2049 err=-11 total=92
kworker/u4:3-1199 [000] 515.157067: rpc_task_run_action: task:16534@4 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:3-1199 [000] 515.157070: rpc_task_run_action: task:16534@4 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:3-1199 [000] 515.157071: rpc_task_run_action: task:16534@4 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:3-1199 [000] 515.157076: rpc_task_run_action: task:16534@4 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:3-1199 [000] 515.157085: rpc_stats_latency: task:16534@4 xid=0xa7601c7c nfsv4 SEQUENCE backlog=53 rtt=598 execute=819
kworker/1:0-638 [001] 530.516675: rpc_task_begin: task:16535@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 530.516684: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 530.516686: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 530.516688: rpc_request: task:16535@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 530.516689: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 530.516690: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 530.516691: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 530.516694: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 530.516694: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 530.516695: rpc_task_run_action: task:16535@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 530.516699: rpc_task_run_action: task:16535@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 530.516699: rpc_task_run_action: task:16535@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 530.516700: rpc_task_run_action: task:16535@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 530.516719: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xcfa13197 status=0
kworker/u4:0-7 [001] 530.516720: rpc_task_run_action: task:16535@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 530.516722: rpc_task_sleep: task:16535@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 530.516931: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xcfa13197 status=0
kworker/u5:0-277 [001] 530.516936: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xcfa13197 status=80
kworker/u5:0-277 [001] 530.516937: rpc_task_wakeup: task:16535@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 530.516942: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xcfa13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 530.516944: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 530.516947: rpc_task_run_action: task:16535@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 530.516947: rpc_task_run_action: task:16535@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 530.516948: rpc_task_run_action: task:16535@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 530.516950: rpc_task_run_action: task:16535@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 530.516955: rpc_stats_latency: task:16535@3 xid=0xcfa13197 nfsv4 SEQUENCE backlog=30 rtt=230 execute=282
kworker/1:0-638 [001] 531.267801: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: DISCONNECTED (10/0)
kworker/1:0-638 [001] 531.267809: rpc_task_wakeup: task:16530@10 flags=5a80 state=0016 status=-11 timeout=54000 queue=xprt_pending
kworker/u5:0-277 [001] 531.267839: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
mount.nfs-1325 [001] 531.267852: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=xprt_timer
mount.nfs-1325 [001] 531.267853: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=call_status
mount.nfs-1325 [001] 531.267855: rpc_call_status: task:16530@10 status=-11
mount.nfs-1325 [001] 531.267856: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_encode
mount.nfs-1325 [001] 531.267865: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 531.267866: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 531.267869: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=-11 timeout=54000 queue=xprt_sending
kworker/u5:0-277 [001] 531.268006: rpc_task_wakeup: task:16530@10 flags=5a80 state=001f status=-11 timeout=54000 queue=xprt_sending
mount.nfs-1325 [001] 531.268010: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 531.268012: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 531.268012: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 531.268013: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 531.268014: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 531.268014: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 531.268016: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 533.503373: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: TIMEWAIT_EXIT (15/0)
kworker/1:0-638 [001] 552.704017: xprtrdma_reconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/1:0-638 [001] 552.704039: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
kworker/1:0-638 [001] 552.704071: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/u4:3-1199 [000] 552.704136: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ADDR_RESOLVED (0/0)
kworker/u4:3-1199 [000] 552.704220: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ROUTE_RESOLVED (2/0)
kworker/1:0-638 [001] 552.704697: xprtrdma_post_recv: cqe=0xffff936438a8fa00
kworker/1:0-638 [001] 552.704699: xprtrdma_post_recv: cqe=0xffff936438a8f000
kworker/1:0-638 [001] 552.704699: xprtrdma_post_recv: cqe=0xffff936438a8f400
kworker/1:0-638 [001] 552.704701: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 3 new recvs, 3 active (rc 0)
kworker/1:1-38 [001] 552.705782: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ESTABLISHED (9/0)
kworker/1:0-638 [001] 552.705836: rpc_task_wakeup: task:16530@10 flags=5a80 state=001e status=-11 timeout=54000 queue=xprt_pending
mount.nfs-1325 [001] 552.705847: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=xprt_connect_status
mount.nfs-1325 [001] 552.705848: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 552.705850: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 552.705850: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 552.705852: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 552.705852: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 552.705853: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 552.705853: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_transmit
mount.nfs-1325 [001] 552.705859: xprtrdma_mr_map: mr=0xffff93643876cc00 0@0x0000000000000000:0x00000000
mount.nfs-1325 [001] 552.705861: xprtrdma_reply_chunk: task:16530@10 mr=0xffff93643876cc00 4380@0xffffd37d38bec100:0x00001617 (last)
mount.nfs-1325 [001] 552.705862: xprtrdma_marshal: task:16530@10 xid=0x09c9d05d: hdr=48 xdr=232/0/0 inline/reply chunk
mount.nfs-1325 [001] 552.705867: xprtrdma_post_send: req=0xffff936438a80000, 2 SGEs, status=0
mount.nfs-1325 [001] 552.705868: xprt_transmit: peer=[192.168.100.215]:20049 xid=0x09c9d05d status=0
mount.nfs-1325 [001] 552.705891: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_transmit_status
mount.nfs-1325 [001] 552.705892: rpc_task_sleep: task:16530@10 flags=5a80 state=0015 status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 552.705900: xprtrdma_mr_recycle: mr=0xffff93643876c900 4380@0xffffd37d38bec100:0x0000172d
kworker/1:0-638 [001] 552.705901: xprtrdma_mr_unmap: mr=0xffff93643876c900 4380@0xffffd37d38bec100:0x0000172d
kworker/1:1H-177 [001] 552.708491: xprtrdma_wc_receive: cqe=0xffff936438a8f400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 552.708493: xprtrdma_wc_receive: cqe=0xffff936438a8f000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 552.708493: xprtrdma_wc_receive: cqe=0xffff936438a8fa00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:0-638 [001] 561.237755: rpc_task_begin: task:16536@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 561.237766: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 561.237769: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 561.237772: rpc_request: task:16536@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 561.237796: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 561.237798: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 561.237799: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 561.237803: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 561.237804: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 561.237805: rpc_task_run_action: task:16536@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 561.237811: rpc_task_run_action: task:16536@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 561.237811: rpc_task_run_action: task:16536@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 561.237812: rpc_task_run_action: task:16536@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 561.237883: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xd0a13197 status=0
kworker/u4:0-7 [001] 561.237892: rpc_task_run_action: task:16536@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 561.237894: rpc_task_sleep: task:16536@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 561.238249: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xd0a13197 status=0
kworker/u5:0-277 [001] 561.238255: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xd0a13197 status=80
kworker/u5:0-277 [001] 561.238257: rpc_task_wakeup: task:16536@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 561.238264: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xd0a13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 561.238266: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 561.238271: rpc_task_run_action: task:16536@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 561.238272: rpc_task_run_action: task:16536@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 561.238273: rpc_task_run_action: task:16536@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 561.238276: rpc_task_run_action: task:16536@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 561.238282: rpc_stats_latency: task:16536@3 xid=0xd0a13197 nfsv4 SEQUENCE backlog=65 rtt=436 execute=532
kworker/1:0-638 [001] 569.029490: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: DISCONNECTED (10/0)
kworker/1:0-638 [001] 569.029502: rpc_task_wakeup: task:16530@10 flags=5a80 state=0016 status=-11 timeout=54000 queue=xprt_pending
kworker/u5:0-277 [001] 569.029539: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
mount.nfs-1325 [001] 569.029556: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=xprt_timer
mount.nfs-1325 [001] 569.029558: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=call_status
mount.nfs-1325 [001] 569.029560: rpc_call_status: task:16530@10 status=-11
mount.nfs-1325 [001] 569.029561: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_encode
mount.nfs-1325 [001] 569.029574: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 569.029575: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 569.029578: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=-11 timeout=54000 queue=xprt_sending
kworker/u5:0-277 [001] 569.029712: rpc_task_wakeup: task:16530@10 flags=5a80 state=001f status=-11 timeout=54000 queue=xprt_sending
mount.nfs-1325 [001] 569.029717: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 569.029720: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 569.029720: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 569.029722: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 569.029722: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 569.029723: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 569.029725: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 571.264674: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: TIMEWAIT_EXIT (15/0)
kworker/0:1-630 [000] 576.598154: rpc_task_begin: task:16537@4 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:3-1199 [000] 576.598159: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:3-1199 [000] 576.598161: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=call_start
kworker/u4:3-1199 [000] 576.598163: rpc_request: task:16537@4 nfsv4 SEQUENCE (async)
kworker/u4:3-1199 [000] 576.598163: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:3-1199 [000] 576.598165: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:3-1199 [000] 576.598165: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:3-1199 [000] 576.598167: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:3-1199 [000] 576.598167: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:3-1199 [000] 576.598168: rpc_task_run_action: task:16537@4 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:3-1199 [000] 576.598171: rpc_task_run_action: task:16537@4 flags=5281 state=001d status=0 action=call_bind
kworker/u4:3-1199 [000] 576.598171: rpc_task_run_action: task:16537@4 flags=5281 state=001d status=0 action=call_connect
kworker/u4:3-1199 [000] 576.598172: rpc_task_run_action: task:16537@4 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:3-1199 [000] 576.598185: xprt_transmit: peer=[192.168.100.215]:2049 xid=0xa8601c7c status=0
kworker/u4:3-1199 [000] 576.598186: rpc_task_run_action: task:16537@4 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:3-1199 [000] 576.598187: rpc_task_sleep: task:16537@4 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 576.598388: xprt_lookup_rqst: peer=[192.168.100.215]:2049 xid=0xa8601c7c status=0
kworker/u5:0-277 [001] 576.598392: xprt_complete_rqst: peer=[192.168.100.215]:2049 xid=0xa8601c7c status=80
kworker/u5:0-277 [001] 576.598393: rpc_task_wakeup: task:16537@4 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 576.598401: xs_stream_read_request: peer=[192.168.100.215]:2049 xid=0xa8601c7c copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 576.598402: xs_stream_read_data: peer=[192.168.100.215]:2049 err=-11 total=92
kworker/u4:3-1199 [000] 576.598435: rpc_task_run_action: task:16537@4 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:3-1199 [000] 576.598436: rpc_task_run_action: task:16537@4 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:3-1199 [000] 576.598437: rpc_task_run_action: task:16537@4 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:3-1199 [000] 576.598440: rpc_task_run_action: task:16537@4 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:3-1199 [000] 576.598444: rpc_stats_latency: task:16537@4 xid=0xa8601c7c nfsv4 SEQUENCE backlog=21 rtt=216 execute=292
kworker/1:0-638 [001] 591.958812: rpc_task_begin: task:16538@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 591.958821: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 591.958822: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 591.958824: rpc_request: task:16538@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 591.958825: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 591.958827: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 591.958827: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 591.958830: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 591.958830: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 591.958832: rpc_task_run_action: task:16538@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 591.958835: rpc_task_run_action: task:16538@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 591.958836: rpc_task_run_action: task:16538@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 591.958836: rpc_task_run_action: task:16538@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 591.958863: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xd1a13197 status=0
kworker/u4:0-7 [001] 591.958865: rpc_task_run_action: task:16538@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 591.958867: rpc_task_sleep: task:16538@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 591.959128: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xd1a13197 status=0
kworker/u5:0-277 [001] 591.959133: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xd1a13197 status=80
kworker/u5:0-277 [001] 591.959134: rpc_task_wakeup: task:16538@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 591.959139: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xd1a13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 591.959141: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 591.959145: rpc_task_run_action: task:16538@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 591.959145: rpc_task_run_action: task:16538@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 591.959146: rpc_task_run_action: task:16538@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 591.959149: rpc_task_run_action: task:16538@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 591.959153: rpc_stats_latency: task:16538@3 xid=0xd1a13197 nfsv4 SEQUENCE backlog=30 rtt=291 execute=344
kworker/1:0-638 [001] 600.492304: xprtrdma_reconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/1:0-638 [001] 600.492339: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
kworker/1:0-638 [001] 600.492393: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/u4:3-1199 [000] 600.492618: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ADDR_RESOLVED (0/0)
kworker/u4:3-1199 [000] 600.492872: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ROUTE_RESOLVED (2/0)
kworker/1:0-638 [001] 600.493835: xprtrdma_post_recv: cqe=0xffff936438a8fa00
kworker/1:0-638 [001] 600.493837: xprtrdma_post_recv: cqe=0xffff936438a8f000
kworker/1:0-638 [001] 600.493838: xprtrdma_post_recv: cqe=0xffff936438a8f400
kworker/1:0-638 [001] 600.493842: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 3 new recvs, 3 active (rc 0)
kworker/1:1-38 [001] 600.495693: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ESTABLISHED (9/0)
kworker/1:0-638 [001] 600.495805: rpc_task_wakeup: task:16530@10 flags=5a80 state=001e status=-11 timeout=54000 queue=xprt_pending
mount.nfs-1325 [001] 600.495844: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=xprt_connect_status
mount.nfs-1325 [001] 600.495855: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 600.495858: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 600.495859: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 600.495860: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 600.495861: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 600.495862: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 600.495863: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_transmit
mount.nfs-1325 [001] 600.495874: xprtrdma_mr_map: mr=0xffff93643876c100 0@0x0000000000000000:0x00000000
mount.nfs-1325 [001] 600.495878: xprtrdma_reply_chunk: task:16530@10 mr=0xffff93643876c100 4380@0xffffd37d38bec100:0x0000158c (last)
mount.nfs-1325 [001] 600.495880: xprtrdma_marshal: task:16530@10 xid=0x09c9d05d: hdr=48 xdr=232/0/0 inline/reply chunk
mount.nfs-1325 [001] 600.495889: xprtrdma_post_send: req=0xffff936438a80000, 2 SGEs, status=0
mount.nfs-1325 [001] 600.495892: xprt_transmit: peer=[192.168.100.215]:20049 xid=0x09c9d05d status=0
mount.nfs-1325 [001] 600.495939: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_transmit_status
mount.nfs-1325 [001] 600.495942: rpc_task_sleep: task:16530@10 flags=5a80 state=0015 status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 600.495957: xprtrdma_mr_recycle: mr=0xffff93643876cc00 4380@0xffffd37d38bec100:0x00001617
kworker/1:0-638 [001] 600.495959: xprtrdma_mr_unmap: mr=0xffff93643876cc00 4380@0xffffd37d38bec100:0x00001617
kworker/1:1H-177 [001] 600.500898: xprtrdma_wc_receive: cqe=0xffff936438a8f400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 600.500901: xprtrdma_wc_receive: cqe=0xffff936438a8f000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 600.500901: xprtrdma_wc_receive: cqe=0xffff936438a8fa00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:0-638 [001] 616.818067: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: DISCONNECTED (10/0)
kworker/1:0-638 [001] 616.818073: rpc_task_wakeup: task:16530@10 flags=5a80 state=0016 status=-11 timeout=54000 queue=xprt_pending
kworker/u5:0-277 [001] 616.818092: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
mount.nfs-1325 [001] 616.818100: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=xprt_timer
mount.nfs-1325 [001] 616.818101: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=-11 action=call_status
mount.nfs-1325 [001] 616.818102: rpc_call_status: task:16530@10 status=-11
mount.nfs-1325 [001] 616.818103: rpc_task_run_action: task:16530@10 flags=5a80 state=0015 status=0 action=call_encode
mount.nfs-1325 [001] 616.818108: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 616.818109: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 616.818110: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=-11 timeout=54000 queue=xprt_sending
kworker/u5:0-277 [001] 616.818169: rpc_task_wakeup: task:16530@10 flags=5a80 state=001f status=-11 timeout=54000 queue=xprt_sending
mount.nfs-1325 [001] 616.818171: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 616.818172: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 616.818173: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 616.818173: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_encode
mount.nfs-1325 [001] 616.818173: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_bind
mount.nfs-1325 [001] 616.818174: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_connect
mount.nfs-1325 [001] 616.818174: rpc_task_sleep: task:16530@10 flags=5a80 state=001d status=0 timeout=54000 queue=xprt_pending
kworker/1:0-638 [001] 619.052854: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: TIMEWAIT_EXIT (15/0)
kworker/1:0-638 [001] 622.679678: rpc_task_begin: task:16539@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 622.679687: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 622.679689: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 622.679691: rpc_request: task:16539@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 622.679692: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 622.679693: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 622.679694: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 622.679696: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 622.679697: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 622.679698: rpc_task_run_action: task:16539@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 622.679702: rpc_task_run_action: task:16539@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 622.679702: rpc_task_run_action: task:16539@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 622.679703: rpc_task_run_action: task:16539@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 622.679722: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xd2a13197 status=0
kworker/u4:0-7 [001] 622.679723: rpc_task_run_action: task:16539@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 622.679725: rpc_task_sleep: task:16539@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 622.679851: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xd2a13197 status=0
kworker/u5:0-277 [001] 622.679856: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xd2a13197 status=80
kworker/u5:0-277 [001] 622.679857: rpc_task_wakeup: task:16539@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 622.679862: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xd2a13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 622.679864: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 622.679867: rpc_task_run_action: task:16539@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 622.679867: rpc_task_run_action: task:16539@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 622.679868: rpc_task_run_action: task:16539@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 622.679870: rpc_task_run_action: task:16539@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 622.679874: rpc_stats_latency: task:16539@3 xid=0xd2a13197 nfsv4 SEQUENCE backlog=29 rtt=148 execute=198
kworker/0:1-630 [000] 638.040121: rpc_task_begin: task:16540@4 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:2-703 [001] 638.040207: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:2-703 [001] 638.040209: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=call_start
kworker/u4:2-703 [001] 638.040211: rpc_request: task:16540@4 nfsv4 SEQUENCE (async)
kworker/u4:2-703 [001] 638.040212: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:2-703 [001] 638.040213: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:2-703 [001] 638.040214: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:2-703 [001] 638.040216: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:2-703 [001] 638.040217: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:2-703 [001] 638.040218: rpc_task_run_action: task:16540@4 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:2-703 [001] 638.040221: rpc_task_run_action: task:16540@4 flags=5281 state=001d status=0 action=call_bind
kworker/u4:2-703 [001] 638.040222: rpc_task_run_action: task:16540@4 flags=5281 state=001d status=0 action=call_connect
kworker/u4:2-703 [001] 638.040222: rpc_task_run_action: task:16540@4 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:2-703 [001] 638.040247: xprt_transmit: peer=[192.168.100.215]:2049 xid=0xa9601c7c status=0
kworker/u4:2-703 [001] 638.040248: rpc_task_run_action: task:16540@4 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:2-703 [001] 638.040250: rpc_task_sleep: task:16540@4 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 638.040552: xprt_lookup_rqst: peer=[192.168.100.215]:2049 xid=0xa9601c7c status=0
kworker/u5:0-277 [001] 638.040555: xprt_complete_rqst: peer=[192.168.100.215]:2049 xid=0xa9601c7c status=80
kworker/u5:0-277 [001] 638.040557: rpc_task_wakeup: task:16540@4 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 638.040561: xs_stream_read_request: peer=[192.168.100.215]:2049 xid=0xa9601c7c copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 638.040575: xs_stream_read_data: peer=[192.168.100.215]:2049 err=-11 total=92
kworker/u4:2-703 [001] 638.040578: rpc_task_run_action: task:16540@4 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:2-703 [001] 638.040578: rpc_task_run_action: task:16540@4 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:2-703 [001] 638.040579: rpc_task_run_action: task:16540@4 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:2-703 [001] 638.040581: rpc_task_run_action: task:16540@4 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:2-703 [001] 638.040584: rpc_stats_latency: task:16540@4 xid=0xa9601c7c nfsv4 SEQUENCE backlog=105 rtt=329 execute=466
kworker/1:2-1330 [001] 648.280545: xprtrdma_reconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/1:2-1330 [001] 648.280581: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
kworker/1:2-1330 [001] 648.280637: xprtrdma_conn_start: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/u4:0-7 [001] 648.280712: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ADDR_RESOLVED (0/0)
kworker/u4:0-7 [001] 648.280728: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ROUTE_RESOLVED (2/0)
kworker/1:2-1330 [001] 648.281754: xprtrdma_post_recv: cqe=0xffff936438a8fa00
kworker/1:2-1330 [001] 648.281756: xprtrdma_post_recv: cqe=0xffff936438a8f000
kworker/1:2-1330 [001] 648.281757: xprtrdma_post_recv: cqe=0xffff936438a8f400
kworker/1:2-1330 [001] 648.281761: xprtrdma_post_recvs: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: 3 new recvs, 3 active (rc 0)
kworker/1:0-638 [001] 648.283415: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: ESTABLISHED (9/0)
kworker/1:2-1330 [001] 648.283499: rpc_task_wakeup: task:16530@10 flags=5a80 state=001e status=-11 timeout=54000 queue=xprt_pending
mount.nfs-1325 [001] 648.283519: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=xprt_connect_status
mount.nfs-1325 [001] 648.283520: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-11 action=call_connect_status
mount.nfs-1325 [001] 648.283522: rpc_connect_status: task:16530@10 status=-11
mount.nfs-1325 [001] 648.283523: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=0 action=call_timeout
mount.nfs-1325 [001] 648.287570: rpc_task_run_action: task:16530@10 flags=5a80 state=001d status=-110 action=rpc_exit_task
mount.nfs-1325 [001] 648.287576: rpc_stats_latency: task:16530@10 xid=0x09c9d05d nfsv4 EXCHANGE_ID backlog=149816112 rtt=0 execute=197606237
mount.nfs-1325 [001] 648.287584: xprtrdma_mr_localinv: mr=0xffff93643876c100 4380@0xffffd37d38bec100:0x0000158c
kworker/1:1H-177 [001] 648.287618: xprtrdma_wc_li_wake: mr=0xffff93643876c100 state=INVALID: SUCCESS (0/0x0)
mount.nfs-1325 [001] 648.287627: xprtrdma_mr_unmap: mr=0xffff93643876c100 4380@0xffffd37d38bec100:0x0000158c
mount.nfs-1325 [001] 648.287629: xprtrdma_rpc_done: task:16530@10 req=0xffff936438a80000 rep=(nil)
mount.nfs-1325 [001] 648.287657: svc_xprt_do_enqueue: xprt=0xffff93643814cc00 addr=uninitialized pid=0 flags=XPT_BUSY|XPT_CLOSE|XPT_CHNGBUF|XPT_CONG_CTRL
kworker/1:2-1330 [001] 648.294206: xprtrdma_destroy: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000
kworker/1:1H-177 [001] 648.294254: xprtrdma_wc_receive: cqe=0xffff936438a8f400 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 648.294255: xprtrdma_wc_receive: cqe=0xffff936438a8f000 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:1H-177 [001] 648.294255: xprtrdma_wc_receive: cqe=0xffff936438a8fa00 0 bytes: WR_FLUSH_ERR (5/0x0)
kworker/1:0-638 [001] 648.294647: xprtrdma_cm_event: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: DISCONNECTED (10/0)
kworker/1:2-1330 [001] 648.295876: xprtrdma_disconnect: peer=[192.168.100.215]:20049 r_xprt=0xffff936438713000: status=0 disconnected
kworker/1:2-1330 [001] 653.400612: rpc_task_begin: task:16541@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 653.400618: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 653.400619: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 653.400621: rpc_request: task:16541@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 653.400621: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 653.400622: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 653.400623: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 653.400625: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 653.400625: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 653.400626: rpc_task_run_action: task:16541@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 653.400629: rpc_task_run_action: task:16541@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 653.400629: rpc_task_run_action: task:16541@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 653.400629: rpc_task_run_action: task:16541@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 653.400669: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xd3a13197 status=0
kworker/u4:0-7 [001] 653.400671: rpc_task_run_action: task:16541@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 653.400672: rpc_task_sleep: task:16541@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 653.400747: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xd3a13197 status=0
kworker/u5:0-277 [001] 653.400750: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xd3a13197 status=80
kworker/u5:0-277 [001] 653.400751: rpc_task_wakeup: task:16541@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 653.400754: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xd3a13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 653.400756: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 653.400757: rpc_task_run_action: task:16541@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 653.400758: rpc_task_run_action: task:16541@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 653.400758: rpc_task_run_action: task:16541@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 653.400765: rpc_task_run_action: task:16541@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 653.400769: rpc_stats_latency: task:16541@3 xid=0xd3a13197 nfsv4 SEQUENCE backlog=22 rtt=117 execute=159
kworker/1:2-1330 [001] 684.121749: rpc_task_begin: task:16542@3 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 684.121767: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 684.121772: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 684.121775: rpc_request: task:16542@3 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 684.121776: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 684.121779: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 684.121779: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 684.121785: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 684.121786: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 684.121789: rpc_task_run_action: task:16542@3 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 684.121796: rpc_task_run_action: task:16542@3 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 684.121796: rpc_task_run_action: task:16542@3 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 684.121797: rpc_task_run_action: task:16542@3 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 684.121908: xprt_transmit: peer=[192.168.100.1]:2049 xid=0xd4a13197 status=0
kworker/u4:0-7 [001] 684.121913: rpc_task_run_action: task:16542@3 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 684.121916: rpc_task_sleep: task:16542@3 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 684.122268: xprt_lookup_rqst: peer=[192.168.100.1]:2049 xid=0xd4a13197 status=0
kworker/u5:0-277 [001] 684.122276: xprt_complete_rqst: peer=[192.168.100.1]:2049 xid=0xd4a13197 status=80
kworker/u5:0-277 [001] 684.122279: rpc_task_wakeup: task:16542@3 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 684.122288: xs_stream_read_request: peer=[192.168.100.1]:2049 xid=0xd4a13197 copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 684.122292: xs_stream_read_data: peer=[192.168.100.1]:2049 err=-11 total=92
kworker/u4:0-7 [001] 684.122299: rpc_task_run_action: task:16542@3 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 684.122301: rpc_task_run_action: task:16542@3 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 684.122341: rpc_task_run_action: task:16542@3 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 684.122346: rpc_task_run_action: task:16542@3 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 684.122355: rpc_stats_latency: task:16542@3 xid=0xd4a13197 nfsv4 SEQUENCE backlog=57 rtt=470 execute=609
kworker/1:2-1330 [001] 699.482373: rpc_task_begin: task:16543@4 flags=5281 state=0004 status=0 action=(nil)f
kworker/u4:0-7 [001] 699.482393: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=rpc_prepare_task
kworker/u4:0-7 [001] 699.482397: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=call_start
kworker/u4:0-7 [001] 699.482401: rpc_request: task:16543@4 nfsv4 SEQUENCE (async)
kworker/u4:0-7 [001] 699.482403: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=call_reserve
kworker/u4:0-7 [001] 699.482406: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=call_reserveresult
kworker/u4:0-7 [001] 699.482407: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=call_refresh
kworker/u4:0-7 [001] 699.482413: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=call_refreshresult
kworker/u4:0-7 [001] 699.482414: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=call_allocate
kworker/u4:0-7 [001] 699.482418: rpc_task_run_action: task:16543@4 flags=5281 state=0005 status=0 action=call_encode
kworker/u4:0-7 [001] 699.482496: rpc_task_run_action: task:16543@4 flags=5281 state=001d status=0 action=call_bind
kworker/u4:0-7 [001] 699.482498: rpc_task_run_action: task:16543@4 flags=5281 state=001d status=0 action=call_connect
kworker/u4:0-7 [001] 699.482498: rpc_task_run_action: task:16543@4 flags=5281 state=001d status=0 action=call_transmit
kworker/u4:0-7 [001] 699.482563: xprt_transmit: peer=[192.168.100.215]:2049 xid=0xaa601c7c status=0
kworker/u4:0-7 [001] 699.482568: rpc_task_run_action: task:16543@4 flags=5a81 state=0015 status=0 action=call_transmit_status
kworker/u4:0-7 [001] 699.482571: rpc_task_sleep: task:16543@4 flags=5a81 state=0015 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 699.483036: xprt_lookup_rqst: peer=[192.168.100.215]:2049 xid=0xaa601c7c status=0
kworker/u5:0-277 [001] 699.483047: xprt_complete_rqst: peer=[192.168.100.215]:2049 xid=0xaa601c7c status=80
kworker/u5:0-277 [001] 699.483051: rpc_task_wakeup: task:16543@4 flags=5a81 state=0006 status=0 timeout=18000 queue=xprt_pending
kworker/u5:0-277 [001] 699.483062: xs_stream_read_request: peer=[192.168.100.215]:2049 xid=0xaa601c7c copied=80 reclen=80 offset=80
kworker/u5:0-277 [001] 699.483066: xs_stream_read_data: peer=[192.168.100.215]:2049 err=-11 total=92
kworker/u4:0-7 [001] 699.483073: rpc_task_run_action: task:16543@4 flags=5a81 state=0005 status=0 action=xprt_timer
kworker/u4:0-7 [001] 699.483074: rpc_task_run_action: task:16543@4 flags=5a81 state=0005 status=0 action=call_status
kworker/u4:0-7 [001] 699.483075: rpc_task_run_action: task:16543@4 flags=5a81 state=0005 status=0 action=call_decode
kworker/u4:0-7 [001] 699.483080: rpc_task_run_action: task:16543@4 flags=5a81 state=0005 status=0 action=rpc_exit_task
kworker/u4:0-7 [001] 699.483089: rpc_stats_latency: task:16543@4 xid=0xaa601c7c nfsv4 SEQUENCE backlog=137 rtt=536 execute=721
