RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 654198 - CIFS needs to gracefully handle unresponsive server
Summary: CIFS needs to gracefully handle unresponsive server
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: kernel
Version: 6.1
Hardware: Unspecified
OS: Unspecified
low
medium
Target Milestone: rc
: ---
Assignee: Jeff Layton
QA Contact: Jian Li
URL:
Whiteboard:
: 626291 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-11-17 06:48 UTC by Luming Yu
Modified: 2014-06-18 07:40 UTC (History)
10 users (show)

Fixed In Version: kernel-2.6.32-168.el6
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-12-06 12:35:23 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2011:1530 0 normal SHIPPED_LIVE Moderate: Red Hat Enterprise Linux 6 kernel security, bug fix and enhancement update 2011-12-06 01:45:35 UTC

Description Luming Yu 2010-11-17 06:48:48 UTC 
Description of problem:

I've got some CIFS debug info that can explain one error in run-cpycmp test
suite. In this type of failure,error number 112 does returned to user space
correctly.

Does it ring any bell to you?

The following is from the log of run-cpycmp test 

==================================================
root@bxbDB ~/cifs-test# grep 17021-145 *bxbdb*.log
SWNUM-bxbdb-17021.log:2010-11-10 03:24:45: ERROR: Could not open file
'/clients/all/client2/cpycmp_src/SWNUM-bxbdb-17021-145.srcdat' (errno=112, Host
is down)
==================================================================

The following is CIFS debug info related to above error:

=======================================================================
fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 200306711) rc = 0
fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 200306719 with uid: 0
fs/cifs/dir.c: parent inode = 0xffff881bb86de830 name is:
SWNUM-bxbdb-17021-145..
srcdat and dentry = 0xffff881bd0b03900
fs/cifs/dir.c: NULL inode in lookup
fs/cifs/dir.c: Full path: \cpycmp_src\SWNUM-bxbdb-17021-145.srcdat inode =
0x(nuu
ll)
fs/cifs/inode.c: Getting info on \cpycmp_src\SWNUM-bxbdb-17021-145.srcdat
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 158
fs/cifs/connect.c: rfc1002 length 0x8a
fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 672
fs/cifs/inode.c: cifs_revalidate_cache: inode 672 is unchanged
fs/cifs/inode.c: inode 0xffff881bd0ae4190 old_time=4327417569
new_time=4327493933
7
fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry (xid = 200306718) rc
==
 0
fs/cifs/inode.c: CIFS VFS: in cifs_revalidate_dentry as Xid: 200306720 with
uid::
 500
fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry (xid = 200306720) rc
==
 0
fs/cifs/connect.c: rfc1002 length 0xd8
fs/cifs/inode.c: looking for uniqueid=2079
fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 2079
fs/cifs/inode.c: cifs_revalidate_cache: inode 2079 is new
fs/cifs/inode.c: inode 0xffff881bb86de110 old_time=0 new_time=4327493997
fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 200306719) rc = 0
fs/cifs/file.c: CIFS VFS: in cifs_open as Xid: 200306721 with uid: 0
fs/cifs/file.c: inode = 0xffff881bb86de110 file flags are 0x8000 for
\cpycmp_srcc
\SWNUM-bxbdb-17021-145.srcdat
fs/cifs/transport.c: For smb_command 162
fs/cifs/transport.c: Sending smb:  total_len 170
fs/cifs/connect.c: rfc1002 length 0x6b
fs/cifs/file.c: inode unchanged on server
fs/cifs/inode.c: Getting info on \cpycmp_src\SWNUM-bxbdb-17021-145.srcdat
fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 2079
fs/cifs/inode.c: cifs_revalidate_cache: inode 2079 is unchanged
fs/cifs/inode.c: inode 0xffff881bb86de110 old_time=4327493997
new_time=4327493999
7
fs/cifs/file.c: Exclusive Oplock granted on inode ffff881bb86de110
fs/cifs/file.c: CIFS VFS: leaving cifs_open (xid = 200306721) rc = 0
fs/cifs/file.c: CIFS VFS: in cifs_user_read as Xid: 200306722 with uid: 0
fs/cifs/cifssmb.c: Reading 16384 bytes on fid 49152
fs/cifs/transport.c: For smb_command 46
fs/cifs/transport.c: Sending smb:  total_len 63
fs/cifs/connect.c: rfc1002 length 0x403f

fs/cifs/transport.c: Sending smb:  total_len 63
fs/cifs/connect.c: rfc1002 length 0x403f
fs/cifs/cifssmb.c: Reading 16384 bytes on fid 49152
fs/cifs/transport.c: For smb_command 46
fs/cifs/transport.c: Sending smb:  total_len 63
fs/cifs/connect.c: rfc1002 length 0x403f
fs/cifs/cifssmb.c: Reading 16384 bytes on fid 49152
fs/cifs/transport.c: For smb_command 46
fs/cifs/transport.c: Sending smb:  total_len 63
fs/cifs/connect.c: rfc1002 length 0x403f
fs/cifs/cifssmb.c: Reading 16384 bytes on fid 49152
fs/cifs/transport.c: For smb_command 46
fs/cifs/transport.c: Sending smb:  total_len 63
fs/cifs/connect.c: rfc1002 length 0x403f
fs/cifs/file.c: CIFS VFS: leaving cifs_user_read (xid = 200306722) rc = 0
fs/cifs/file.c: CIFS VFS: in cifs_writepages as Xid: 200306723 with uid: 0
fs/cifs/file.c: CIFS VFS: leaving cifs_writepages (xid = 200306723) rc = 0
fs/cifs/file.c: Flush inode ffff881bb86de110 file ffff881be2a448c0 rc 0
fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 200306724 with uid: 0
fs/cifs/cifssmb.c: In CIFSSMBClose
fs/cifs/transport.c: For smb_command 4
fs/cifs/transport.c: Sending smb:  total_len 45
CIFS VFS: tcpStatus = 1
fs/cifs/transport.c: For smb_command 46
fs/cifs/transport.c: Sending smb:  total_len 63
fs/cifs/connect.c: rfc1002 length 0x403f
fs/cifs/file.c: CIFS VFS: leaving cifs_user_read (xid = 200306722) rc = 0
fs/cifs/file.c: CIFS VFS: in cifs_writepages as Xid: 200306723 with uid: 0
fs/cifs/file.c: CIFS VFS: leaving cifs_writepages (xid = 200306723) rc = 0
fs/cifs/file.c: Flush inode ffff881bb86de110 file ffff881be2a448c0 rc 0
fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 200306724 with uid: 0
fs/cifs/cifssmb.c: In CIFSSMBClose
fs/cifs/transport.c: For smb_command 4
fs/cifs/transport.c: Sending smb:  total_len 45
CIFS VFS: tcpStatus = 1

CIFS VFS: tcpStatus = 1

CIFS VFS: No response for cmd 162 mid 32404
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Error in Open = -11
CIFS VFS: No response for cmd 50 mid 32403
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/connect.c: Reconnect after server stopped responding
fs/cifs/connect.c: Reconnecting tcp session
fs/cifs/connect.c: State: 0x3 Flags: 0x0
fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
fs/cifs/connect.c: Socket created
fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
fs/cifs/connect.c: call to reconnect done
CIFS VFS: tcpStatus = 1

fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: For smb_command 114
fs/cifs/transport.c: Sending smb:  total_len 82
fs/cifs/connect.c: rfc1002 length 0x7b
fs/cifs/cifssmb.c: Dialect: 2
fs/cifs/cifssmb.c: Max buf = 16472
fs/cifs/cifssmb.c: negprot rc 0
fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x1e3fc TimeAdjust: 28800
fs/cifs/sess.c: sess setup type 1
fs/cifs/transport.c: For smb_command 115
fs/cifs/transport.c: Sending smb:  total_len 246
fs/cifs/connect.c: rfc1002 length 0xd3
fs/cifs/transport.c: Sending smb:  total_len 246
fs/cifs/connect.c: rfc1002 length 0xd3
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/sess.c: ssetup rc from sendrecv2 is 0
fs/cifs/sess.c: UID = 6145
fs/cifs/sess.c: bleft 165
fs/cifs/sess.c: serverOS=Windows Server 2008 R2 Standard 7600
fs/cifs/sess.c: serverNOS=Windows Server 2008 R2 Standard 6.1
fs/cifs/sess.c: serverDomain=WORKGROUP
fs/cifs/sess.c: ssetup freeing small buf ffff881bde9fd9c0
fs/cifs/connect.c: CIFS Session Established successfully
fs/cifs/transport.c: For smb_command 117
fs/cifs/transport.c: Sending smb:  total_len 86
fs/cifs/connect.c: rfc1002 length 0x42
fs/cifs/connect.c: disk share connection
fs/cifs/connect.c: nativeFileSystem=NTFS
fs/cifs/connect.c: Tcon flags: 0x1
fs/cifs/cifssmb.c: reconnect tcon rc = 0
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 160
fs/cifs/transport.c: For smb_command 162
fs/cifs/transport.c: Sending smb:  total_len 172
CIFS VFS: No response to cmd 4 mid 32412
fs/cifs/transport.c: Sending smb:  total_len 172
CIFS VFS: No response to cmd 4 mid 32412
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/transport.c: SendRcvNoRsp flags 64 rc -11
CIFS VFS: Send error in Close = -11
fs/cifs/file.c: closing last open instance for inode ffff881bb86de110
fs/cifs/file.c: CIFS VFS: leaving cifs_close (xid = 200306724) rc = 0
fs/cifs/inode.c: CIFS VFS: in cifs_revalidate_dentry as Xid: 200306725 with
uid::
 0
fs/cifs/inode.c: Revalidate: \cpycmp_src inode 0xffff881bb86de830 count 1
dentryy
: 0xffff881b7d722e40 d_time 4327493997 jiffies 4327501009
fs/cifs/inode.c: Getting info on \cpycmp_src
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 100
fs/cifs/connect.c: rfc1002 length 0x9e
fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 2078
fs/cifs/inode.c: cifs_revalidate_cache: inode 2078 is unchanged
fs/cifs/inode.c: inode 0xffff881bb86de830 old_time=4327493937
new_time=4327501200
8
fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry (xid = 200306725) rc
==
 0
fs/cifs/inode.c: inode 0xffff881bb86de830 old_time=4327493937
new_time=4327501200
8
fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry (xid = 200306725) rc
==
 0
fs/cifs/inode.c: CIFS VFS: in cifs_revalidate_dentry as Xid: 200306726 with
uid::
 0
fs/cifs/inode.c: Revalidate: \cpycmp_src\SWNUM-bxbdb-17021-145.srcdat inode
0xfff
ff881bb86de110 count 1 dentry: 0xffff881bd0b03900 d_time 4327493997 jiffies
43277
501208
fs/cifs/inode.c: Getting info on \cpycmp_src\SWNUM-bxbdb-17021-145.srcdat
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 158
CIFS VFS: tcpStatus = 1

CIFS VFS: tcpStatus = 1

CIFS VFS: No response for cmd 50 mid 32416
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
CIFS VFS: No response for cmd 162 mid 32417
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Error in Open = -11
fs/cifs/connect.c: Reconnect after server stopped responding
fs/cifs/connect.c: Reconnecting tcp session
fs/cifs/connect.c: State: 0x3 Flags: 0x0
fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
fs/cifs/connect.c: Socket created
fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
fs/cifs/connect.c: call to reconnect done
CIFS VFS: tcpStatus = 1

fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: For smb_command 114
fs/cifs/transport.c: Sending smb:  total_len 82
fs/cifs/connect.c: rfc1002 length 0x7b
fs/cifs/cifssmb.c: Dialect: 2
fs/cifs/cifssmb.c: Max buf = 16472
fs/cifs/cifssmb.c: negprot rc 0
fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x1e3fc TimeAdjust: 28800
fs/cifs/sess.c: sess setup type 1
fs/cifs/transport.c: For smb_command 115
fs/cifs/transport.c: Sending smb:  total_len 246

fs/cifs/transport.c: For smb_command 115
fs/cifs/transport.c: Sending smb:  total_len 246
fs/cifs/connect.c: rfc1002 length 0xd3
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/sess.c: ssetup rc from sendrecv2 is 0
fs/cifs/sess.c: UID = 6145
fs/cifs/sess.c: bleft 165
fs/cifs/sess.c: serverOS=Windows Server 2008 R2 Standard 7600
fs/cifs/sess.c: serverNOS=Windows Server 2008 R2 Standard 6.1
fs/cifs/sess.c: serverDomain=WORKGROUP
fs/cifs/sess.c: ssetup freeing small buf ffff881be6241140
fs/cifs/connect.c: CIFS Session Established successfully
fs/cifs/transport.c: For smb_command 117
fs/cifs/transport.c: Sending smb:  total_len 86
fs/cifs/connect.c: rfc1002 length 0x42
fs/cifs/connect.c: disk share connection
fs/cifs/connect.c: nativeFileSystem=NTFS
fs/cifs/connect.c: Tcon flags: 0x1
fs/cifs/cifssmb.c: reconnect tcon rc = 0
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 160
fs/cifs/transport.c: For smb_command 162
fs/cifs/transport.c: Sending smb:  total_len 172
fs/cifs/transport.c: For smb_command 162
fs/cifs/transport.c: Sending smb:  total_len 172
CIFS VFS: No response for cmd 50 mid 32419
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 158
CIFS VFS: tcpStatus = 1

CIFS VFS: tcpStatus = 1

CIFS VFS: No response for cmd 162 mid 32424
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Error in Open = -11
CIFS VFS: No response for cmd 50 mid 32423
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/connect.c: Reconnect after server stopped responding
fs/cifs/connect.c: Reconnecting tcp session
fs/cifs/connect.c: State: 0x3 Flags: 0x0

fs/cifs/connect.c: Reconnecting tcp session
fs/cifs/connect.c: State: 0x3 Flags: 0x0
fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
fs/cifs/connect.c: Socket created
fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
fs/cifs/connect.c: call to reconnect done
CIFS VFS: tcpStatus = 1

fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: For smb_command 114
fs/cifs/transport.c: Sending smb:  total_len 82
fs/cifs/connect.c: rfc1002 length 0x7b
fs/cifs/cifssmb.c: Dialect: 2
fs/cifs/cifssmb.c: Max buf = 16472
fs/cifs/cifssmb.c: negprot rc 0
fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x1e3fc TimeAdjust: 28800
fs/cifs/sess.c: sess setup type 1
fs/cifs/transport.c: For smb_command 115
fs/cifs/transport.c: Sending smb:  total_len 246
fs/cifs/connect.c: rfc1002 length 0xd3
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/sess.c: ssetup rc from sendrecv2 is 0
fs/cifs/sess.c: UID = 6146

fs/cifs/sess.c: ssetup rc from sendrecv2 is 0
fs/cifs/sess.c: UID = 6146
fs/cifs/sess.c: bleft 165
fs/cifs/sess.c: serverOS=Windows Server 2008 R2 Standard 7600
fs/cifs/sess.c: serverNOS=Windows Server 2008 R2 Standard 6.1
fs/cifs/sess.c: serverDomain=WORKGROUP
fs/cifs/sess.c: ssetup freeing small buf ffff881bfbb4ad40
fs/cifs/connect.c: CIFS Session Established successfully
fs/cifs/transport.c: For smb_command 117
fs/cifs/transport.c: Sending smb:  total_len 86
fs/cifs/connect.c: rfc1002 length 0x42
fs/cifs/connect.c: disk share connection
fs/cifs/connect.c: nativeFileSystem=NTFS
fs/cifs/connect.c: Tcon flags: 0x1
fs/cifs/cifssmb.c: reconnect tcon rc = 0
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 160
fs/cifs/transport.c: For smb_command 162
fs/cifs/transport.c: Sending smb:  total_len 172
CIFS VFS: No response for cmd 50 mid 32425
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11

fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 158
CIFS VFS: tcpStatus = 1

CIFS VFS: tcpStatus = 1

CIFS VFS: No response for cmd 162 mid 32430
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Error in Open = -11
CIFS VFS: No response for cmd 50 mid 32429
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/connect.c: Reconnect after server stopped responding
fs/cifs/connect.c: Reconnecting tcp session
fs/cifs/connect.c: State: 0x3 Flags: 0x0
fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
fs/cifs/connect.c: Socket created
fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
fs/cifs/connect.c: call to reconnect done
fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
fs/cifs/connect.c: call to reconnect done
CIFS VFS: tcpStatus = 1

fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: For smb_command 114
fs/cifs/transport.c: Sending smb:  total_len 82
fs/cifs/connect.c: rfc1002 length 0x7b
fs/cifs/cifssmb.c: Dialect: 2
fs/cifs/cifssmb.c: Max buf = 16472
fs/cifs/cifssmb.c: negprot rc 0
fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x1e3fc TimeAdjust: 28800
fs/cifs/sess.c: sess setup type 1
fs/cifs/transport.c: For smb_command 115
fs/cifs/transport.c: Sending smb:  total_len 246
fs/cifs/connect.c: rfc1002 length 0xd3
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/sess.c: ssetup rc from sendrecv2 is 0
fs/cifs/sess.c: UID = 6144
fs/cifs/sess.c: bleft 165
fs/cifs/sess.c: serverOS=Windows Server 2008 R2 Standard 7600
fs/cifs/sess.c: serverNOS=Windows Server 2008 R2 Standard 6.1
fs/cifs/sess.c: serverDomain=WORKGROUP
fs/cifs/sess.c: serverNOS=Windows Server 2008 R2 Standard 6.1
fs/cifs/sess.c: serverDomain=WORKGROUP
fs/cifs/sess.c: ssetup freeing small buf ffff881bdcf334c0
fs/cifs/connect.c: CIFS Session Established successfully
fs/cifs/transport.c: For smb_command 117
fs/cifs/transport.c: Sending smb:  total_len 86
fs/cifs/connect.c: rfc1002 length 0x42
fs/cifs/connect.c: disk share connection
fs/cifs/connect.c: nativeFileSystem=NTFS
fs/cifs/connect.c: Tcon flags: 0x1
fs/cifs/cifssmb.c: reconnect tcon rc = 0
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 160
fs/cifs/transport.c: For smb_command 162
fs/cifs/transport.c: Sending smb:  total_len 172
CIFS VFS: No response for cmd 50 mid 32431
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 158
CIFS VFS: tcpStatus = 1
CIFS VFS: tcpStatus = 1

CIFS VFS: tcpStatus = 1

CIFS VFS: No response for cmd 162 mid 32436
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Error in Open = -11
CIFS VFS: No response for cmd 50 mid 32435
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
fs/cifs/connect.c: Reconnect after server stopped responding
fs/cifs/connect.c: Reconnecting tcp session
fs/cifs/connect.c: State: 0x3 Flags: 0x0
fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
fs/cifs/connect.c: Socket created
fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
fs/cifs/connect.c: call to reconnect done
CIFS VFS: tcpStatus = 1

fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: For smb_command 114
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: For smb_command 114
fs/cifs/transport.c: Sending smb:  total_len 82
CIFS VFS: No response for cmd 50 mid 32437
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: Send error in QPathInfo = -11
CIFS VFS: tcpStatus = 1

CIFS VFS: No response for cmd 114 mid 32438
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
CIFS VFS: Unexpected lookup error -112
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/file.c: cifs_open returned 0xffffff90
fs/cifs/file.c: oplock: 2
fs/cifs/file.c: CIFS VFS: leaving cifs_reopen_file (xid = 200306717) rc = -112
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/file.c: CIFS VFS: leaving cifs_user_write (xid = 200233911) rc = -112
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry (xid = 200306726) rc
==
 -112
fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 200306727 with uid: 0
fs/cifs/dir.c: parent inode = 0xffff881bb86de830 name is:
SWNUM-bxbdb-17021-145..
srcdat and dentry = 0xffff881b8f9b4180
fs/cifs/dir.c: NULL inode in lookup
fs/cifs/dir.c: Full path: \cpycmp_src\SWNUM-bxbdb-17021-145.srcdat inode =
0x(nuu
ll)
fs/cifs/inode.c: Getting info on \cpycmp_src\SWNUM-bxbdb-17021-145.srcdat
fs/cifs/file.c: CIFS VFS: in cifs_writepages as Xid: 200306728 with uid: 0
fs/cifs/file.c: CIFS VFS: leaving cifs_writepages (xid = 200306728) rc = 0
fs/cifs/file.c: CIFS VFS: in cifs_writepages as Xid: 200306728 with uid: 0
fs/cifs/file.c: CIFS VFS: leaving cifs_writepages (xid = 200306728) rc = 0
fs/cifs/file.c: Flush inode ffff881bb86de5d0 file ffff881be36e7180 rc 0
fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 200306729 with uid: 0
fs/cifs/cifssmb.c: In CIFSSMBClose
fs/cifs/transport.c: For smb_command 4
fs/cifs/transport.c: Sending smb:  total_len 45
fs/cifs/connect.c: rfc1002 length 0x27
fs/cifs/transport.c: SendRcvNoRsp flags 64 rc 0
fs/cifs/file.c: closing last open instance for inode ffff881bb86de5d0
fs/cifs/file.c: CIFS VFS: leaving cifs_close (xid = 200306729) rc = 0
fs/cifs/file.c: CIFS VFS: in cifs_writepages as Xid: 200306730 with uid: 0
fs/cifs/file.c: CIFS VFS: leaving cifs_writepages (xid = 200306730) rc = 0
fs/cifs/file.c: Flush inode ffff881bb010e7f0 file ffff881be07d9e40 rc 0
fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 200306731 with uid: 0
fs/cifs/file.c: closing last open instance for inode ffff881bb010e7f0
fs/cifs/file.c: CIFS VFS: leaving cifs_close (xid = 200306731) rc = 0
fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 200306710) rc = -112
fs/cifs/connect.c: Reconnect after server stopped responding
fs/cifs/connect.c: Reconnecting tcp session
fs/cifs/connect.c: State: 0x3 Flags: 0x0
fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
fs/cifs/connect.c: Socket created
fs/cifs/connect.c: Post shutdown state: 0x3 Flags: 0x0
fs/cifs/connect.c: Socket created
fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
fs/cifs/connect.c: call to reconnect done
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: For smb_command 114
fs/cifs/transport.c: Sending smb:  total_len 82
fs/cifs/cifsfs.c: CIFS VFS: in cifs_statfs as Xid: 200306732 with uid: 500
fs/cifs/cifssmb.c: In QFSInfo
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 72
fs/cifs/connect.c: rfc1002 length 0x54
fs/cifs/cifssmb.c: Blocks: 48127789  Free: 47908432 Block size 4096
fs/cifs/cifsfs.c: CIFS VFS: leaving cifs_statfs (xid = 200306732) rc = 0
fs/cifs/inode.c: CIFS VFS: in cifs_revalidate_dentry as Xid: 200306733 with
uid::
 500
fs/cifs/inode.c: Revalidate:  inode 0xffff881bd0ae4d70 count 2 dentry:
0xffff8811
b96829a40 d_time 4300666434 jiffies 4327537575
fs/cifs/inode.c: Getting info on
fs/cifs/transport.c: For smb_command 50
fs/cifs/transport.c: Sending smb:  total_len 78
fs/cifs/connect.c: rfc1002 length 0x8a
fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 671
fs/cifs/connect.c: rfc1002 length 0x8a
fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 671
fs/cifs/inode.c: cifs_revalidate_cache: inode 671 is unchanged
fs/cifs/inode.c: inode 0xffff881bd0ae4d70 old_time=4327477572
new_time=4327537577
5
fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry (xid = 200306733) rc
==
 0
fs/cifs/inode.c: CIFS VFS: in cifs_revalidate_dentry as Xid: 200306734 with
uid::
 500
fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry (xid = 200306734) rc
==
 0
fs/cifs/cifsfs.c: CIFS VFS: in cifs_statfs as Xid: 200306735 with uid: 500
fs/cifs/cifssmb.c: In QFSInfo
CIFS VFS: tcpStatus = 1

CIFS VFS: No response for cmd 114 mid 32444
fs/cifs/transport.c: marking request for retry
fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
CIFS VFS: Unexpected lookup error -112

fs/cifs/cifssmb.c: negprot rc -11
CIFS VFS: Unexpected lookup error -112
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/cifssmb.c: secFlags 0x7
fs/cifs/transport.c: tcp session dead - return to caller to retry
fs/cifs/cifssmb.c: negprot rc -11
fs/cifs/cifssmb.c: OldQFSInfo
fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 200306727) rc = -112

[reply] [-] Comment 43 Jeff Layton 2010-11-10 10:09:29 EST

The CIFS client code will return EHOSTDOWN in some situations, usually relating
to a reconnect attempt failure.

[reply] [-] Comment 44 Luming Yu 2010-11-10 10:24:04 EST

(In reply to comment #43)
> The CIFS client code will return EHOSTDOWN in some situations, usually relating
> to a reconnect attempt failure.

Do you think the test case mentioned in comment# 42 should find a better way to
handle EHOSTDOWN rather than exploding?

[reply] [-] Comment 45 Jeff Layton 2010-11-10 13:56:51 EST

That's really a better question for Intel, given that it's their test program.

[reply] [-] Comment 46 Jeff Layton 2010-11-10 14:20:22 EST

Now that said... EHOSTDOWN isn't a valid return code for open(). So that's
clearly a bug. I suppose we could translate that to something else, but I doubt
that'll make this program any happier.

I think the root cause of all of this is likely poor handling of timeouts and
reconnects in the lower layers of the cifs code. But, until we have a more
well-defined problem phrased in terms of what's happening at the system call
layer, we won't be able to make much progress on solving this.

Once we have that, there's still likely a substantial amount of upstream work
involved. I believe that large swaths of the socket handling code in cifs will
need to be rewritten.

[reply] [-] Comment 48 Jeff Layton 2010-11-12 10:59:05 EST

One thing that you may want to play with is the patchset for bug 629085. It's
not clear to me that it'll fix this case, but may prevent some problems seen
when there are problems establishing sessions with the server while mounting.

In the meantime, I've started some work on a project to clean up timeout
handling in cifs. I doubt that it'll be ready in time for 6.1, but once I have
something I'll try to post it here so that you can test it. I suspect that
that's the root cause of the problem here, but until we have a better defined
test case I can't do much more than guess.

[reply] [-] Comment 49 Jeff Layton 2010-11-12 16:41:53 EST

Created attachment 460156 [details]
patch -- experimental, don't reconnect on call timeouts

Here's an experimental, proof-of-concept patch:

It changes the code in a significant way such that it'll always wait
indefinitely for calls to complete (though it does make them TASK_KILLABLE, so
they shouldn't hang on SIGKILLs).

The idea here is to make the client more resilient in the face of a
bogged-down, unresponsive server. If the server really goes unresponsive
however, then the client will probably hang. Please test this using the "hard"
mount option, though I don't think you want to use any of the other ones that
Luming mentioned earlier.

Lightly tested -- passes connectathon tests, but don't let it near any
important data. I'll be interested if it helps the tests to pass. If it does,
then it'll tell us we're on the right track as to what the problem is, though
it's not a complete solution in and of itself...

[reply] [-] Comment 50 Luming Yu 2010-11-15 01:04:05 EST

(In reply to comment #49)
> Created attachment 460156 [details] [details]
> patch -- experimental, don't reconnect on call timeouts
> 
> Here's an experimental, proof-of-concept patch:

Hmm.. interesting thing to try.

> 
> It changes the code in a significant way such that it'll always wait
> indefinitely for calls to complete (though it does make them TASK_KILLABLE, so
> they shouldn't hang on SIGKILLs).

We can't assume how server would handle clients requests in all possible
situations that server could have to handle.Is it possible to get a quick POC
patch that can re-try *forever* in calls? Have you already had it in the POC
patch, or we need to test a new patch?


> 
> The idea here is to make the client more resilient in the face of a
> bogged-down, unresponsive server. If the server really goes unresponsive
> however, then the client will probably hang. Please test this using the "hard"
> mount option, though I don't think you want to use any of the other ones that
> Luming mentioned earlier.

how to handle unresponsive server is hard.

> 
> Lightly tested -- passes connectathon tests, but don't let it near any
> important data. I'll be interested if it helps the tests to pass. If it does,
> then it'll tell us we're on the right track as to what the problem is, though
> it's not a complete solution in and of itself...

I'm testing it right now...

[reply] [-] Comment 51 Luming Yu 2010-11-15 04:25:56 EST

After running over 3 hours, nothing errors found so far, not seen any kind of
hang so far.. It's definitely a good sign that we are on track..

[reply] [-] Comment 52 Jeff Layton 2010-11-15 08:58:14 EST

> > 
> > It changes the code in a significant way such that it'll always wait
> > indefinitely for calls to complete (though it does make them TASK_KILLABLE, so
> > they shouldn't hang on SIGKILLs).
> 
> We can't assume how server would handle clients requests in all possible
> situations that server could have to handle.Is it possible to get a quick POC
> patch that can re-try *forever* in calls? Have you already had it in the POC
> patch, or we need to test a new patch?
> 
> 

That's essentially what this patch does, but it doesn't try to retransmit
packets until the socket has to be reconnected. Doing so could be very
problematic on non-idempotent calls. We don't really need to continually retry
calls like that since we're on a connection-oriented socket. We only want to
retry a call when the socket needs to be reconnected.

The problem is handling the situation where the socket still seems to be
connected, but the server isn't responding. How do we tell whether the server
is really not responding or just taking a long time to service a call? For
instance, writes past the end of a file can take a very long time on windows
servers.

What we'll want to do eventually is something like this:

When we send a call to the server, we'll start a timer. If the server doesn't
respond within a certain amount of time, we'll send it an SMB echo call. The
server should respond to that fairly quickly, but if it doesn't we'll send
another a little later. We'll do that for several calls.

If none of the echoes get a response or the socket ends up disconnected, then
we'll reconnect the socket.

Implementing that however is a little difficult as the underlying socket code
in cifs is not well equipped for asynchronous calls (which is needed to
properly handle the echo requests).
Comment 2 Jeff Layton 2010-11-17 12:08:35 UTC 
Thanks. We can leave this on the 6.1 proposed list for now, but I really doubt that it will make it. This is more likely 6.2 material. The changes needed here are substantial and are in some rather sensitive code. We'll probably need them to go upstream for a little while before we can reasonably pull them into RHEL.
Comment 4 Jeff Layton 2010-11-23 20:59:14 UTC 
*** Bug 626291 has been marked as a duplicate of this bug. ***
Comment 6 RHEL Program Management 2011-05-26 14:49:39 UTC 
This request was evaluated by Red Hat Product Management for inclusion
in a Red Hat Enterprise Linux maintenance release. Product Management has 
requested further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed 
products. This request is not yet committed for inclusion in an Update release.
Comment 8 Jeff Layton 2011-06-22 18:03:09 UTC 
Luming, it's been a while since we've looked at this, but do you have the ability to test some kernels for this bug?
Comment 10 Luming Yu 2011-06-24 12:58:33 UTC 
Jima,

Do you have interests in testing some kernels for run-cpycmp test
suite failure we worked about 6 months ago?

Thanks,
Luming
Comment 11 Kyle McMartin 2011-07-13 23:00:43 UTC 
Patch(es) available on kernel-2.6.32-168.el6
Comment 14 errata-xmlrpc 2011-12-06 12:35:23 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHSA-2011-1530.html
Note You need to log in before you can comment on or make changes to this bug.