Bug 197311

Summary: CIFS: mount.cifs stopped working with the Windows 10 Pro 15063 SMB server
Product: File System Reporter: Jaroslav Škarvada (jskarvad)
Component: CIFSAssignee: fs_cifs (fs_cifs)
Status: RESOLVED CODE_FIX    
Severity: normal CC: cesar.infoo, jeremy, nathan.renniewaldock+kernelbugs, rkudyba, smfrench
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 4.13.5 Subsystem:
Regression: No Bisected commit-id:

Description Jaroslav Škarvada 2017-10-18 08:47:15 UTC
Downstream Fedora bugzilla report:
https://bugzilla.redhat.com/show_bug.cgi?id=1502606

The mount.cifs doesn't work with the default protocol, which is now negotiated as SMB3.02 (i.e. it stopped working with the default configuration), but it works with the SMB2.1. The problem manifests as the Windows server doing connection reset after the FSCTL_VALIDATE_NEGOTIATE_INFO request.

Server is Windows 10 Pro 15063 (i.e. OS=[Windows 10 Pro 15063] Server=[Windows 10 Pro 6.3]), no domain, with nearly default config, IIRC the only tweak there is enabled admin shares. It's Czech language variant. The server supports SMB3.1.1 dialect but the CONFIG_CIFS_SMB311 options is not set in the downstream Linux kernel. Enabling it and recompiling the kernel CIFS module didn't help.

The following command fails:
# mount -t cifs //192.168.1.2/C\$ /mnt/win_c -o username=user --verbose
mount.cifs kernel mount options: ip=192.168.1.2,unc=\\192.168.1.2\C$,user=user,pass=*
mount error(13): Permission denied
Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)

With enforced 2.1 dialect it works (probably because the FSCTL_VALIDATE_NEGOTIATE_INFO is not called), i.e. the following works:
# mount -t cifs //192.168.1.2/C\$ /mnt/win_c -o username=user,vers=2.1 --verbose

Also the smbclient works, probably because it doesn't use SMB3 by default.

Dmesg output:
[ 6296.754518] FS-Cache: Netfs 'cifs' registered for caching
[ 6296.754634] Key type cifs.spnego registered
[ 6296.754637] Key type cifs.idmap registered
[ 6296.755054] No dialect specified on mount. Default has changed to a more secu
re dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secur
e SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) speci
fy vers=1.0 on mount.
[ 6297.093312] CIFS VFS: validate protocol negotiate failed: -11
[ 6297.095360] CIFS VFS: cifs_mount failed w/return code = -5

Dmesg output with the kernel CIFS module recompiled with the all the debugging information enabled:

[58014.081891] No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount.
[58014.081898] CIFS VFS: Username: user
[58014.081905] CIFS VFS: file mode: 0x1ed  dir mode: 0x1ed
[58014.081912] CIFS VFS: CIFS VFS: in cifs_mount as Xid: 0 with uid: 0
[58014.081917] CIFS VFS: UNC: \\192.168.1.2\C$
[58014.081946] CIFS VFS: Socket created
[58014.081950] CIFS VFS: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
[58014.084062] CIFS VFS: cifs_fscache_get_client_cookie: (0xffff8c2978906800/0xffff8c2ac514a9a0)
[58014.084073] CIFS VFS: CIFS VFS: in cifs_get_smb_ses as Xid: 1 with uid: 0
[58014.084076] CIFS VFS: Existing smb sess not found
[58014.084082] CIFS VFS: Demultiplex PID: 10297
[58014.084090] CIFS VFS: Negotiate protocol
[58014.084099] CIFS VFS: Sending smb: smb_len=106
[58014.088013] CIFS VFS: RFC1002 header 0x1c0
[58014.088032] CIFS VFS: smb2_check_message length: 0x1c4, smb_buf_length: 0x1c0
[58014.088038] CIFS VFS: SMB2 data length 320 offset 128
[58014.088041] CIFS VFS: SMB2 len 452
[58014.088086] CIFS VFS: cifs_sync_mid_result: cmd=0 mid=0 state=4
[58014.088097] CIFS VFS: mode 0x1
[58014.088099] CIFS VFS: negotiated smb3.02 dialect
[58014.088107] CIFS VFS: OID len = 10 oid = 0x1 0x3 0x6 0x1
[58014.088110] CIFS VFS: OID len = 10 oid = 0x1 0x3 0x6 0x1
[58014.088115] CIFS VFS: Security Mode: 0x1 Capabilities: 0x300047 TimeAdjust: 0
[58014.088118] CIFS VFS: Session Setup
[58014.088120] CIFS VFS: sess setup type 4
[58014.088126] CIFS VFS: Sending smb: smb_len=120
[58014.091380] CIFS VFS: RFC1002 header 0xd2
[58014.091394] CIFS VFS: smb2_check_message length: 0xd6, smb_buf_length: 0xd2
[58014.091398] CIFS VFS: SMB2 data length 138 offset 72
[58014.091400] CIFS VFS: SMB2 len 214
[58014.091438] CIFS VFS: cifs_sync_mid_result: cmd=1 mid=1 state=4
[58014.091447] CIFS VFS: Mapping SMB2 status code 0xc0000016 to POSIX err -5
[58014.091450] CIFS VFS: Null buffer passed to cifs_small_buf_release
[58014.091455] CIFS VFS: rawntlmssp session setup challenge phase
[58014.091510] CIFS VFS: Sending smb: smb_len=296
[58014.095924] CIFS VFS: RFC1002 header 0x48
[58014.095939] CIFS VFS: smb2_check_message length: 0x4c, smb_buf_length: 0x48
[58014.095944] CIFS VFS: SMB2 data length 0 offset 72
[58014.095948] CIFS VFS: SMB2 len 77
[58014.095952] CIFS VFS: Calculated size 77 length 76 mismatch mid 2
[58014.095999] CIFS VFS: cifs_sync_mid_result: cmd=1 mid=2 state=4
[58014.096006] CIFS VFS: Null buffer passed to cifs_small_buf_release
[58014.096086] CIFS VFS: SMB2/3 session established successfully
[58014.096101] CIFS VFS: CIFS VFS: leaving cifs_get_smb_ses (xid = 1) rc = 0
[58014.096108] CIFS VFS: CIFS VFS: in cifs_get_tcon as Xid: 2 with uid: 0
[58014.096111] CIFS VFS: TCON
[58014.096119] CIFS VFS: Sending smb: smb_len=106
[58014.097956] CIFS VFS: RFC1002 header 0x50
[58014.097969] CIFS VFS: smb2_check_message length: 0x54, smb_buf_length: 0x50
[58014.097973] CIFS VFS: SMB2 len 84
[58014.098023] CIFS VFS: cifs_sync_mid_result: cmd=3 mid=3 state=4
[58014.098031] CIFS VFS: Null buffer passed to cifs_small_buf_release
[58014.098037] CIFS VFS: connection to disk share
[58014.098041] CIFS VFS: validate negotiate
[58014.098044] CIFS VFS: SMB2 IOCTL
[58014.098049] CIFS VFS: Sending smb: smb_len=150
[58014.099152] CIFS VFS: Received no data or error: -104
[58014.099158] CIFS VFS: Reconnecting tcp session
[58014.099163] CIFS VFS: cifs_reconnect: marking sessions and tcons for reconnect
[58014.099167] CIFS VFS: cifs_reconnect: tearing down socket
[58014.099171] CIFS VFS: State: 0x3 Flags: 0x0
[58014.099177] CIFS VFS: Post shutdown state: 0x3 Flags: 0x0
[58014.099199] CIFS VFS: cifs_reconnect: moving mids to private list
[58014.099203] CIFS VFS: cifs_reconnect: issuing mid callbacks
[58014.099228] CIFS VFS: Socket created
[58014.099232] CIFS VFS: cifs_sync_mid_result: cmd=11 mid=4 state=8
[58014.099235] CIFS VFS: Null buffer passed to cifs_small_buf_release
[58014.099240] CIFS VFS: validate protocol negotiate failed: -11
[58014.099244] CIFS VFS: CIFS VFS: leaving cifs_get_tcon (xid = 2) rc = -5
[58014.099247] CIFS VFS: Tcon rc = -5
...

It seems the connection is reset by peer (error 104 from the underlying sock_recvmsg) when calling FSCTL_VALIDATE_NEGOTIATE_INFO. It seems it's reset by the server. Firewalls are disabled on both Linux client and Windows server.

The tcpdump confirms the connection is reset by the Windows server:
240	128.715022	192.168.1.6	192.168.1.2	SMB2	366	Session Setup Request, NTLMSSP_AUTH, User: \user
241	128.717994	192.168.1.2	192.168.1.6	SMB2	142	Session Setup Response
242	128.720375	192.168.1.6	192.168.1.2	SMB2	176	Tree Connect Request Tree: \\192.168.1.2\C$
243	128.721110	192.168.1.2	192.168.1.6	SMB2	150	Tree Connect Response
244	128.723624	192.168.1.6	192.168.1.2	SMB2	220	Ioctl Request FSCTL_VALIDATE_NEGOTIATE_INFO
245	128.723991	192.168.1.2	192.168.1.6	TCP	60	445 → 35848 [RST, ACK] Seq=827 Ack=799 Win=0 Len=0

I have no idea why it happens. It maybe related to error:
[ 8185.240840] CIFS VFS: cifs_mount failed w/return code = -112
which I wasn't able to reproduce but is reported by some other users. And also the failure: negotiation failed: NT_STATUS_CONNECTION_RESET could be related.

I am going to check this with my other Windows 10 machines.

I can provide full TCP dumps if you are interested.
Comment 1 Jaroslav Škarvada 2017-10-18 08:49:09 UTC
Max supported SMB dialect on the server is 3.1.1 as shown by the 'Get-SmbConnection' PowerShell command on the server if doing SMB connection to itself (which works OK).
Comment 2 Jeremy Cline 2017-10-18 17:15:49 UTC
The issue started in 4.13 with https://marc.info/?l=linux-kernel&m=150703479427738&w=2 which is upstream commit 0603c96f3af50e2f9299fa410c224ab1d465e0f9.
Comment 3 Jaroslav Škarvada 2017-10-19 09:06:53 UTC
(In reply to Jeremy Cline from comment #2)
> The issue started in 4.13 with
> https://marc.info/?l=linux-kernel&m=150703479427738&w=2 which is upstream
> commit 0603c96f3af50e2f9299fa410c224ab1d465e0f9.

Thanks for info, I will try to recompile with this patch reverted and I will re-check.
Comment 4 Jaroslav Škarvada 2017-10-19 21:38:28 UTC
(In reply to Jaroslav Škarvada from comment #3)
> (In reply to Jeremy Cline from comment #2)
> > The issue started in 4.13 with
> > https://marc.info/?l=linux-kernel&m=150703479427738&w=2 which is upstream
> > commit 0603c96f3af50e2f9299fa410c224ab1d465e0f9.
> 
> Thanks for info, I will try to recompile with this patch reverted and I will
> re-check.

I can confirm that reverting the patch fixes the problem for me.
Comment 6 Jeremy Cline 2017-10-26 18:32:25 UTC
I tested that on top of 4.13.9 and it works for me.
Comment 7 Nathan R 2017-10-26 20:27:11 UTC
Applying that patch to v4.13.5 also fixed it for me.
Comment 8 RobbieTheK 2017-11-01 19:26:04 UTC
This doesn't seem to fix error: 12. Or at least I don't know where else I can add the vers=1.0 option as I noted in this SF thread: https://serverfault.com/questions/881260/no-dialect-specified-on-mount-error-where-to-set-vers-1-0-with-autofs-fedora-26

Here are the debug-enabled autofs logs from our server and Drobo FS which only supports SMB1:
Oct 31 16:12:20 workstation automount[5234]: handle_packet_missing_indirect: token 508, name drobo-down, request pid 10165
Oct 31 16:12:20 workstation automount[5234]: attempting to mount entry /drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: lookup_mount: lookup(yp): looking up drobo-down
Oct 31 16:12:20 workstation automount[5234]: lookup_mount: lookup(yp): drobo-down -> -fstype=cifs,rw,user,suid,credentials=/etc/auto.smb.drobo-up ://drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: parse_mount: parse(sun): expanded entry: -fstype=cifs,rw,user,suid,credentials=/etc/auto.smb.drobo-up ://drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: parse_mount: parse(sun): gathered options: fstype=cifs,rw,user,suid,credentials=/etc/auto.smb.drobo-up
Oct 31 16:12:20 workstation automount[5234]: parse_mount: parse(sun): dequote("://drobo-up/drobo-down") -> ://drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: parse_mount: parse(sun): core of entry: options=fstype=cifs,rw,user,suid,credentials=/etc/auto.smb.drobo-up, loc=://drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: sun_mount: parse(sun): mounting root /drobo-up, mountpoint drobo-down, what //drobo-up/drobo-down, fstype cifs, options rw,user,suid,credentials=/etc/auto.smb.drobo-up
Oct 31 16:12:20 workstation automount[5234]: do_mount: //drobo-up/drobo-down /drobo-up/drobo-down type cifs options rw,user,suid,credentials=/etc/auto.smb.drobo-up using module generic
Oct 31 16:12:20 workstation automount[5234]: mount_mount: mount(generic): calling mkdir_path /drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: mount_mount: mount(generic): calling mount -t cifs -o rw,user,suid,credentials=/etc/auto.smb.drobo-up //drobo-up/drobo-down /drobo-up/drobo-down
Oct 31 16:12:20 workstation kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount.
Oct 31 16:12:20 workstation automount[5234]: >> mount error(112): Host is down
Oct 31 16:12:20 workstation automount[5234]: >> Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)
Oct 31 16:12:20 workstation kernel: CIFS VFS: cifs_mount failed w/return code = -112
Oct 31 16:12:20 workstation automount[5234]: mount(generic): failed to mount //drobo-up/drobo-down (type cifs) on /drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: dev_ioctl_send_fail: token = 508
Oct 31 16:12:20 workstation automount[5234]: failed to mount /drobo-up/drobo-down
Oct 31 16:12:20 workstation automount[5234]: handle_packet: type = 3
Oct 31 16:12:20 workstation automount[5234]: handle_packet_missing_indirect: token 509, name drobo-down, request pid 10182
Oct 31 16:12:20 workstation automount[5234]: dev_ioctl_send_fail: token = 509
Oct 31 16:12:20 workstation automount[5234]: handle_packet: type = 3
Oct 31 16:12:20 workstation automount[5234]: handle_packet_missing_indirect: token 510, name drobo-down, request pid 10165
Oct 31 16:12:20 workstation automount[5234]: dev_ioctl_send_fail: token = 510
Comment 9 Jaroslav Škarvada 2017-12-27 17:16:40 UTC
This seems to be fixed in kernel-4.14.8 (maybe it was fixed in older version, but I tried only with the 4.14.8). I got the following in the dmesg:

[26016.028845] No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount.
[26016.058380] CIFS VFS: ioctl error in smb2_get_dfs_refer rc=-5

Despite the error in the log above it mounts without problem with default parameters, i.e. the following command now works for me:
# mount -t cifs //192.168.1.2/C\$ /mnt/win_c -o username=user --verbose

So I think this bug cang be closed.