| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <c8-cRKuS2KXjk19lBwOGLCt21IbVv7HsS-V-ihDmhQ1Uae_LHNm83T0dOKvbYqsf4AeP5T8PR_xdiKLj5-Nvec-QVTLqIC4NGuU2FA0hN5U=@tylerwross.com>
Date: Thu, 13 Nov 2025 17:16:18 +0000
From: "Tyler W. Ross" <TWR@...erwross.com>
To: "1120598@...s.debian.org" <1120598@...s.debian.org>, Chuck Lever <chuck.lever@...cle.com>, Jeff Layton <jlayton@...nel.org>, NeilBrown <neil@...wn.name>, Scott Mayhew <smayhew@...hat.com>, Steve Dickson <steved@...hat.com>, Salvatore Bonaccorso <carnil@...ian.org>
Cc: Olga Kornievskaia <okorniev@...hat.com>, Dai Ngo <Dai.Ngo@...cle.com>, Tom Talpey <tom@...pey.com>, Trond Myklebust <trondmy@...nel.org>, Anna Schumaker <anna@...nel.org>, linux-nfs@...r.kernel.org, linux-kernel@...r.kernel.org
Subject: Re: ls input/output error ("NFS: readdir(/) returns -5") on krb5 NFSv4 client using SHA2
Thanks, Chunk.
Suggested trace-cmd report from the client follows. Last 3 lines appear salient, but I've included the full report just in case.
cpus=4
ls-969 [003] ..... 270.318649: nfs_getattr_enter: fileid=00:2d:262146 fhandle=0xad8c294c version=31 cache_validity=0x0 ()
ls-969 [003] ..... 270.318651: nfs_getattr_exit: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x0 ()
ls-969 [003] ..... 270.318654: nfs_revalidate_inode_enter: fileid=00:2d:262146 fhandle=0xad8c294c version=31 cache_validity=0x0 ()
ls-969 [003] ..... 270.318658: rpc_task_begin: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=0x4 status=0 action=0x0
ls-969 [003] ..... 270.318658: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=rpc_prepare_task
ls-969 [003] ..... 270.318660: nfs4_setup_sequence: session=0x5988ad3c slot_nr=0 seq_nr=24 highest_used_slotid=0
ls-969 [003] ..... 270.318661: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_start
ls-969 [003] ..... 270.318661: rpc_request: task:00000006@...00005 nfsv4 GETATTR (sync)
ls-969 [003] ..... 270.318662: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_reserve
ls-969 [003] ..... 270.318663: xprt_reserve: task:00000006@...00005 xid=0x79569c7a
ls-969 [003] ..... 270.318663: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_reserveresult
ls-969 [003] ..... 270.318663: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_refresh
rpc.gssd-613 [001] ..... 270.318690: rpcgss_upcall_msg: msg='mech=krb5 uid=591200003 enctypes=20,19,18,17'
rpc.gssd-970 [002] ..... 270.326582: rpcgss_context: win_size=128 expiry=4316009978 now=4294959728 timeout=84201 acceptor=nfs@...srv.ipa.twrlab.net
ls-969 [003] ...1. 270.326598: rpcgss_ctx_init: cred=0xffff8895c5989900 service=integrity principal='(null)'
ls-969 [003] ..... 270.326600: rpcgss_upcall_result: for uid 591200003, result=0
ls-969 [003] ..... 270.326601: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_refreshresult
ls-969 [003] ..... 270.326601: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_allocate
ls-969 [003] ..... 270.326603: rpc_buf_alloc: task:00000006@...00005 callsize=1844 recvsize=2704 status=0
ls-969 [003] ..... 270.326603: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_encode
ls-969 [003] ..... 270.326604: rpcgss_seqno: task:00000006@...00005 xid=0x79569c7a seqno=1
ls-969 [003] ..... 270.326611: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x1c status=0 action=call_transmit
ls-969 [003] ...1. 270.326611: xprt_reserve_xprt: task:00000006@...00005 snd_task:00000006
ls-969 [003] ..... 270.326612: rpcgss_need_reencode: task:00000006@...00005 xid=0x79569c7a rq_seqno=1 seq_xmit=0 reencode unneeded
ls-969 [003] ..... 270.326612: rpc_xdr_sendto: task:00000006@...00005 head=[0xffff8895c29fe008,260] page=0(0) tail=[(nil),0] len=260
ls-969 [003] ..... 270.326627: xprt_transmit: task:00000006@...00005 xid=0x79569c7a seqno=1 status=0
ls-969 [003] ...1. 270.326628: xprt_release_xprt: task:00000006@...00005 snd_task:ffffffff
ls-969 [003] ..... 270.326629: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x14 status=0 action=call_transmit_status
ls-969 [003] ...2. 270.326629: rpc_task_sleep: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x14 status=0 timeout=0 queue=xprt_pending
ls-969 [003] ..... 270.326630: rpc_task_sync_sleep: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=0x16 status=0 action=call_status
<idle>-0 [001] ..s2. 270.326754: xs_data_ready: peer=[10.108.2.102]:2049
kworker/u16:0-12 [001] ...1. 270.326762: xprt_lookup_rqst: peer=[10.108.2.102]:2049 xid=0x79569c7a status=0
kworker/u16:0-12 [001] ...2. 270.326764: rpc_task_wakeup: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=0x6 status=0 timeout=15000 queue=xprt_pending
kworker/u16:0-12 [001] ..... 270.326768: xs_stream_read_request: peer=[10.108.2.102]:2049 xid=0x79569c7a copied=384 reclen=384 offset=384
kworker/u16:0-12 [001] ..... 270.326769: xs_stream_read_data: peer=[10.108.2.102]:2049 err=-11 total=388
ls-969 [003] ..... 270.326775: rpc_task_sync_wake: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_status
ls-969 [003] ..... 270.326775: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=xprt_timer
ls-969 [003] ..... 270.326775: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_status
ls-969 [003] ..... 270.326775: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_decode
ls-969 [003] ..... 270.326776: rpc_xdr_recvfrom: task:00000006@...00005 head=[0xffff8895c29fe73c,2704] page=0(0) tail=[(nil),0] len=384
ls-969 [003] ..... 270.326785: nfs4_map_name_to_uid: error=0 (OK) id=591200000 name=admin@....twrlab.net
ls-969 [003] ..... 270.326786: nfs4_map_group_to_gid: error=0 (OK) id=591200004 name=domainusers@....twrlab.net
ls-969 [003] ..... 270.326787: rpc_task_run_action: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=rpc_exit_task
ls-969 [003] ..... 270.326787: rpc_task_end: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=rpc_exit_task
ls-969 [003] ..... 270.326788: rpc_stats_latency: task:00000006@...00005 xid=0x79569c7a nfsv4 GETATTR backlog=7956 rtt=149 execute=8131 xprt_id=1
ls-969 [003] ..... 270.326789: rpc_task_call_done: task:00000006@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=nfs41_call_sync_done
ls-969 [003] ..... 270.326789: nfs4_sequence_done: error=0 (OK) session=0x5988ad3c slot_nr=0 seq_nr=24 highest_slotid=63 target_highest_slotid=63 status_flags=0x0 ()
ls-969 [003] ...1. 270.326791: xprt_release_xprt: task:00000006@...00005 snd_task:ffffffff
ls-969 [003] ..... 270.326793: nfs4_getattr: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c valid=TYPE|MODE|NLINK|OWNER|GROUP|RDEV|SIZE|FSID|FILEID|ATIME|MTIME|CTIME|CHANGE|BTIME|0x400200
ls-969 [003] ...1. 270.326795: nfs_refresh_inode_enter: fileid=00:2d:262146 fhandle=0xad8c294c version=31 cache_validity=0x0 ()
ls-969 [003] ...1. 270.326797: nfs_set_cache_invalid: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x0 ()
ls-969 [003] ...1. 270.326797: nfs_refresh_inode_exit: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x0 ()
ls-969 [003] ..... 270.326798: nfs_revalidate_inode_exit: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x0 ()
ls-969 [003] ..... 270.326799: nfs_access_enter: fileid=00:2d:262146 fhandle=0xad8c294c version=31 cache_validity=0x0 ()
ls-969 [003] ..... 270.326801: rpc_task_begin: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=0x4 status=0 action=0x0
ls-969 [003] ..... 270.326801: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=rpc_prepare_task
ls-969 [003] ..... 270.326801: nfs4_setup_sequence: session=0x5988ad3c slot_nr=0 seq_nr=25 highest_used_slotid=0
ls-969 [003] ..... 270.326802: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_start
ls-969 [003] ..... 270.326802: rpc_request: task:00000007@...00005 nfsv4 ACCESS (sync)
ls-969 [003] ..... 270.326802: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_reserve
ls-969 [003] ..... 270.326803: xprt_reserve: task:00000007@...00005 xid=0x7a569c7a
ls-969 [003] ..... 270.326803: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_reserveresult
ls-969 [003] ..... 270.326803: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_refresh
ls-969 [003] ..... 270.326804: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_refreshresult
ls-969 [003] ..... 270.326804: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_allocate
ls-969 [003] ..... 270.326804: rpc_buf_alloc: task:00000007@...00005 callsize=1836 recvsize=2712 status=0
ls-969 [003] ..... 270.326804: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_encode
ls-969 [003] ..... 270.326805: rpcgss_seqno: task:00000007@...00005 xid=0x7a569c7a seqno=2
ls-969 [003] ..... 270.326807: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x1c status=0 action=call_transmit
ls-969 [003] ...1. 270.326807: xprt_reserve_xprt: task:00000007@...00005 snd_task:00000007
ls-969 [003] ..... 270.326808: rpcgss_need_reencode: task:00000007@...00005 xid=0x7a569c7a rq_seqno=2 seq_xmit=1 reencode unneeded
ls-969 [003] ..... 270.326808: rpc_xdr_sendto: task:00000007@...00005 head=[0xffff8895c29fe008,268] page=0(0) tail=[(nil),0] len=268
ls-969 [003] ..... 270.326816: xprt_transmit: task:00000007@...00005 xid=0x7a569c7a seqno=2 status=0
ls-969 [003] ...1. 270.326817: xprt_release_xprt: task:00000007@...00005 snd_task:ffffffff
ls-969 [003] ..... 270.326817: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x14 status=0 action=call_transmit_status
ls-969 [003] ...2. 270.326817: rpc_task_sleep: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x14 status=0 timeout=0 queue=xprt_pending
ls-969 [003] ..... 270.326817: rpc_task_sync_sleep: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=0x16 status=0 action=call_status
<idle>-0 [001] ..s2. 270.326882: xs_data_ready: peer=[10.108.2.102]:2049
kworker/u16:0-12 [001] ...1. 270.326885: xprt_lookup_rqst: peer=[10.108.2.102]:2049 xid=0x7a569c7a status=0
kworker/u16:0-12 [001] ...2. 270.326885: rpc_task_wakeup: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=0x6 status=0 timeout=15000 queue=xprt_pending
kworker/u16:0-12 [001] ..... 270.326888: xs_stream_read_request: peer=[10.108.2.102]:2049 xid=0x7a569c7a copied=260 reclen=260 offset=260
kworker/u16:0-12 [001] ..... 270.326888: xs_stream_read_data: peer=[10.108.2.102]:2049 err=-11 total=264
ls-969 [003] ..... 270.326895: rpc_task_sync_wake: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_status
ls-969 [003] ..... 270.326895: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=xprt_timer
ls-969 [003] ..... 270.326895: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_status
ls-969 [003] ..... 270.326895: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_decode
ls-969 [003] ..... 270.326895: rpc_xdr_recvfrom: task:00000007@...00005 head=[0xffff8895c29fe734,2712] page=0(0) tail=[(nil),0] len=260
ls-969 [003] ..... 270.326898: rpc_task_run_action: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=rpc_exit_task
ls-969 [003] ..... 270.326898: rpc_task_end: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=rpc_exit_task
ls-969 [003] ..... 270.326899: rpc_stats_latency: task:00000007@...00005 xid=0x7a569c7a nfsv4 ACCESS backlog=7 rtt=76 execute=98 xprt_id=1
ls-969 [003] ..... 270.326899: rpc_task_call_done: task:00000007@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=nfs41_call_sync_done
ls-969 [003] ..... 270.326899: nfs4_sequence_done: error=0 (OK) session=0x5988ad3c slot_nr=0 seq_nr=25 highest_slotid=63 target_highest_slotid=63 status_flags=0x0 ()
ls-969 [003] ...1. 270.326900: xprt_release_xprt: task:00000007@...00005 snd_task:ffffffff
ls-969 [003] ...1. 270.326901: nfs_refresh_inode_enter: fileid=00:2d:262146 fhandle=0xad8c294c version=31 cache_validity=0x0 ()
ls-969 [003] ...1. 270.326901: nfs_set_cache_invalid: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x0 ()
ls-969 [003] ...1. 270.326901: nfs_refresh_inode_exit: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x0 ()
ls-969 [003] ..... 270.326902: nfs4_access: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c
ls-969 [003] ..... 270.326903: nfs_access_exit: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x4 (ACL_LRU_SET) mask=0x24 permitted=0x7
ls-969 [003] ..... 270.326907: nfs_getattr_enter: fileid=00:2d:262146 fhandle=0xad8c294c version=31 cache_validity=0x0 ()
ls-969 [003] ..... 270.326908: nfs_getattr_exit: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x0 () nfs_flags=0x4 (ACL_LRU_SET)
ls-969 [003] ..... 270.326928: nfs_readdir_cache_fill: fileid=00:2d:262146 fhandle=0xad8c294c version=31 cookie=0000000000000000:0x0 cache_index=0 dtsize=4096
ls-969 [003] ..... 270.326931: rpc_task_begin: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=0x4 status=0 action=0x0
ls-969 [003] ..... 270.326931: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=rpc_prepare_task
ls-969 [003] ..... 270.326931: nfs4_setup_sequence: session=0x5988ad3c slot_nr=0 seq_nr=26 highest_used_slotid=0
ls-969 [003] ..... 270.326931: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_start
ls-969 [003] ..... 270.326932: rpc_request: task:00000008@...00005 nfsv4 READDIR (sync)
ls-969 [003] ..... 270.326932: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_reserve
ls-969 [003] ..... 270.326932: xprt_reserve: task:00000008@...00005 xid=0x7b569c7a
ls-969 [003] ..... 270.326932: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_reserveresult
ls-969 [003] ..... 270.326932: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_refresh
ls-969 [003] ..... 270.326933: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_refreshresult
ls-969 [003] ..... 270.326933: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_allocate
ls-969 [003] ..... 270.326933: rpc_buf_alloc: task:00000008@...00005 callsize=3932 recvsize=176 status=0
ls-969 [003] ..... 270.326933: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_encode
ls-969 [003] ..... 270.326934: rpcgss_seqno: task:00000008@...00005 xid=0x7b569c7a seqno=3
ls-969 [003] ..... 270.326936: rpc_xdr_reply_pages: task:00000008@...00005 head=[0xffff8895c29fef64,140] page=4008(88) tail=[0xffff8895c29feff0,36] len=0
ls-969 [003] ..... 270.326937: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|NORTO|CRED_NOREF runstate=RUNNING|0x1c status=0 action=call_transmit
ls-969 [003] ...1. 270.326937: xprt_reserve_xprt: task:00000008@...00005 snd_task:00000008
ls-969 [003] ..... 270.326937: rpcgss_need_reencode: task:00000008@...00005 xid=0x7b569c7a rq_seqno=3 seq_xmit=2 reencode unneeded
ls-969 [003] ..... 270.326938: rpc_xdr_sendto: task:00000008@...00005 head=[0xffff8895c29fe008,284] page=0(0) tail=[(nil),0] len=284
ls-969 [003] ..... 270.326946: xprt_transmit: task:00000008@...00005 xid=0x7b569c7a seqno=3 status=0
ls-969 [003] ...1. 270.326947: xprt_release_xprt: task:00000008@...00005 snd_task:ffffffff
ls-969 [003] ..... 270.326947: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x14 status=0 action=call_transmit_status
ls-969 [003] ...2. 270.326947: rpc_task_sleep: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x14 status=0 timeout=0 queue=xprt_pending
ls-969 [003] ..... 270.326947: rpc_task_sync_sleep: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=0x16 status=0 action=call_status
<idle>-0 [001] ..s2. 270.327040: xs_data_ready: peer=[10.108.2.102]:2049
kworker/u16:0-12 [001] ...1. 270.327048: xprt_lookup_rqst: peer=[10.108.2.102]:2049 xid=0x7b569c7a status=0
kworker/u16:0-12 [001] ...2. 270.327050: rpc_task_wakeup: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=0x6 status=0 timeout=15000 queue=xprt_pending
kworker/u16:0-12 [001] ..... 270.327054: xs_stream_read_request: peer=[10.108.2.102]:2049 xid=0x7b569c7a copied=988 reclen=988 offset=988
kworker/u16:0-12 [001] ..... 270.327055: xs_stream_read_data: peer=[10.108.2.102]:2049 err=-11 total=992
ls-969 [003] ..... 270.327062: rpc_task_sync_wake: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_status
ls-969 [003] ..... 270.327062: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=xprt_timer
ls-969 [003] ..... 270.327063: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_status
ls-969 [003] ..... 270.327063: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=0 action=call_decode
ls-969 [003] ..... 270.327063: rpc_xdr_recvfrom: task:00000008@...00005 head=[0xffff8895c29fef64,140] page=4008(88) tail=[0xffff8895c29feff0,36] len=988
ls-969 [003] ..... 270.327067: rpc_xdr_overflow: task:00000008@...00005 nfsv4 READDIR requested=8 p=0xffff8895c29fefec end=0xffff8895c29feff0 xdr=[0xffff8895c29fef64,140]/4008/[0xffff8895c29feff0,36]/988
ls-969 [003] ..... 270.327068: rpc_task_run_action: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=-5 action=rpc_exit_task
ls-969 [003] ..... 270.327068: rpc_task_end: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=-5 action=rpc_exit_task
ls-969 [003] ..... 270.327068: rpc_stats_latency: task:00000008@...00005 xid=0x7b569c7a nfsv4 READDIR backlog=7 rtt=110 execute=137 xprt_id=1
ls-969 [003] ..... 270.327068: rpc_task_call_done: task:00000008@...00005 flags=MOVEABLE|DYNAMIC|SENT|NORTO|CRED_NOREF runstate=RUNNING|0x4 status=-5 action=nfs41_call_sync_done
ls-969 [003] ..... 270.327068: nfs4_sequence_done: error=0 (OK) session=0x5988ad3c slot_nr=0 seq_nr=26 highest_slotid=63 target_highest_slotid=63 status_flags=0x0 ()
ls-969 [003] ...1. 270.327069: xprt_release_xprt: task:00000008@...00005 snd_task:ffffffff
ls-969 [003] ...1. 270.327070: nfs_set_cache_invalid: error=0 (OK) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x4 (INVALID_ATIME) nfs_flags=0x4 (ACL_LRU_SET)
ls-969 [003] ..... 270.327070: nfs4_readdir: error=-5 (EIO) fileid=00:2d:262146 fhandle=0xad8c294c
ls-969 [003] ..... 270.327071: nfs_readdir_cache_fill_done: error=-5 (IO) fileid=00:2d:262146 fhandle=0xad8c294c type=4 (DIR) version=31 size=4096 cache_validity=0x4 (INVALID_ATIME) nfs_flags=0x4 (ACL_LRU_SET)
TWR
Powered by blists - more mailing lists