From: Chuck Lever <chuck.lever@oracle.com>
To: Trond Myklebust <trondmy@hammerspace.com>
Cc: "tibbs@math.uh.edu" <tibbs@math.uh.edu>,
"bcodding@redhat.com" <bcodding@redhat.com>,
Anna Schumaker <Anna.Schumaker@netapp.com>,
Linux NFS Mailing List <linux-nfs@vger.kernel.org>
Subject: Re: Need help debugging NFS issues new to 4.20 kernel
Date: Wed, 20 Feb 2019 10:39:16 -0500 [thread overview]
Message-ID: <1FA7F8B3-872E-4AF6-8125-2664443E59D1@oracle.com> (raw)
In-Reply-To: <2ab06cbdc19d7a642e04f1e66abbeaa507b034bc.camel@hammerspace.com>
> On Feb 20, 2019, at 10:37 AM, Trond Myklebust <trondmy@hammerspace.com> wrote:
>
> On Wed, 2019-02-20 at 09:25 -0600, Jason L Tibbitts III wrote:
>> Sadly, after a bit more testing I find that 4.20.10 with that patch
>> applied still exhibits the problem. Just found a machine where NFS
>> hung
>> up just six minutes after the user logged in. As always: nothing is
>> logged to the client or the server. I turned on the tracing as
>> requested previously and see what I think it just the same sequence
>> as
>> before. Please let me know if there is any other information I can
>> provide. Right now I'm going to build 4.20.10 with my previously
>> posted
>> revert patch applied and roll that out to the same 50 hosts and see
>> how
>> it fares.
>>
>> - J<
>>
>> kworker/u8:0-12608 [001] .... 47884.661073: rpc_request: task:
>> 20469@1 nfsv4 SEQUENCE (async)
>> kworker/u8:0-12608 [001] .... 47884.661073: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=call_reserve
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661074: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=call_reserveresult
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661074: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=call_refresh
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661075: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=call_refreshresult
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661076: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=call_allocate
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661076: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=call_encode
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661091: rpc_task_run_action:
>> task:20469@1 flags=5281 state=001d status=0 action=call_bind [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661091: rpc_task_run_action:
>> task:20469@1 flags=5281 state=001d status=0 action=call_connect
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661092: rpc_task_run_action:
>> task:20469@1 flags=5281 state=001d status=0 action=call_transmit
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661106: xprt_transmit:
>> peer=[172.21.86.74]:2049 xid=0x0d7ca068 status=0
>> kworker/u8:0-12608 [001] .... 47884.661107: rpc_task_run_action:
>> task:20469@1 flags=5a81 state=0015 status=0
>> action=call_transmit_status [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661107: rpc_task_sleep: task:
>> 20469@1 flags=5a81 state=0015 status=0 timeout=60000
>> queue=xprt_pending
>> kworker/u9:0-12884 [002] .... 47884.661371: xprt_lookup_rqst:
>> peer=[172.21.86.74]:2049 xid=0x0d7ca068 status=0
>> kworker/u9:0-12884 [002] .... 47884.661372: xprt_complete_rqst:
>> peer=[172.21.86.74]:2049 xid=0x0d7ca068 status=112
>> kworker/u9:0-12884 [002] .... 47884.661373: rpc_task_wakeup:
>> task:20469@1 flags=5a81 state=0006 status=0 timeout=60000
>> queue=xprt_pending
>> kworker/u9:0-12884 [002] .... 47884.661375:
>> xs_stream_read_request: peer=[172.21.86.74]:2049 xid=0x0d7ca068
>> copied=112 reclen=112 offset=112
>> kworker/u9:0-12884 [002] .... 47884.661376: xs_stream_read_data:
>> peer=[172.21.86.74]:2049 err=-11 total=116
>> kworker/u8:0-12608 [001] .... 47884.661388: rpc_task_run_action:
>> task:20469@1 flags=5a81 state=0005 status=0 action=xprt_timer
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661389: rpc_task_run_action:
>> task:20469@1 flags=5a81 state=0005 status=0 action=call_status
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661389: rpc_task_run_action:
>> task:20469@1 flags=5a81 state=0005 status=0 action=call_decode
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661408: rpc_task_run_action:
>> task:20469@1 flags=5a81 state=0005 status=-10063 action=rpc_exit_task
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661409: nfs4_sequence_done:
>> error=-10063 (SEQ_MISORDERED) session=0x4480e725 slot_nr=0 seq_nr=1
>> highest_slotid=0 target_highest_slotid=0 status_flags=0 ()
>> kworker/u8:0-12608 [001] .... 47884.661410: rpc_stats_latency:
>> task:20469@1 xid=0x0d7ca068 nfsv4 SEQUENCE backlog=21 rtt=278
>> execute=339
>> kworker/u8:0-12608 [001] .... 47884.661412: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=rpc_prepare_task
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661413: nfs4_setup_sequence:
>> session=0x4480e725 slot_nr=0 seq_nr=1 highest_used_slotid=0
>> kworker/u8:0-12608 [001] .... 47884.661413: rpc_task_run_action:
>> task:20469@1 flags=5281 state=0005 status=0 action=call_start
>> [sunrpc]
>> kworker/u8:0-12608 [001] .... 47884.661414: rpc_request: task:
>> 20469@1 nfsv4 SEQUENCE (async)
>
> This is not an RPC layer issue. It is a SEQ_MISORDERED error on slot 0.
> If the client can't recover then that will hang your NFSv4.1 session
> against that server.
>
> Are you sure this isn't what was happening previously?
This is exactly what was happening earlier. See my e-mail to the list
on Feb 8.
--
Chuck Lever
next prev parent reply other threads:[~2019-02-20 15:39 UTC|newest]
Thread overview: 25+ messages / expand[flat|nested] mbox.gz Atom feed top
2019-01-24 17:32 Need help debugging NFS issues new to 4.20 kernel Jason L Tibbitts III
2019-01-24 19:28 ` Jason L Tibbitts III
2019-01-24 19:58 ` Trond Myklebust
2019-01-25 19:13 ` Schumaker, Anna
2019-01-26 17:59 ` Sasha Levin
2019-01-25 19:51 ` Jason L Tibbitts III
2019-02-05 18:12 ` Jason Tibbitts
2019-02-06 12:05 ` Benjamin Coddington
[not found] ` <87imxwab12.fsf@hippogriff.math.uh.edu>
2019-02-07 11:13 ` Benjamin Coddington
[not found] ` <87d0o3aadg.fsf@hippogriff.math.uh.edu>
2019-02-08 12:01 ` Benjamin Coddington
2019-02-08 15:19 ` Chuck Lever
2019-02-08 17:17 ` Jason L Tibbitts III
2019-02-15 20:33 ` Jason L Tibbitts III
2019-02-16 14:46 ` Trond Myklebust
2019-02-20 2:13 ` Jason L Tibbitts III
2019-02-20 15:25 ` Jason L Tibbitts III
2019-02-20 15:37 ` Trond Myklebust
2019-02-20 15:39 ` Chuck Lever [this message]
2019-02-20 15:41 ` Trond Myklebust
2019-02-21 18:19 ` Jason L Tibbitts III
2019-02-25 19:24 ` Jason L Tibbitts III
2019-02-25 23:15 ` Benjamin Coddington
2019-02-20 16:25 ` Jason L Tibbitts III
2019-02-20 16:45 ` Trond Myklebust
2019-02-20 16:49 ` Jason L Tibbitts III
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=1FA7F8B3-872E-4AF6-8125-2664443E59D1@oracle.com \
--to=chuck.lever@oracle.com \
--cc=Anna.Schumaker@netapp.com \
--cc=bcodding@redhat.com \
--cc=linux-nfs@vger.kernel.org \
--cc=tibbs@math.uh.edu \
--cc=trondmy@hammerspace.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).