Re: cifs.upcall requests ticket for wrong host when using dfs

[Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com>]

[-- Attachment #1: Type: text/plain, Size: 1519 bytes --]

Hi,

Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com> writes:

> I tried kernel 5.4.6, including this fix, but still no luck:
> [   25.825075] CIFS: Attempting to mount //domain.com/common
> [   27.127925] CIFS VFS:  BAD_NETWORK_NAME: \\domain.com\common
> [   31.406697] CIFS: Attempting to mount //DC01.domain.com/common/Pd_Std
> [   31.414527] srv rsp padded more than expected. Length 98 not 73 for cmd:1 mid:1
> [   31.414533] Status code returned 0xc000006d STATUS_LOGON_FAILURE
> [   31.414537] CIFS VFS: \\DC01.domain.com Send error in SessSetup = -13
> [   31.414544] CIFS VFS: cifs_mount failed w/return code = -13
> [   31.414590] CIFS: Attempting to mount //DC01.domain.com/common/Pd_Std
> [   31.422410] Status code returned 0xc000006d STATUS_LOGON_FAILURE
> [   31.422416] CIFS VFS: \\DC01.domain.com Send error in SessSetup = -13
> [   31.422423] CIFS VFS: cifs_mount failed w/return code = -13
>
> Where 4.19 prints:
> [  132.012498] CIFS: Attempting to mount //domain.com/common
> [  132.183038] CIFS VFS: error -2 on ioctl to get interface list
> [  132.344343] CIFS: Attempting to mount //nas01/common$/pd_std

> Thanks for testing it.
> 
> Could you post dmesg output of both versions with debugging enabled as per
> instructions in [1]?

I attached the traces for kernel 4.19 and 5.4, I try to access the subdirectory after the '=====' separator in the log.
I looks like in the past a different sesInfo was passed to cifs_get_spnego_key().

Regards, Martijn

[-- Attachment #2: dfs-4.19.67-autofs.log --]
[-- Type: application/octet-stream, Size: 21536 bytes --]

[   56.207911] fs/cifs/cifsfs.c: Devname: //prodrive.nl/product flags: 0
[   56.207943] fs/cifs/connect.c: Username: mdg
[   56.211337] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
[   56.211339] fs/cifs/connect.c: CIFS VFS: in cifs_mount as Xid: 0 with uid: 0
[   56.211340] fs/cifs/connect.c: UNC: \\prodrive.nl\product
[   56.211347] fs/cifs/connect.c: Socket created
[   56.211347] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x6d6
[   56.302277] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x0000000052b09517/0x00000000f1aba55a)
[   56.302281] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 1 with uid: 0
[   56.302281] fs/cifs/connect.c: Existing smb sess not found
[   56.302284] fs/cifs/smb2pdu.c: Negotiate protocol
[   56.302326] fs/cifs/transport.c: Sending smb: smb_len=106
[   56.302379] fs/cifs/connect.c: Demultiplex PID: 1540
[   56.392687] fs/cifs/connect.c: RFC1002 header 0xf8
[   56.392693] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[   56.392693] fs/cifs/smb2misc.c: SMB2 len 248
[   56.392702] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[   56.392706] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   56.392709] fs/cifs/smb2pdu.c: mode 0x3
[   56.392709] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[   56.392712] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   56.392712] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[   56.392713] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[   56.392714] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[   56.392715] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   56.392716] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
[   56.392717] fs/cifs/smb2pdu.c: Session Setup
[   56.392717] fs/cifs/smb2pdu.c: sess setup type 5
[   56.392720] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=prodrive.nl;ip4=10.122.0.3;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x600
[   56.427018] fs/cifs/transport.c: Sending smb: smb_len=6934
[   56.521252] fs/cifs/connect.c: RFC1002 header 0x5e
[   56.521258] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
[   56.521258] fs/cifs/smb2misc.c: SMB2 len 94
[   56.521267] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
[   56.521268] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   56.521279] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[   56.521283] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 1) rc = 0
[   56.521286] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 2 with uid: 0
[   56.521287] fs/cifs/smb2pdu.c: TCON
[   56.521297] fs/cifs/transport.c: Sending smb: smb_len=114
[   56.610840] fs/cifs/connect.c: RFC1002 header 0x50
[   56.610845] fs/cifs/smb2misc.c: SMB2 len 80
[   56.610855] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
[   56.610859] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   56.610861] fs/cifs/smb2ops.c: add 2 credits total=131
[   56.610862] fs/cifs/smb2pdu.c: connection to pipe share
[   56.610863] fs/cifs/smb2pdu.c: validate negotiate
[   56.610864] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   56.610872] fs/cifs/transport.c: Sending smb: smb_len=150
[   56.700312] fs/cifs/connect.c: RFC1002 header 0x88
[   56.700318] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[   56.700319] fs/cifs/smb2misc.c: SMB2 len 136
[   56.700327] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=3 state=4
[   56.700332] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   56.700334] fs/cifs/smb2ops.c: add 2 credits total=132
[   56.700335] fs/cifs/smb2pdu.c: validate negotiate info successful
[   56.700337] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 2) rc = 0
[   56.700338] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[   56.700340] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 3 with uid: 0
[   56.700341] fs/cifs/smb2pdu.c: TCON
[   56.700349] fs/cifs/transport.c: Sending smb: smb_len=120
[   56.790155] fs/cifs/connect.c: RFC1002 header 0x48
[   56.790161] fs/cifs/smb2misc.c: SMB2 len 73
[   56.790162] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 4
[   56.790171] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=4 state=4
[   56.790176] Status code returned 0xc00000cc STATUS_BAD_NETWORK_NAME
[   56.790179] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc00000cc to POSIX err -2
[   56.790179] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   56.790181] fs/cifs/smb2ops.c: add 2 credits total=133
[   56.790182] CIFS VFS: BAD_NETWORK_NAME: \\prodrive.nl\product
[   56.790185] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 3) rc = -2
[   56.790186] fs/cifs/connect.c: Tcon rc = -2
[   56.790188] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
[   56.790189] fs/cifs/smb2ops.c: smb2_get_dfs_refer path <\prodrive.nl\product>
[   56.790192] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   56.790199] fs/cifs/transport.c: Sending smb: smb_len=168
[   56.879977] fs/cifs/connect.c: RFC1002 header 0x178
[   56.879982] fs/cifs/smb2misc.c: SMB2 data length 264 offset 112
[   56.879983] fs/cifs/smb2misc.c: SMB2 len 376
[   56.879990] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=5 state=4
[   56.879997] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   56.879998] fs/cifs/smb2ops.c: add 2 credits total=134
[   56.880000] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
[   56.884589] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC03.Prodrive.nl to 10.1.1.3
[   56.884622] fs/cifs/connect.c: Username: mdg
[   56.884624] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=1
[   56.884625] fs/cifs/connect.c: CIFS VFS: in cifs_free_ipc as Xid: 4 with uid: 0
[   56.884626] fs/cifs/smb2pdu.c: Tree Disconnect
[   56.884627] fs/cifs/connect.c: CIFS VFS: leaving cifs_free_ipc (xid = 4) rc = -5
[   56.884628] fs/cifs/connect.c: failed to disconnect IPC tcon (rc=-5)
[   56.884629] fs/cifs/connect.c: CIFS VFS: in cifs_put_smb_ses as Xid: 5 with uid: 0
[   56.884631] fs/cifs/smb2pdu.c: disconnect session 0000000079e90667
[   56.884658] fs/cifs/transport.c: Sending smb: smb_len=72
[   56.973947] fs/cifs/connect.c: RFC1002 header 0x44
[   56.973952] fs/cifs/smb2misc.c: SMB2 len 68
[   56.973960] fs/cifs/transport.c: cifs_sync_mid_result: cmd=2 mid=6 state=4
[   56.973966] fs/cifs/smb2ops.c: add 2 credits total=135
[   56.973972] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x0000000052b09517/0x00000000f1aba55a)
[   56.973977] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 0) rc = -2
[   56.973978] fs/cifs/connect.c: CIFS VFS: in cifs_mount as Xid: 6 with uid: 0
[   56.973978] fs/cifs/connect.c: UNC: \\DC03.Prodrive.nl\product
[   56.973988] fs/cifs/connect.c: Socket created
[   56.973989] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x6d6
[   56.975065] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000b59953b4/0x00000000f1aba55a)
[   56.975067] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 7 with uid: 0
[   56.975068] fs/cifs/connect.c: Existing smb sess not found
[   56.975070] fs/cifs/smb2pdu.c: Negotiate protocol
[   56.975112] fs/cifs/transport.c: Sending smb: smb_len=106
[   56.975135] fs/cifs/connect.c: Demultiplex PID: 1556
[   56.976574] fs/cifs/connect.c: RFC1002 header 0xf8
[   56.976577] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[   56.976577] fs/cifs/smb2misc.c: SMB2 len 248
[   56.976581] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[   56.976584] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   56.976585] fs/cifs/smb2pdu.c: mode 0x3
[   56.976585] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[   56.976587] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   56.976588] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[   56.976589] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[   56.976589] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[   56.976590] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   56.976591] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
[   56.976592] fs/cifs/smb2pdu.c: Session Setup
[   56.976592] fs/cifs/smb2pdu.c: sess setup type 5
[   56.976595] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=DC03.Prodrive.nl;ip4=10.1.1.3;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x600
[   57.000235] fs/cifs/transport.c: Sending smb: smb_len=6932
[   57.004434] fs/cifs/connect.c: RFC1002 header 0x5e
[   57.004438] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
[   57.004438] fs/cifs/smb2misc.c: SMB2 len 94
[   57.004444] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
[   57.004445] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   57.004454] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[   57.004457] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 7) rc = 0
[   57.004459] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 8 with uid: 0
[   57.004460] fs/cifs/smb2pdu.c: TCON
[   57.004467] fs/cifs/transport.c: Sending smb: smb_len=124
[   57.005230] fs/cifs/connect.c: RFC1002 header 0x50
[   57.005232] fs/cifs/smb2misc.c: SMB2 len 80
[   57.005237] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
[   57.005239] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   57.005240] fs/cifs/smb2ops.c: add 2 credits total=131
[   57.005240] fs/cifs/smb2pdu.c: connection to pipe share
[   57.005241] fs/cifs/smb2pdu.c: validate negotiate
[   57.005242] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.006053] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[   57.006059] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   57.006060] fs/cifs/smb2ops.c: add 2 credits total=132
[   57.006061] fs/cifs/smb2pdu.c: validate negotiate info successful
[   57.006062] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 8) rc = 0
[   57.006063] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[   57.006064] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 9 with uid: 0
[   57.006065] fs/cifs/smb2pdu.c: TCON
[   57.006817] fs/cifs/smb2ops.c: add 2 credits total=133
[   57.006818] fs/cifs/smb2pdu.c: connection to disk share
[   57.006818] fs/cifs/smb2pdu.c: validate negotiate
[   57.006819] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.007551] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[   57.007559] fs/cifs/smb2ops.c: add 2 credits total=134
[   57.007565] fs/cifs/smb2pdu.c: validate negotiate info successful
[   57.007566] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 9) rc = 0
[   57.007566] fs/cifs/connect.c: Tcon rc = 0
[   57.007569] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x00000000f1aba55a/0x00000000cf051041)
[   57.007570] fs/cifs/smb2pdu.c: create/open
[   57.008380] fs/cifs/smb2misc.c: SMB2 data length 0 offset 0
[   57.008381] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 6
[   57.008388] fs/cifs/smb2ops.c: add 2 credits total=135
[   57.008388] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.009090] fs/cifs/smb2misc.c: SMB2 data length 304 offset 112
[   57.009098] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[   57.009099] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[   57.009100] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[   57.009100] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:6142:6b8c:505e:61e3
[   57.009101] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
[   57.009101] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[   57.009102] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[   57.009102] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.3
[   57.009103] fs/cifs/smb2pdu.c: Query FSInfo level 5
[   57.009726] fs/cifs/smb2pdu.c: Query FSInfo level 4
[   57.010250] fs/cifs/smb2pdu.c: Query FSInfo level 1
[   57.010841] fs/cifs/smb2pdu.c: Query FSInfo level 11
[   57.011390] fs/cifs/smb2pdu.c: Close
[   57.011878] fs/cifs/smb2pdu.c: create/open
[   57.012441] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 13
[   57.012448] fs/cifs/smb2pdu.c: Close
[   57.012966] fs/cifs/smb2pdu.c: create/open
[   57.013580] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 15
[   57.013586] fs/cifs/smb2pdu.c: Close
[   57.014167] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 6) rc = 0
[   57.014214] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 10 with uid: 0
[   57.014214] fs/cifs/inode.c: Getting info on 
[   57.014216] fs/cifs/smb2pdu.c: create/open
[   57.014895] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 17
[   57.014902] fs/cifs/smb2pdu.c: Query Info
[   57.015460] fs/cifs/smb2pdu.c: Close
[   57.016126] fs/cifs/inode.c: looking for uniqueid=121
[   57.016132] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 121
[   57.016133] fs/cifs/inode.c: cifs_revalidate_cache: inode 121 is new
[   57.016134] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 10) rc = 0
[   57.016136] fs/cifs/cifsfs.c: Get root dentry for 
[   57.016137] fs/cifs/cifsfs.c: dentry root is: 00000000a5e6e075
[   57.020324] fs/cifs/cifsfs.c: CIFS VFS: in cifs_statfs as Xid: 11 with uid: 0
[   57.021098] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 20
[   57.021101] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 22
[   57.021112] fs/cifs/cifsfs.c: CIFS VFS: leaving cifs_statfs (xid = 11) rc = 0
[   57.021409] =========================================
[   57.021498] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 12 with uid: 10003
[   57.021499] fs/cifs/dir.c: parent inode = 0x00000000402c68aa name is: KAES6309 and dentry = 0x00000000a5864cec
[   57.021500] fs/cifs/dir.c: name: \KAES6309
[   57.021501] fs/cifs/dir.c: NULL inode in lookup
[   57.021501] fs/cifs/dir.c: Full path: \KAES6309 inode = 0x          (null)
[   57.021502] fs/cifs/inode.c: Getting info on \KAES6309
[   57.021506] fs/cifs/smb2pdu.c: create/open
[   57.022197] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 23
[   57.022203] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
[   57.022205] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
[   57.022207] fs/cifs/inode.c: creating fake fattr for DFS referral
[   57.022208] fs/cifs/inode.c: looking for uniqueid=122
[   57.022212] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 122
[   57.022212] fs/cifs/inode.c: cifs_revalidate_cache: inode 122 is new
[   57.022213] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 12) rc = 0
[   57.022220] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_d_automount
[   57.022221] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_do_automount
[   57.022222] fs/cifs/dir.c: name: \KAES6309
[   57.022223] fs/cifs/cifs_dfs_ref.c: CIFS VFS: in cifs_dfs_do_automount as Xid: 13 with uid: 10003
[   57.022223] fs/cifs/smb2ops.c: smb2_get_dfs_refer path <\DC03.Prodrive.nl\product\KAES6309>
[   57.022226] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.023315] fs/cifs/misc.c: num_referrals: 1 dfs flags: 0x2 ...
[   57.023322] fs/cifs/cifs_dfs_ref.c: CIFS VFS: leaving cifs_dfs_do_automount (xid = 13) rc = 0
[   57.023323] fs/cifs/cifs_dfs_ref.c: DFS: ref path: \DC03.Prodrive.nl\product\KAES6309
[   57.023323] fs/cifs/cifs_dfs_ref.c: DFS: node path: \str02\product1$\KAES6309
[   57.023324] fs/cifs/cifs_dfs_ref.c: DFS: fl: 2, srv_type: 0
[   57.023324] fs/cifs/cifs_dfs_ref.c: DFS: ref_flags: 0, path_consumed: 34
[   57.028217] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: str02 to 10.1.1.6
[   57.028224] fs/cifs/cifsfs.c: Devname: //str02/product1$/KAES6309 flags: 67108864
[   57.028247] fs/cifs/connect.c: Username: mdg
[   57.028249] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
[   57.028250] fs/cifs/connect.c: CIFS VFS: in cifs_mount as Xid: 14 with uid: 10003
[   57.028251] fs/cifs/connect.c: UNC: \\str02\product1$
[   57.028256] fs/cifs/connect.c: Socket created
[   57.028256] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x6d6
[   57.029192] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000677615be/0x0000000099487af3)
[   57.029194] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 15 with uid: 10003
[   57.029194] fs/cifs/connect.c: Existing smb sess not found
[   57.029197] fs/cifs/smb2pdu.c: Negotiate protocol
[   57.029246] fs/cifs/connect.c: Demultiplex PID: 1559
[   57.029731] fs/cifs/smb2pdu.c: mode 0x1
[   57.029732] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[   57.029735] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300077 TimeAdjust: 0
[   57.029736] fs/cifs/smb2pdu.c: Session Setup
[   57.029736] fs/cifs/smb2pdu.c: sess setup type 5
[   57.029738] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=str02;ip4=10.1.1.6;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x5e0
[   57.058289] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[   57.058295] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 15) rc = 0
[   57.058298] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 16 with uid: 10003
[   57.058298] fs/cifs/smb2pdu.c: TCON
[   57.059606] fs/cifs/smb2pdu.c: connection to pipe share
[   57.059607] fs/cifs/smb2pdu.c: validate negotiate
[   57.059608] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.061631] fs/cifs/smb2pdu.c: validate negotiate info successful
[   57.061632] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 16) rc = 0
[   57.061633] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[   57.061635] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 17 with uid: 10003
[   57.061635] fs/cifs/smb2pdu.c: TCON
[   57.063217] fs/cifs/smb2pdu.c: connection to disk share
[   57.063218] fs/cifs/smb2pdu.c: validate negotiate
[   57.063218] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.064473] fs/cifs/smb2pdu.c: validate negotiate info successful
[   57.064475] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 17) rc = 0
[   57.064476] fs/cifs/connect.c: Tcon rc = 0
[   57.064479] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x0000000099487af3/0x00000000ffb8f0b0)
[   57.064479] fs/cifs/smb2pdu.c: create/open
[   57.065729] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 6
[   57.065734] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.066931] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[   57.066932] fs/cifs/smb2ops.c: parse_server_interfaces: speed 20000000000 bps
[   57.066932] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000001
[   57.066933] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.6
[   57.066934] fs/cifs/smb2pdu.c: Query FSInfo level 5
[   57.067786] fs/cifs/smb2pdu.c: Query FSInfo level 4
[   57.068549] fs/cifs/smb2pdu.c: Query FSInfo level 1
[   57.069370] fs/cifs/smb2pdu.c: Query FSInfo level 11
[   57.070071] fs/cifs/smb2pdu.c: Close
[   57.070734] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\str02\product1$\KAES6309
[   57.070735] fs/cifs/smb2ops.c: smb2_get_dfs_refer path <\str02\product1$>
[   57.070737] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.071339] Status code returned 0xc0000225 STATUS_NOT_FOUND
[   57.071342] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000225 to POSIX err -2
[   57.071345] fs/cifs/smb2pdu.c: create/open
[   57.071866] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 14
[   57.071870] fs/cifs/smb2pdu.c: Close
[   57.072509] fs/cifs/smb2pdu.c: create/open
[   57.073209] fs/cifs/smb2pdu.c: Close
[   57.073847] fs/cifs/smb2pdu.c: create/open
[   57.074636] fs/cifs/smb2pdu.c: Close
[   57.075387] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 14) rc = 0
[   57.075435] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 18 with uid: 10003
[   57.075436] fs/cifs/inode.c: Getting info on 
[   57.075438] fs/cifs/smb2pdu.c: create/open
[   57.076118] fs/cifs/smb2pdu.c: Query Info
[   57.076681] fs/cifs/smb2pdu.c: Close
[   57.077295] fs/cifs/inode.c: looking for uniqueid=123
[   57.077302] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 123
[   57.077303] fs/cifs/inode.c: cifs_revalidate_cache: inode 123 is new
[   57.077304] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 18) rc = 0
[   57.077306] fs/cifs/cifsfs.c: Get root dentry for \KAES6309
[   57.077308] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 19 with uid: 10003
[   57.077309] fs/cifs/dir.c: parent inode = 0x000000002a8fdab7 name is: KAES6309 and dentry = 0x0000000048070c0a
[   57.077310] fs/cifs/dir.c: name: \KAES6309
[   57.077310] fs/cifs/dir.c: NULL inode in lookup
[   57.077311] fs/cifs/dir.c: Full path: \KAES6309 inode = 0x          (null)
[   57.077311] fs/cifs/inode.c: Getting info on \KAES6309
[   57.078260] fs/cifs/smb2pdu.c: Query Info
[   57.078995] fs/cifs/smb2pdu.c: Close
[   57.079673] fs/cifs/inode.c: looking for uniqueid=124
[   57.079675] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 124
[   57.079676] fs/cifs/inode.c: cifs_revalidate_cache: inode 124 is new
[   57.079677] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 19) rc = 0
[   57.079678] fs/cifs/cifsfs.c: dentry root is: 0000000048070c0a
[   57.079680] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: cifs_dfs_do_refmount:\str02\product1$\KAES6309 , mnt:000000007a66184a
[   57.079681] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_do_automount
[   57.079682] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_d_automount [ok]

[-- Attachment #3: dfs-5.4.6-autofs.log --]
[-- Type: application/octet-stream, Size: 23366 bytes --]

[   56.881118] fs/cifs/cifsfs.c: Devname: //prodrive.nl/product flags: 0
[   56.881145] fs/cifs/connect.c: Username: mdg
[   56.881147] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
[   56.881149] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 0 with uid: 0
[   56.881149] fs/cifs/connect.c: UNC: \\prodrive.nl\product
[   56.881155] fs/cifs/connect.c: Socket created
[   56.881156] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[   57.089272] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x000000007a4c14cc/0x00000000c5f95f7a)
[   57.089275] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 1 with uid: 0
[   57.089275] fs/cifs/connect.c: Existing smb sess not found
[   57.089278] fs/cifs/smb2pdu.c: Negotiate protocol
[   57.089287] fs/cifs/transport.c: Sending smb: smb_len=106
[   57.089324] fs/cifs/connect.c: Demultiplex PID: 1569
[   57.297207] fs/cifs/connect.c: RFC1002 header 0xf8
[   57.297213] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[   57.297213] fs/cifs/smb2misc.c: SMB2 len 248
[   57.297222] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[   57.297226] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   57.297228] fs/cifs/smb2pdu.c: mode 0x3
[   57.297229] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[   57.297231] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   57.297232] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[   57.297233] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[   57.297233] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[   57.297234] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   57.297235] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
[   57.297269] fs/cifs/smb2pdu.c: Session Setup
[   57.297270] fs/cifs/smb2pdu.c: sess setup type 5
[   57.297273] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=prodrive.nl;ip4=10.3.0.3;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x61f
[   57.331534] fs/cifs/transport.c: Sending smb: smb_len=6934
[   57.549251] fs/cifs/connect.c: RFC1002 header 0x5e
[   57.549257] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
[   57.549257] fs/cifs/smb2misc.c: SMB2 len 94
[   57.549268] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
[   57.549269] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   57.549279] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[   57.549283] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 1) rc = 0
[   57.549286] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 2 with uid: 0
[   57.549286] fs/cifs/smb2pdu.c: TCON
[   57.549330] fs/cifs/transport.c: Sending smb: smb_len=114
[   57.756760] fs/cifs/connect.c: RFC1002 header 0x50
[   57.756766] fs/cifs/smb2misc.c: SMB2 len 80
[   57.756768] fs/cifs/smb2ops.c: add 33 credits total=65
[   57.756778] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
[   57.756783] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   57.756785] fs/cifs/smb2pdu.c: connection to pipe share
[   57.756786] fs/cifs/smb2pdu.c: validate negotiate
[   57.756787] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   57.756834] fs/cifs/transport.c: Sending smb: smb_len=152
[   57.965942] fs/cifs/connect.c: RFC1002 header 0x88
[   57.965948] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[   57.965949] fs/cifs/smb2misc.c: SMB2 len 136
[   57.965950] fs/cifs/smb2ops.c: add 10 credits total=74
[   57.965961] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=3 state=4
[   57.965966] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   57.965968] fs/cifs/smb2pdu.c: validate negotiate info successful
[   57.965970] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 2) rc = 0
[   57.965970] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[   57.965973] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 3 with uid: 0
[   57.965974] fs/cifs/smb2pdu.c: TCON
[   57.965982] fs/cifs/transport.c: Sending smb: smb_len=120
[   58.175561] fs/cifs/connect.c: RFC1002 header 0x49
[   58.175566] fs/cifs/smb2misc.c: SMB2 len 73
[   58.175568] fs/cifs/smb2ops.c: add 33 credits total=106
[   58.175578] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=4 state=4
[   58.175583] Status code returned 0xc00000cc STATUS_BAD_NETWORK_NAME
[   58.175585] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc00000cc to POSIX err -2
[   58.175586] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   58.175588] CIFS VFS:  BAD_NETWORK_NAME: \\prodrive.nl\product
[   58.175591] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 3) rc = -2
[   58.175592] fs/cifs/connect.c: Tcon rc = -2
[   58.175594] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
[   58.175594] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
[   58.175595] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
[   58.175596] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \prodrive.nl\product
[   58.175597] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[   58.175598] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \prodrive.nl\product
[   58.175599] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \prodrive.nl\product
[   58.175601] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   58.175610] fs/cifs/transport.c: Sending smb: smb_len=168
[   58.387356] fs/cifs/connect.c: RFC1002 header 0x49
[   58.387362] fs/cifs/smb2misc.c: SMB2 data length 0 offset 0
[   58.387363] fs/cifs/smb2misc.c: SMB2 len 73
[   58.429592] fs/cifs/connect.c: RFC1002 header 0x178
[   58.429598] fs/cifs/smb2misc.c: SMB2 data length 264 offset 112
[   58.429599] fs/cifs/smb2misc.c: SMB2 len 376
[   58.429600] fs/cifs/smb2ops.c: add 0 credits total=115
[   58.429610] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=5 state=4
[   58.429616] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   58.429653] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
[   58.429663] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[   58.429666] fs/cifs/dfs_cache.c: setup_ref: set up new ref
[   58.433584] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC01.Prodrive.nl to 10.1.1.14
[   58.433611] fs/cifs/connect.c: Username: mdg
[   58.433613] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=1
[   58.433614] fs/cifs/connect.c: CIFS VFS: in cifs_free_ipc as Xid: 4 with uid: 0
[   58.433614] fs/cifs/smb2pdu.c: Tree Disconnect
[   58.433615] fs/cifs/connect.c: CIFS VFS: leaving cifs_free_ipc (xid = 4) rc = -5
[   58.433616] fs/cifs/connect.c: failed to disconnect IPC tcon (rc=-5)
[   58.433617] fs/cifs/connect.c: CIFS VFS: in cifs_put_smb_ses as Xid: 5 with uid: 0
[   58.433618] fs/cifs/smb2pdu.c: disconnect session 0000000040a793cf
[   58.433628] fs/cifs/transport.c: Sending smb: smb_len=72
[   58.640734] fs/cifs/connect.c: RFC1002 header 0x44
[   58.640740] fs/cifs/smb2misc.c: SMB2 len 68
[   58.640742] fs/cifs/smb2ops.c: add 2 credits total=116
[   58.640752] fs/cifs/transport.c: cifs_sync_mid_result: cmd=2 mid=6 state=4
[   58.640797] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x000000007a4c14cc/0x00000000c5f95f7a)
[   58.640801] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 0) rc = 0
[   58.640802] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 6 with uid: 0
[   58.640803] fs/cifs/connect.c: UNC: \\DC01.Prodrive.nl\product
[   58.640812] fs/cifs/connect.c: Socket created
[   58.640813] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[   58.643590] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000579df081/0x00000000ded2a9c9)
[   58.643592] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 7 with uid: 0
[   58.643593] fs/cifs/connect.c: Existing smb sess not found
[   58.643595] fs/cifs/smb2pdu.c: Negotiate protocol
[   58.643600] fs/cifs/transport.c: Sending smb: smb_len=106
[   58.643654] fs/cifs/connect.c: Demultiplex PID: 1579
[   58.645677] fs/cifs/connect.c: RFC1002 header 0xf8
[   58.645680] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[   58.645680] fs/cifs/smb2misc.c: SMB2 len 248
[   58.645685] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[   58.645688] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   58.645689] fs/cifs/smb2pdu.c: mode 0x3
[   58.645689] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[   58.645691] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   58.645692] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[   58.645693] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[   58.645694] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[   58.645694] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[   58.645696] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
[   58.645696] fs/cifs/smb2pdu.c: Session Setup
[   58.645697] fs/cifs/smb2pdu.c: sess setup type 5
[   58.645700] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=DC01.Prodrive.nl;ip4=10.1.1.14;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x61f
[   58.676635] fs/cifs/transport.c: Sending smb: smb_len=6932
[   58.681495] fs/cifs/connect.c: RFC1002 header 0x5e
[   58.681500] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
[   58.681500] fs/cifs/smb2misc.c: SMB2 len 94
[   58.681508] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
[   58.681509] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   58.681518] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[   58.681521] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 7) rc = 0
[   58.681523] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 8 with uid: 0
[   58.681524] fs/cifs/smb2pdu.c: TCON
[   58.681531] fs/cifs/transport.c: Sending smb: smb_len=124
[   58.683250] fs/cifs/smb2ops.c: add 64 credits total=193
[   58.683256] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
[   58.683258] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   58.683258] fs/cifs/smb2pdu.c: connection to pipe share
[   58.683259] fs/cifs/smb2pdu.c: validate negotiate
[   58.683260] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   58.684692] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[   58.684694] fs/cifs/smb2ops.c: add 10 credits total=202
[   58.684700] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[   58.684701] fs/cifs/smb2pdu.c: validate negotiate info successful
[   58.684703] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 8) rc = 0
[   58.684704] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[   58.684705] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 9 with uid: 0
[   58.684706] fs/cifs/smb2pdu.c: TCON
[   58.686569] fs/cifs/smb2ops.c: add 64 credits total=265
[   58.686576] fs/cifs/smb2pdu.c: connection to disk share
[   58.686577] fs/cifs/smb2pdu.c: validate negotiate
[   58.686578] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   58.687350] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[   58.687351] fs/cifs/smb2ops.c: add 10 credits total=274
[   58.687359] fs/cifs/smb2pdu.c: validate negotiate info successful
[   58.687360] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 9) rc = 0
[   58.687360] fs/cifs/connect.c: Tcon rc = 0
[   58.687363] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x00000000ded2a9c9/0x0000000037550426)
[   58.687364] fs/cifs/smb2pdu.c: create/open
[   58.688381] fs/cifs/smb2misc.c: SMB2 data length 56 offset 152
[   58.688382] fs/cifs/smb2ops.c: add 10 credits total=283
[   58.688418] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   58.690917] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[   58.690918] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[   58.690918] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[   58.690919] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:7d2b:8e78:9c7c:fc51
[   58.690920] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
[   58.690920] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[   58.690921] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[   58.690921] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.14
[   58.690922] fs/cifs/smb2pdu.c: Query FSInfo level 5
[   58.693641] fs/cifs/smb2pdu.c: Query FSInfo level 4
[   58.696440] fs/cifs/smb2pdu.c: Query FSInfo level 1
[   58.698875] fs/cifs/smb2pdu.c: Query FSInfo level 11
[   58.700718] fs/cifs/smb2pdu.c: Close
[   58.701419] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC01.Prodrive.nl\product
[   58.701421] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product
[   58.701422] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[   58.701422] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC01.Prodrive.nl\product
[   58.701423] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC01.Prodrive.nl\product
[   58.701426] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   58.703469] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
[   58.703479] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[   58.703483] fs/cifs/connect.c: is_path_remote: full_path: 
[   58.703493] fs/cifs/smb2pdu.c: create/open
[   58.705727] fs/cifs/smb2pdu.c: Close
[   58.707253] fs/cifs/smb2pdu.c: create/open
[   58.709356] fs/cifs/smb2pdu.c: Close
[   58.710923] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
[   58.710925] fs/cifs/dfs_cache.c: dfs_cache_add_vol: fullpath: \\prodrive.nl\product
[   58.710926] fs/cifs/dfs_cache.c: dup_vol: vol->UNC: \\DC01.Prodrive.nl\product
[   58.710928] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 6) rc = 0
[   58.710979] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 10 with uid: 0
[   58.710979] fs/cifs/inode.c: Getting info on 
[   58.711709] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 20
[   58.711723] fs/cifs/inode.c: looking for uniqueid=117
[   58.711730] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 117
[   58.711731] fs/cifs/inode.c: cifs_revalidate_cache: inode 117 is new
[   58.711732] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 10) rc = 0
[   58.711734] fs/cifs/cifsfs.c: Get root dentry for 
[   58.711735] fs/cifs/cifsfs.c: dentry root is: 000000009ad726e2
[   58.715919] fs/cifs/cifsfs.c: CIFS VFS: in cifs_statfs as Xid: 11 with uid: 0
[   58.718970] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 23
[   58.718980] fs/cifs/cifsfs.c: CIFS VFS: leaving cifs_statfs (xid = 11) rc = 0
[   58.719282] =========================================
[   58.719375] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 12 with uid: 10003
[   58.719377] fs/cifs/dir.c: parent inode = 0x00000000e06c3285 name is: KAES6309 and dentry = 0x0000000036a0df48
[   58.719377] fs/cifs/dir.c: name: \KAES6309
[   58.719378] fs/cifs/dir.c: NULL inode in lookup
[   58.719379] fs/cifs/dir.c: Full path: \KAES6309 inode = 0x00000000ec0f402e
[   58.719379] fs/cifs/inode.c: Getting info on \KAES6309
[   58.721959] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 24
[   58.721961] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 25
[   58.721963] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 26
[   58.721972] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
[   58.721974] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
[   58.721977] fs/cifs/inode.c: creating fake fattr for DFS referral
[   58.721978] fs/cifs/inode.c: looking for uniqueid=118
[   58.721983] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 118
[   58.721983] fs/cifs/inode.c: cifs_revalidate_cache: inode 118 is new
[   58.721985] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 12) rc = 0
[   58.721994] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_d_automount
[   58.721995] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_do_automount
[   58.721996] fs/cifs/dir.c: name: \KAES6309
[   58.721997] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: full_path: \\DC01.Prodrive.nl\product\KAES6309
[   58.721997] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: root path: \\DC01.Prodrive.nl\product
[   58.721998] fs/cifs/cifs_dfs_ref.c: CIFS VFS: in cifs_dfs_do_automount as Xid: 13 with uid: 10003
[   58.721999] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product
[   58.722000] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product\KAES6309
[   58.722001] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[   58.722002] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC01.Prodrive.nl\product\KAES6309
[   58.722003] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC01.Prodrive.nl\product\KAES6309
[   58.722005] fs/cifs/smb2pdu.c: SMB2 IOCTL
[   58.724758] fs/cifs/misc.c: num_referrals: 1 dfs flags: 0x2 ...
[   58.724765] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[   58.724767] fs/cifs/dfs_cache.c: setup_ref: set up new ref
[   58.724768] fs/cifs/cifs_dfs_ref.c: CIFS VFS: leaving cifs_dfs_do_automount (xid = 13) rc = 0
[   58.724769] fs/cifs/cifs_dfs_ref.c: DFS: ref path: \DC01.Prodrive.nl\product\KAES6309
[   58.724769] fs/cifs/cifs_dfs_ref.c: DFS: node path: \str02\product1$\KAES6309
[   58.724770] fs/cifs/cifs_dfs_ref.c: DFS: fl: 0, srv_type: 0
[   58.724770] fs/cifs/cifs_dfs_ref.c: DFS: ref_flags: 0, path_consumed: 34
[   58.729228] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: str02 to 10.1.1.6
[   58.729234] fs/cifs/cifsfs.c: Devname: //DC01.Prodrive.nl/product/KAES6309 flags: 67108864
[   58.729259] fs/cifs/connect.c: Username: mdg
[   58.729261] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
[   58.729263] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 14 with uid: 10003
[   58.729263] fs/cifs/connect.c: UNC: \\DC01.Prodrive.nl\product
[   58.729271] fs/cifs/connect.c: Socket created
[   58.729272] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[   58.730446] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x000000001bfb52bf/0x00000000bf4eb55f)
[   58.730448] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 15 with uid: 10003
[   58.730449] fs/cifs/connect.c: Existing smb sess not found
[   58.730451] fs/cifs/smb2pdu.c: Negotiate protocol
[   58.730513] fs/cifs/connect.c: Demultiplex PID: 1582
[   58.731299] fs/cifs/smb2pdu.c: mode 0x1
[   58.731300] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[   58.731303] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300077 TimeAdjust: 0
[   58.731304] fs/cifs/smb2pdu.c: Session Setup
[   58.731305] fs/cifs/smb2pdu.c: sess setup type 5
[   58.731307] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=DC01.Prodrive.nl;ip4=10.1.1.6;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x60b
[   58.737496] fs/cifs/smb2misc.c: Calculated size 73 length 98 mismatch mid 1
[   58.737497] srv rsp padded more than expected. Length 98 not 73 for cmd:1 mid:1
[   58.737503] Status code returned 0xc000006d STATUS_LOGON_FAILURE
[   58.737506] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc000006d to POSIX err -13
[   58.737509] CIFS VFS: \\DC01.Prodrive.nl Send error in SessSetup = -13
[   58.737512] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 15) rc = -13
[   58.737516] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x000000001bfb52bf/0x00000000bf4eb55f)
[   58.737519] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 14) rc = 0
[   58.737519] CIFS VFS: cifs_mount failed w/return code = -13
[   58.737523] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: cifs_dfs_do_refmount:\str02\product1$\KAES6309 , mnt:000000004dc58971
[   58.737523] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_do_automount
[   58.737524] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_d_automount [automount failed]
[   58.737564] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_d_automount
[   58.737565] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_do_automount
[   58.737566] fs/cifs/dir.c: name: \KAES6309
[   58.737581] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: full_path: \\DC01.Prodrive.nl\product\KAES6309
[   58.737582] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: root path: \\DC01.Prodrive.nl\product
[   58.737583] fs/cifs/cifs_dfs_ref.c: CIFS VFS: in cifs_dfs_do_automount as Xid: 16 with uid: 10003
[   58.737584] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product
[   58.737585] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product\KAES6309
[   58.737586] fs/cifs/dfs_cache.c: setup_ref: set up new ref
[   58.737587] fs/cifs/cifs_dfs_ref.c: CIFS VFS: leaving cifs_dfs_do_automount (xid = 16) rc = 0
[   58.737587] fs/cifs/cifs_dfs_ref.c: DFS: ref path: \DC01.Prodrive.nl\product\KAES6309
[   58.737588] fs/cifs/cifs_dfs_ref.c: DFS: node path: \str02\product1$\KAES6309
[   58.737588] fs/cifs/cifs_dfs_ref.c: DFS: fl: 0, srv_type: 0
[   58.737589] fs/cifs/cifs_dfs_ref.c: DFS: ref_flags: 0, path_consumed: 34
[   58.737593] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: str02 to 10.1.1.6
[   58.737598] fs/cifs/cifsfs.c: Devname: //DC01.Prodrive.nl/product/KAES6309 flags: 67108864
[   58.737621] fs/cifs/connect.c: Username: mdg
[   58.737622] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
[   58.737623] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 17 with uid: 10003
[   58.737624] fs/cifs/connect.c: UNC: \\DC01.Prodrive.nl\product
[   58.737631] fs/cifs/connect.c: Socket created
[   58.737632] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[   58.739421] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000c52cdf01/0x0000000068aa9c59)
[   58.739423] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 18 with uid: 10003
[   58.739424] fs/cifs/connect.c: Existing smb sess not found
[   58.739426] fs/cifs/smb2pdu.c: Negotiate protocol
[   58.739489] fs/cifs/connect.c: Demultiplex PID: 1584
[   58.742814] fs/cifs/smb2pdu.c: mode 0x1
[   58.742815] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[   58.742818] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300077 TimeAdjust: 0
[   58.742819] fs/cifs/smb2pdu.c: Session Setup
[   58.742819] fs/cifs/smb2pdu.c: sess setup type 5
[   58.742822] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=DC01.Prodrive.nl;ip4=10.1.1.6;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x60b
[   58.750239] fs/cifs/smb2misc.c: Calculated size 73 length 98 mismatch mid 1
[   58.750247] Status code returned 0xc000006d STATUS_LOGON_FAILURE
[   58.750249] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc000006d to POSIX err -13
[   58.750252] CIFS VFS: \\DC01.Prodrive.nl Send error in SessSetup = -13
[   58.750255] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 18) rc = -13
[   58.750261] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x00000000c52cdf01/0x0000000068aa9c59)
[   58.750263] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 17) rc = 0
[   58.750264] CIFS VFS: cifs_mount failed w/return code = -13
[   58.750267] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: cifs_dfs_do_refmount:\str02\product1$\KAES6309 , mnt:000000004dc58971
[   58.750267] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_do_automount
[   58.750268] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_d_automount [automount failed]