linux-cifs.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* cifs.upcall requests ticket for wrong host when using dfs
@ 2020-01-03 14:11 Martijn de Gouw
       [not found] ` <87png0boej.fsf@cjr.nz>
  0 siblings, 1 reply; 12+ messages in thread
From: Martijn de Gouw @ 2020-01-03 14:11 UTC (permalink / raw)
  To: linux-cifs

Hi,

I'm trying to switch from ntlpssp to kerbebos for mounting our dfs 
shares. It seems to work, but only for 'older' kernel versions. Since we 
are running debian 9 and 10, I'm testing this for both version. The 
thing is that is seems to work when I run kernel 4.19.67, but not when 
I'm running kernel 5.3.9.

What I'm trying to do:
mount -t cifs //domain.com/common /mnt/common -o 
rw,vers=3.0,sec=krb5,cruid=10003,username=mdg,uid=10003,gid=10276,addr=10.1.1.14,file_mode=0600,dir_mode=0700,nobrl,nohandlecache,user=mdg

So far it works fine on 4.19, but not on 5.3. Because when I try to 
travel into the directories (which are actually dfs pointers to the NAS 
shares) I get permission denied.

So far, I was able to track this down to cifs.upcall, because on kernel 
4.19 I see it tries to get a service ticket for the nas (cifs.upcall: 
handle_krb5_mech: getting service ticket for nas01.domain.com). But on 
kernel 5.3 it tries to get a ticket for the dc again: cifs.upcall: 
handle_krb5_mech: getting service ticket for dc01.domain.com.

What could be wrong here?
-- 
Martijn de Gouw
Designer
Prodrive Technologies
Mobile: +31 63 17 76 161
Phone:  +31 40 26 76 200

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
       [not found] ` <87png0boej.fsf@cjr.nz>
@ 2020-01-03 16:30   ` Martijn de Gouw
  2020-01-03 20:14     ` Paulo Alcantara
  0 siblings, 1 reply; 12+ messages in thread
From: Martijn de Gouw @ 2020-01-03 16:30 UTC (permalink / raw)
  To: Paulo Alcantara, linux-cifs

Hi Paulo,

On 03-01-2020 15:33, Paulo Alcantara wrote:
> Hi Martinj,
> 
> Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com> writes:
> 
>> I'm trying to switch from ntlpssp to kerbebos for mounting our dfs
>> shares. It seems to work, but only for 'older' kernel versions. Since we
>> are running debian 9 and 10, I'm testing this for both version. The
>> thing is that is seems to work when I run kernel 4.19.67, but not when
>> I'm running kernel 5.3.9.
>>
>> What I'm trying to do:
>> mount -t cifs //domain.com/common /mnt/common -o
>> rw,vers=3.0,sec=krb5,cruid=10003,username=mdg,uid=10003,gid=10276,addr=10.1.1.14,file_mode=0600,dir_mode=0700,nobrl,nohandlecache,user=mdg
>>
>> So far it works fine on 4.19, but not on 5.3. Because when I try to
>> travel into the directories (which are actually dfs pointers to the NAS
>> shares) I get permission denied.
>>
>> So far, I was able to track this down to cifs.upcall, because on kernel
>> 4.19 I see it tries to get a service ticket for the nas (cifs.upcall:
>> handle_krb5_mech: getting service ticket for nas01.domain.com). But on
>> kernel 5.3 it tries to get a ticket for the dc again: cifs.upcall:
>> handle_krb5_mech: getting service ticket for dc01.domain.com.
>>
>> What could be wrong here?
> 
> Could you please try it again with below commit:
> 
>        5bb30a4dd60e ("cifs: Fix retrieval of DFS referrals in cifs_mount()")

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,
> Paulo
> 

Regards, Martijn

-- 
Martijn de Gouw
Designer
Prodrive Technologies
Mobile: +31 63 17 76 161
Phone:  +31 40 26 76 200

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-03 16:30   ` Martijn de Gouw
@ 2020-01-03 20:14     ` Paulo Alcantara
  2020-01-06 15:07       ` Martijn de Gouw
  0 siblings, 1 reply; 12+ messages in thread
From: Paulo Alcantara @ 2020-01-03 20:14 UTC (permalink / raw)
  To: Martijn de Gouw, linux-cifs

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]?

Thanks,
Paulo

[1] https://wiki.samba.org/index.php/LinuxCIFS_troubleshooting

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-03 20:14     ` Paulo Alcantara
@ 2020-01-06 15:07       ` Martijn de Gouw
  2020-01-06 23:30         ` Paulo Alcantara
  0 siblings, 1 reply; 12+ messages in thread
From: Martijn de Gouw @ 2020-01-06 15:07 UTC (permalink / raw)
  To: Paulo Alcantara, linux-cifs

[-- 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]

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-06 15:07       ` Martijn de Gouw
@ 2020-01-06 23:30         ` Paulo Alcantara
  2020-01-07 16:13           ` Martijn de Gouw
  0 siblings, 1 reply; 12+ messages in thread
From: Paulo Alcantara @ 2020-01-06 23:30 UTC (permalink / raw)
  To: Martijn de Gouw, linux-cifs

Hi Martijn,

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

> 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().

Thanks for the logs!

I noticed that we're passing a wrong value for "ip=" down to cifs_mount():

[   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

That is,

     10.1.1.6 -> str02
     10.1.1.14 -> DC01.Prodrive.nl

which means that ip option should be set to 10.1.1.14.

cifs_mount() will not attempt to resolve the hostname in case we have a
_valid_ ip address set in the mount options, so we end up connecting to
the wrong server (str02) and then failing to authenticate.

Well, we could simply set "devname" to the resolved target (str02) and
we're done with it, but the problem with that is that it will break DFS
failover - that is, we will not be able to retry the other targets in
the referral in case we failed to connect it in cifs_mount().

I'm not entirely sure if that's the problem you're facing, but could you
please try below changes?

Thanks,
Paulo

diff --git a/fs/cifs/cifs_dfs_ref.c b/fs/cifs/cifs_dfs_ref.c
index 41957b82d796..606f26d862dc 100644
--- a/fs/cifs/cifs_dfs_ref.c
+++ b/fs/cifs/cifs_dfs_ref.c
@@ -120,17 +120,17 @@ cifs_build_devname(char *nodename, const char *prepath)
 
 
 /**
- * cifs_compose_mount_options	-	creates mount options for refferral
+ * cifs_compose_mount_options	-	creates mount options for referral
  * @sb_mountdata:	parent/root DFS mount options (template)
  * @fullpath:		full path in UNC format
- * @ref:		server's referral
+ * @ref:		optional server's referral
  * @devname:		optional pointer for saving device name
  *
  * creates mount options for submount based on template options sb_mountdata
  * and replacing unc,ip,prefixpath options with ones we've got form ref_unc.
  *
  * Returns: pointer to new mount options or ERR_PTR.
- * Caller is responcible for freeing retunrned value if it is not error.
+ * Caller is responsible for freeing returned value if it is not error.
  */
 char *cifs_compose_mount_options(const char *sb_mountdata,
 				   const char *fullpath,
@@ -150,18 +150,27 @@ char *cifs_compose_mount_options(const char *sb_mountdata,
 	if (sb_mountdata == NULL)
 		return ERR_PTR(-EINVAL);
 
-	if (strlen(fullpath) - ref->path_consumed) {
-		prepath = fullpath + ref->path_consumed;
-		/* skip initial delimiter */
-		if (*prepath == '/' || *prepath == '\\')
-			prepath++;
-	}
+	if (ref) {
+		if (strlen(fullpath) - ref->path_consumed) {
+			prepath = fullpath + ref->path_consumed;
+			/* skip initial delimiter */
+			if (*prepath == '/' || *prepath == '\\')
+				prepath++;
+		}
 
-	name = cifs_build_devname(ref->node_name, prepath);
-	if (IS_ERR(name)) {
-		rc = PTR_ERR(name);
-		name = NULL;
-		goto compose_mount_options_err;
+		name = cifs_build_devname(ref->node_name, prepath);
+		if (IS_ERR(name)) {
+			rc = PTR_ERR(name);
+			name = NULL;
+			goto compose_mount_options_err;
+		}
+	} else {
+		name = cifs_build_devname((char *)fullpath, NULL);
+		if (IS_ERR(name)) {
+			rc = PTR_ERR(name);
+			name = NULL;
+			goto compose_mount_options_err;
+		}
 	}
 
 	rc = dns_resolve_server_name_to_ip(name, &srvIP);
@@ -225,6 +234,8 @@ char *cifs_compose_mount_options(const char *sb_mountdata,
 
 	if (devname)
 		*devname = name;
+	else
+		kfree(name);
 
 	/*cifs_dbg(FYI, "%s: parent mountdata: %s\n", __func__, sb_mountdata);*/
 	/*cifs_dbg(FYI, "%s: submount mountdata: %s\n", __func__, mountdata );*/
@@ -241,23 +252,23 @@ char *cifs_compose_mount_options(const char *sb_mountdata,
 }
 
 /**
- * cifs_dfs_do_refmount - mounts specified path using provided refferal
+ * cifs_dfs_do_mount - mounts specified path using DFS full path
+ *
+ * Always pass down @fullpath to smb3_do_mount() so we can use the root server
+ * to perform failover in case we failed to connect to the first target in the
+ * referral.
+ *
  * @cifs_sb:		parent/root superblock
  * @fullpath:		full path in UNC format
- * @ref:		server's referral
  */
-static struct vfsmount *cifs_dfs_do_refmount(struct dentry *mntpt,
-		struct cifs_sb_info *cifs_sb,
-		const char *fullpath, const struct dfs_info3_param *ref)
+static struct vfsmount *cifs_dfs_do_mount(struct dentry *mntpt,
+					  struct cifs_sb_info *cifs_sb,
+					  const char *fullpath)
 {
 	struct vfsmount *mnt;
 	char *mountdata;
 	char *devname;
 
-	/*
-	 * Always pass down the DFS full path to smb3_do_mount() so we
-	 * can use it later for failover.
-	 */
 	devname = kstrndup(fullpath, strlen(fullpath), GFP_KERNEL);
 	if (!devname)
 		return ERR_PTR(-ENOMEM);
@@ -266,7 +277,7 @@ static struct vfsmount *cifs_dfs_do_refmount(struct dentry *mntpt,
 
 	/* strip first '\' from fullpath */
 	mountdata = cifs_compose_mount_options(cifs_sb->mountdata,
-					       fullpath + 1, ref, NULL);
+					       fullpath + 1, NULL, NULL);
 	if (IS_ERR(mountdata)) {
 		kfree(devname);
 		return (struct vfsmount *)mountdata;
@@ -278,28 +289,16 @@ static struct vfsmount *cifs_dfs_do_refmount(struct dentry *mntpt,
 	return mnt;
 }
 
-static void dump_referral(const struct dfs_info3_param *ref)
-{
-	cifs_dbg(FYI, "DFS: ref path: %s\n", ref->path_name);
-	cifs_dbg(FYI, "DFS: node path: %s\n", ref->node_name);
-	cifs_dbg(FYI, "DFS: fl: %d, srv_type: %d\n",
-		 ref->flags, ref->server_type);
-	cifs_dbg(FYI, "DFS: ref_flags: %d, path_consumed: %d\n",
-		 ref->ref_flag, ref->path_consumed);
-}
-
 /*
  * Create a vfsmount that we can automount
  */
 static struct vfsmount *cifs_dfs_do_automount(struct dentry *mntpt)
 {
-	struct dfs_info3_param referral = {0};
 	struct cifs_sb_info *cifs_sb;
 	struct cifs_ses *ses;
 	struct cifs_tcon *tcon;
 	char *full_path, *root_path;
 	unsigned int xid;
-	int len;
 	int rc;
 	struct vfsmount *mnt;
 
@@ -357,7 +356,7 @@ static struct vfsmount *cifs_dfs_do_automount(struct dentry *mntpt)
 	if (!rc) {
 		rc = dfs_cache_find(xid, ses, cifs_sb->local_nls,
 				    cifs_remap(cifs_sb), full_path + 1,
-				    &referral, NULL);
+				    NULL, NULL);
 	}
 
 	free_xid(xid);
@@ -366,26 +365,16 @@ static struct vfsmount *cifs_dfs_do_automount(struct dentry *mntpt)
 		mnt = ERR_PTR(rc);
 		goto free_root_path;
 	}
-
-	dump_referral(&referral);
-
-	len = strlen(referral.node_name);
-	if (len < 2) {
-		cifs_dbg(VFS, "%s: Net Address path too short: %s\n",
-			 __func__, referral.node_name);
-		mnt = ERR_PTR(-EINVAL);
-		goto free_dfs_ref;
-	}
 	/*
-	 * cifs_mount() will retry every available node server in case
-	 * of failures.
+	 * OK - we were able to get and cache a referral for @full_path.
+	 *
+	 * Now, pass it down to cifs_mount() and it will retry every available
+	 * node server in case of failures - no need to do it here.
 	 */
-	mnt = cifs_dfs_do_refmount(mntpt, cifs_sb, full_path, &referral);
-	cifs_dbg(FYI, "%s: cifs_dfs_do_refmount:%s , mnt:%p\n", __func__,
-		 referral.node_name, mnt);
+	mnt = cifs_dfs_do_mount(mntpt, cifs_sb, full_path);
+	cifs_dbg(FYI, "%s: cifs_dfs_do_mount:%s , mnt:%p\n", __func__,
+		 full_path + 1, mnt);
 
-free_dfs_ref:
-	free_dfs_info_param(&referral);
 free_root_path:
 	kfree(root_path);
 free_full_path:


^ permalink raw reply related	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-06 23:30         ` Paulo Alcantara
@ 2020-01-07 16:13           ` Martijn de Gouw
  2020-01-08 17:46             ` Paulo Alcantara
  0 siblings, 1 reply; 12+ messages in thread
From: Martijn de Gouw @ 2020-01-07 16:13 UTC (permalink / raw)
  To: Paulo Alcantara, linux-cifs

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

Hi Paulo,

> Hi Martijn,
>
> Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com> writes:
>
> 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().
>
>Thanks for the logs!
>
>I noticed that we're passing a wrong value for "ip=" down to cifs_mount():
>
>[   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
>
>That is,
>
> 10.1.1.6 -> str02
>  10.1.1.14 -> DC01.Prodrive.nl
>
> which means that ip option should be set to 10.1.1.14.
>
> cifs_mount() will not attempt to resolve the hostname in case we have a
> _valid_ ip address set in the mount options, so we end up connecting to
> the wrong server (str02) and then failing to authenticate.
>
> Well, we could simply set "devname" to the resolved target (str02) and
> we're done with it, but the problem with that is that it will break DFS
> failover - that is, we will not be able to retry the other targets in
> the referral in case we failed to connect it in cifs_mount().
>
> I'm not entirely sure if that's the problem you're facing, but could you
> please try below changes?

I applied your patch to 5.4.6 and it seems to work. I attached
the logs.

Regards, Martijn

[-- Attachment #2: dfs-5.4.6-autofs-ippatch.log --]
[-- Type: application/octet-stream, Size: 31131 bytes --]

[  136.127704] fs/cifs/cifsfs.c: Devname: //prodrive.nl/product flags: 0
[  136.127730] fs/cifs/connect.c: Username: mdg
[  136.127732] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
[  136.127733] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 0 with uid: 0
[  136.127734] fs/cifs/connect.c: UNC: \\prodrive.nl\product
[  136.127738] fs/cifs/connect.c: Socket created
[  136.127739] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[  136.218000] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x000000002e5e09ad/0x00000000a24dc876)
[  136.218003] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 1 with uid: 0
[  136.218004] fs/cifs/connect.c: Existing smb sess not found
[  136.218006] fs/cifs/smb2pdu.c: Negotiate protocol
[  136.218053] fs/cifs/transport.c: Sending smb: smb_len=106
[  136.218092] fs/cifs/connect.c: Demultiplex PID: 997
[  136.308600] fs/cifs/connect.c: RFC1002 header 0xf8
[  136.308606] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[  136.308606] fs/cifs/smb2misc.c: SMB2 len 248
[  136.308615] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[  136.308618] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.308620] fs/cifs/smb2pdu.c: mode 0x3
[  136.308620] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[  136.308623] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[  136.308624] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[  136.308625] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[  136.308625] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[  136.308626] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[  136.308628] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
[  136.308628] fs/cifs/smb2pdu.c: Session Setup
[  136.308629] fs/cifs/smb2pdu.c: sess setup type 5
[  136.308632] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=prodrive.nl;ip4=10.122.0.2;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x3e3
[  136.350435] fs/cifs/transport.c: Sending smb: smb_len=6934
[  136.445159] fs/cifs/connect.c: RFC1002 header 0x5e
[  136.445164] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
[  136.445165] fs/cifs/smb2misc.c: SMB2 len 94
[  136.445174] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
[  136.445176] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.445447] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[  136.445468] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 1) rc = 0
[  136.445471] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 2 with uid: 0
[  136.445471] fs/cifs/smb2pdu.c: TCON
[  136.445549] fs/cifs/transport.c: Sending smb: smb_len=114
[  136.534452] fs/cifs/connect.c: RFC1002 header 0x50
[  136.534457] fs/cifs/smb2misc.c: SMB2 len 80
[  136.534459] fs/cifs/smb2ops.c: add 64 credits total=193
[  136.534467] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
[  136.534471] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.534473] fs/cifs/smb2pdu.c: connection to pipe share
[  136.534474] fs/cifs/smb2pdu.c: validate negotiate
[  136.534475] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  136.534483] fs/cifs/transport.c: Sending smb: smb_len=152
[  136.623924] fs/cifs/connect.c: RFC1002 header 0x88
[  136.623929] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[  136.623930] fs/cifs/smb2misc.c: SMB2 len 136
[  136.623931] fs/cifs/smb2ops.c: add 10 credits total=202
[  136.623940] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=3 state=4
[  136.623944] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.623946] fs/cifs/smb2pdu.c: validate negotiate info successful
[  136.623947] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 2) rc = 0
[  136.623948] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[  136.623951] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 3 with uid: 0
[  136.623951] fs/cifs/smb2pdu.c: TCON
[  136.623958] fs/cifs/transport.c: Sending smb: smb_len=120
[  136.713129] fs/cifs/connect.c: RFC1002 header 0x48
[  136.713134] fs/cifs/smb2misc.c: SMB2 len 73
[  136.713135] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 4
[  136.713137] fs/cifs/smb2ops.c: add 64 credits total=265
[  136.713145] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=4 state=4
[  136.713150] Status code returned 0xc00000cc STATUS_BAD_NETWORK_NAME
[  136.713152] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc00000cc to POSIX err -2
[  136.713153] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.713155] CIFS VFS:  BAD_NETWORK_NAME: \\prodrive.nl\product
[  136.713158] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 3) rc = -2
[  136.713158] fs/cifs/connect.c: Tcon rc = -2
[  136.713160] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
[  136.713161] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
[  136.713161] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
[  136.713162] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \prodrive.nl\product
[  136.713163] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[  136.713164] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \prodrive.nl\product
[  136.713165] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \prodrive.nl\product
[  136.713167] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  136.713175] fs/cifs/transport.c: Sending smb: smb_len=168
[  136.808067] fs/cifs/connect.c: RFC1002 header 0x48
[  136.808072] fs/cifs/smb2misc.c: SMB2 data length 0 offset 0
[  136.808073] fs/cifs/smb2misc.c: SMB2 len 73
[  136.808074] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 5
[  136.849885] fs/cifs/connect.c: RFC1002 header 0x178
[  136.849890] fs/cifs/smb2misc.c: SMB2 data length 264 offset 112
[  136.849890] fs/cifs/smb2misc.c: SMB2 len 376
[  136.849892] fs/cifs/smb2ops.c: add 0 credits total=274
[  136.849900] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=5 state=4
[  136.849904] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.849907] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
[  136.849971] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[  136.849973] fs/cifs/dfs_cache.c: setup_ref: set up new ref
[  136.854069] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC03.Prodrive.nl to 10.1.1.3
[  136.854096] fs/cifs/connect.c: Username: mdg
[  136.854098] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=1
[  136.854099] fs/cifs/connect.c: CIFS VFS: in cifs_free_ipc as Xid: 4 with uid: 0
[  136.854100] fs/cifs/smb2pdu.c: Tree Disconnect
[  136.854100] fs/cifs/connect.c: CIFS VFS: leaving cifs_free_ipc (xid = 4) rc = -5
[  136.854101] fs/cifs/connect.c: failed to disconnect IPC tcon (rc=-5)
[  136.854102] fs/cifs/connect.c: CIFS VFS: in cifs_put_smb_ses as Xid: 5 with uid: 0
[  136.854103] fs/cifs/smb2pdu.c: disconnect session 000000006a8935cd
[  136.854113] fs/cifs/transport.c: Sending smb: smb_len=72
[  136.943308] fs/cifs/connect.c: RFC1002 header 0x44
[  136.943334] fs/cifs/smb2misc.c: SMB2 len 68
[  136.943336] fs/cifs/smb2ops.c: add 2 credits total=275
[  136.943346] fs/cifs/transport.c: cifs_sync_mid_result: cmd=2 mid=6 state=4
[  136.943357] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x000000002e5e09ad/0x00000000a24dc876)
[  136.943360] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 0) rc = 0
[  136.943361] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 6 with uid: 0
[  136.943362] fs/cifs/connect.c: UNC: \\DC03.Prodrive.nl\product
[  136.943397] fs/cifs/connect.c: Socket created
[  136.943398] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[  136.944679] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000a8a74f56/0x00000000f19082dc)
[  136.944681] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 7 with uid: 0
[  136.944682] fs/cifs/connect.c: Existing smb sess not found
[  136.944684] fs/cifs/smb2pdu.c: Negotiate protocol
[  136.944742] fs/cifs/transport.c: Sending smb: smb_len=106
[  136.944797] fs/cifs/connect.c: Demultiplex PID: 1006
[  136.946353] fs/cifs/connect.c: RFC1002 header 0xf8
[  136.946357] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[  136.946357] fs/cifs/smb2misc.c: SMB2 len 248
[  136.946361] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[  136.946365] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.946366] fs/cifs/smb2pdu.c: mode 0x3
[  136.946366] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[  136.946368] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[  136.946369] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[  136.946370] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[  136.946370] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[  136.946371] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[  136.946372] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
[  136.946373] fs/cifs/smb2pdu.c: Session Setup
[  136.946374] fs/cifs/smb2pdu.c: sess setup type 5
[  136.946376] 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=0x3e3
[  136.970808] fs/cifs/transport.c: Sending smb: smb_len=6932
[  136.974794] fs/cifs/connect.c: RFC1002 header 0x5e
[  136.974799] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
[  136.974799] fs/cifs/smb2misc.c: SMB2 len 94
[  136.974807] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
[  136.974808] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.974817] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[  136.974820] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 7) rc = 0
[  136.974822] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 8 with uid: 0
[  136.974823] fs/cifs/smb2pdu.c: TCON
[  136.974918] fs/cifs/transport.c: Sending smb: smb_len=124
[  136.975758] fs/cifs/smb2ops.c: add 64 credits total=193
[  136.975763] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
[  136.975765] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.975766] fs/cifs/smb2pdu.c: connection to pipe share
[  136.975766] fs/cifs/smb2pdu.c: validate negotiate
[  136.975767] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  136.976540] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[  136.976541] fs/cifs/smb2ops.c: add 10 credits total=202
[  136.976547] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[  136.976548] fs/cifs/smb2pdu.c: validate negotiate info successful
[  136.976549] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 8) rc = 0
[  136.976550] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[  136.976552] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 9 with uid: 0
[  136.976552] fs/cifs/smb2pdu.c: TCON
[  136.977343] fs/cifs/smb2ops.c: add 64 credits total=265
[  136.977349] fs/cifs/smb2pdu.c: connection to disk share
[  136.977350] fs/cifs/smb2pdu.c: validate negotiate
[  136.977350] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  136.978933] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[  136.978935] fs/cifs/smb2ops.c: add 10 credits total=274
[  136.978941] fs/cifs/smb2pdu.c: validate negotiate info successful
[  136.978942] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 9) rc = 0
[  136.978942] fs/cifs/connect.c: Tcon rc = 0
[  136.978945] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x00000000f19082dc/0x00000000655aa9a5)
[  136.978946] fs/cifs/smb2pdu.c: create/open
[  136.979795] fs/cifs/smb2misc.c: SMB2 data length 56 offset 152
[  136.979797] fs/cifs/smb2ops.c: add 10 credits total=283
[  136.979825] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  136.980780] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[  136.980781] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[  136.980782] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[  136.980782] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:6142:6b8c:505e:61e3
[  136.980783] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
[  136.980783] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[  136.980784] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[  136.980784] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.3
[  136.980785] fs/cifs/smb2pdu.c: Query FSInfo level 5
[  136.981679] fs/cifs/smb2pdu.c: Query FSInfo level 4
[  136.982424] fs/cifs/smb2pdu.c: Query FSInfo level 1
[  136.983120] fs/cifs/smb2pdu.c: Query FSInfo level 11
[  136.983817] fs/cifs/smb2pdu.c: Close
[  136.984520] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product
[  136.984522] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
[  136.984522] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[  136.984523] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC03.Prodrive.nl\product
[  136.984524] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC03.Prodrive.nl\product
[  136.984526] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  136.985285] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
[  136.985305] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[  136.985308] fs/cifs/connect.c: is_path_remote: full_path: 
[  136.985309] fs/cifs/smb2pdu.c: create/open
[  136.986108] fs/cifs/smb2pdu.c: Close
[  136.986899] fs/cifs/smb2pdu.c: create/open
[  136.987694] fs/cifs/smb2pdu.c: Close
[  136.988408] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
[  136.988410] fs/cifs/dfs_cache.c: dfs_cache_add_vol: fullpath: \\prodrive.nl\product
[  136.988411] fs/cifs/dfs_cache.c: dup_vol: vol->UNC: \\DC03.Prodrive.nl\product
[  136.988413] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 6) rc = 0
[  136.988466] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 10 with uid: 0
[  136.988467] fs/cifs/inode.c: Getting info on 
[  136.989266] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 20
[  136.989277] fs/cifs/inode.c: looking for uniqueid=121
[  136.989283] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 121
[  136.989284] fs/cifs/inode.c: cifs_revalidate_cache: inode 121 is new
[  136.989285] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 10) rc = 0
[  136.989287] fs/cifs/cifsfs.c: Get root dentry for 
[  136.989288] fs/cifs/cifsfs.c: dentry root is: 000000004f317897
[  136.995007] fs/cifs/cifsfs.c: CIFS VFS: in cifs_statfs as Xid: 11 with uid: 0
[  136.996207] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 23
[  136.996217] fs/cifs/cifsfs.c: CIFS VFS: leaving cifs_statfs (xid = 11) rc = 0
[  136.996494] =========================================
[  136.996585] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 12 with uid: 10003
[  136.996586] fs/cifs/dir.c: parent inode = 0x0000000074ab6cc8 name is: KAES6309 and dentry = 0x00000000f6dd221f
[  136.996587] fs/cifs/dir.c: name: \KAES6309
[  136.996588] fs/cifs/dir.c: NULL inode in lookup
[  136.996588] fs/cifs/dir.c: Full path: \KAES6309 inode = 0x00000000a979baf8
[  136.996590] fs/cifs/inode.c: Getting info on \KAES6309
[  136.997333] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 24
[  136.997336] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 25
[  136.997337] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 26
[  136.997344] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
[  136.997346] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
[  136.997349] fs/cifs/inode.c: creating fake fattr for DFS referral
[  136.997350] fs/cifs/inode.c: looking for uniqueid=122
[  136.997354] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 122
[  136.997354] fs/cifs/inode.c: cifs_revalidate_cache: inode 122 is new
[  136.997356] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 12) rc = 0
[  136.997363] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_d_automount
[  136.997364] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_do_automount
[  136.997365] fs/cifs/dir.c: name: \KAES6309
[  136.997365] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: full_path: \\DC03.Prodrive.nl\product\KAES6309
[  136.997366] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: root path: \\DC03.Prodrive.nl\product
[  136.997367] fs/cifs/cifs_dfs_ref.c: CIFS VFS: in cifs_dfs_do_automount as Xid: 13 with uid: 10003
[  136.997368] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
[  136.997369] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product\KAES6309
[  136.997369] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[  136.997370] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC03.Prodrive.nl\product\KAES6309
[  136.997371] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC03.Prodrive.nl\product\KAES6309
[  136.997374] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  136.998437] fs/cifs/misc.c: num_referrals: 1 dfs flags: 0x2 ...
[  136.998444] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[  136.998446] fs/cifs/cifs_dfs_ref.c: CIFS VFS: leaving cifs_dfs_do_automount (xid = 13) rc = 0
[  136.998451] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC03.Prodrive.nl to 10.1.1.3
[  136.998456] fs/cifs/cifsfs.c: Devname: //DC03.Prodrive.nl/product/KAES6309 flags: 67108864
[  136.998480] fs/cifs/connect.c: Username: mdg
[  136.998481] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
[  136.998483] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 14 with uid: 10003
[  136.998483] fs/cifs/connect.c: UNC: \\DC03.Prodrive.nl\product
[  136.998484] fs/cifs/connect.c: Existing tcp session with server found
[  136.998485] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 15 with uid: 10003
[  136.998486] fs/cifs/connect.c: Existing smb sess found (status=1)
[  136.998486] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 15) rc = 0
[  136.998487] fs/cifs/connect.c: Found match on UNC path
[  136.998488] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=2
[  136.998489] fs/cifs/smb2pdu.c: create/open
[  136.999299] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  137.000037] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[  137.000038] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[  137.000038] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[  137.000039] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:6142:6b8c:505e:61e3
[  137.000040] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
[  137.000040] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[  137.000041] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[  137.000042] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.3
[  137.000043] fs/cifs/smb2pdu.c: Query FSInfo level 5
[  137.000707] fs/cifs/smb2pdu.c: Query FSInfo level 4
[  137.001283] fs/cifs/smb2pdu.c: Query FSInfo level 1
[  137.002059] fs/cifs/smb2pdu.c: Query FSInfo level 11
[  137.002769] fs/cifs/smb2pdu.c: Close
[  137.003707] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
[  137.003709] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product
[  137.003710] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product\KAES6309
[  137.003710] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product\KAES6309
[  137.003711] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
[  137.003712] fs/cifs/dfs_cache.c: setup_ref: set up new ref
[  137.005919] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC01.Prodrive.nl to 10.1.1.14
[  137.005945] fs/cifs/connect.c: Username: mdg
[  137.005947] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
[  137.005948] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 14) rc = 0
[  137.005949] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 16 with uid: 10003
[  137.005949] fs/cifs/connect.c: UNC: \\DC01.Prodrive.nl\product
[  137.005954] fs/cifs/connect.c: Socket created
[  137.005955] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[  137.006957] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000a2b4dca0/0x00000000a7cf54d0)
[  137.006959] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 17 with uid: 10003
[  137.006960] fs/cifs/connect.c: Existing smb sess not found
[  137.006961] fs/cifs/smb2pdu.c: Negotiate protocol
[  137.007018] fs/cifs/connect.c: Demultiplex PID: 1009
[  137.008087] fs/cifs/smb2pdu.c: mode 0x3
[  137.008088] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[  137.008091] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
[  137.008092] fs/cifs/smb2pdu.c: Session Setup
[  137.008092] fs/cifs/smb2pdu.c: sess setup type 5
[  137.008095] 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=0x3c3
[  137.035566] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[  137.035569] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 17) rc = 0
[  137.035572] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 18 with uid: 10003
[  137.035573] fs/cifs/smb2pdu.c: TCON
[  137.036412] fs/cifs/smb2pdu.c: connection to pipe share
[  137.036413] fs/cifs/smb2pdu.c: validate negotiate
[  137.036414] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  137.037312] fs/cifs/smb2pdu.c: validate negotiate info successful
[  137.037314] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 18) rc = 0
[  137.037314] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[  137.037316] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 19 with uid: 10003
[  137.037316] fs/cifs/smb2pdu.c: TCON
[  137.038118] fs/cifs/smb2pdu.c: connection to disk share
[  137.038119] fs/cifs/smb2pdu.c: validate negotiate
[  137.038119] fs/cifs/smb2pdu.c: SMB2 IOCTL
[  137.038970] fs/cifs/smb2pdu.c: validate negotiate info successful
[  137.038972] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 19) rc = 0
[  137.038972] fs/cifs/connect.c: Tcon rc = 0
[  137.038975] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x00000000a7cf54d0/0x000000001c0618fa)
[  137.038976] fs/cifs/smb2pdu.c: create/open
[  137.040589] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[  137.040590] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[  137.040591] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[  137.040591] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:7d2b:8e78:9c7c:fc51
[  137.040592] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
[  137.040592] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[  137.040593] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[  137.040594] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.14
[  137.040594] fs/cifs/smb2pdu.c: Query FSInfo level 5
[  137.041182] fs/cifs/smb2pdu.c: Query FSInfo level 4
[  137.043458] fs/cifs/smb2pdu.c: Close
[  137.044105] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC01.Prodrive.nl\product
[  137.044106] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product
[  137.044107] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[  137.044108] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC01.Prodrive.nl\product
[  137.044109] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC01.Prodrive.nl\product
[  137.044857] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
[  137.044866] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[  137.044868] fs/cifs/connect.c: is_path_remote: full_path: \KAES6309
[  137.044870] fs/cifs/smb2pdu.c: create/open
[  137.045617] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 14
[  137.045623] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
[  137.045626] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
[  137.045628] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC01.Prodrive.nl\product\KAES6309
[  137.045628] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC01.Prodrive.nl\product\KAES6309
[  137.045629] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product\KAES6309
[  137.045630] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
[  137.045630] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC01.Prodrive.nl\product\KAES6309
[  137.045631] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC01.Prodrive.nl\product\KAES6309
[  137.046663] fs/cifs/misc.c: num_referrals: 1 dfs flags: 0x2 ...
[  137.046669] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
[  137.046671] fs/cifs/dfs_cache.c: setup_ref: set up new ref
[  137.048545] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: str02 to 10.1.1.6
[  137.048570] fs/cifs/connect.c: Username: mdg
[  137.048572] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
[  137.048573] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 16) rc = 0
[  137.048574] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 20 with uid: 10003
[  137.048574] fs/cifs/connect.c: UNC: \\str02\product1$
[  137.048579] fs/cifs/connect.c: Socket created
[  137.048580] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
[  137.049376] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x000000002233b96e/0x000000008c18fd1d)
[  137.049378] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 21 with uid: 10003
[  137.049379] fs/cifs/connect.c: Existing smb sess not found
[  137.049380] fs/cifs/smb2pdu.c: Negotiate protocol
[  137.049435] fs/cifs/connect.c: Demultiplex PID: 1012
[  137.050549] fs/cifs/smb2pdu.c: mode 0x1
[  137.050550] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[  137.050552] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300077 TimeAdjust: 0
[  137.050553] fs/cifs/smb2pdu.c: Session Setup
[  137.050554] fs/cifs/smb2pdu.c: sess setup type 5
[  137.050556] 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=0x3c3
[  137.076445] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[  137.076450] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 21) rc = 0
[  137.076452] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 22 with uid: 10003
[  137.076453] fs/cifs/smb2pdu.c: TCON
[  137.077858] fs/cifs/smb2pdu.c: connection to pipe share
[  137.077859] fs/cifs/smb2pdu.c: validate negotiate
[  137.079297] fs/cifs/smb2pdu.c: validate negotiate info successful
[  137.079299] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 22) rc = 0
[  137.079300] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[  137.079302] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 23 with uid: 10003
[  137.079302] fs/cifs/smb2pdu.c: TCON
[  137.080133] fs/cifs/smb2pdu.c: connection to disk share
[  137.080133] fs/cifs/smb2pdu.c: validate negotiate
[  137.081124] fs/cifs/smb2pdu.c: validate negotiate info successful
[  137.081125] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 23) rc = 0
[  137.081125] fs/cifs/connect.c: Tcon rc = 0
[  137.081128] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x000000008c18fd1d/0x000000008958ea4b)
[  137.081128] fs/cifs/smb2pdu.c: create/open
[  137.083082] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[  137.083083] fs/cifs/smb2ops.c: parse_server_interfaces: speed 20000000000 bps
[  137.083084] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000001
[  137.083085] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.6
[  137.086177] fs/cifs/smb2pdu.c: Close
[  137.086886] fs/cifs/connect.c: is_path_remote: full_path: \KAES6309
[  137.086887] fs/cifs/smb2pdu.c: create/open
[  137.087764] fs/cifs/smb2pdu.c: Close
[  137.088474] fs/cifs/smb2pdu.c: create/open
[  137.089175] fs/cifs/smb2pdu.c: Close
[  137.089874] fs/cifs/smb2pdu.c: create/open
[  137.090580] fs/cifs/smb2pdu.c: Close
[  137.091293] fs/cifs/connect.c: cifs_put_tcon: tc_count=1
[  137.091294] fs/cifs/connect.c: CIFS VFS: in cifs_put_tcon as Xid: 24 with uid: 10003
[  137.091295] fs/cifs/smb2pdu.c: Tree Disconnect
[  137.091964] fs/cifs/fscache.c: cifs_fscache_release_super_cookie: (0x000000001c0618fa)
[  137.091966] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=1
[  137.091967] fs/cifs/connect.c: CIFS VFS: in cifs_free_ipc as Xid: 25 with uid: 10003
[  137.091967] fs/cifs/smb2pdu.c: Tree Disconnect
[  137.091968] fs/cifs/connect.c: CIFS VFS: leaving cifs_free_ipc (xid = 25) rc = -5
[  137.091968] fs/cifs/connect.c: failed to disconnect IPC tcon (rc=-5)
[  137.091969] fs/cifs/connect.c: CIFS VFS: in cifs_put_smb_ses as Xid: 26 with uid: 10003
[  137.091970] fs/cifs/smb2pdu.c: disconnect session 0000000009690d1e
[  137.092635] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x00000000a2b4dca0/0x00000000a7cf54d0)
[  137.092638] fs/cifs/dfs_cache.c: dfs_cache_add_vol: fullpath: \\DC01.Prodrive.nl\product\KAES6309
[  137.092639] fs/cifs/dfs_cache.c: dup_vol: vol->UNC: \\str02\product1$
[  137.092640] fs/cifs/dfs_cache.c: dup_vol: vol->prepath: KAES6309
[  137.092641] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 20) rc = 0
[  137.092722] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 27 with uid: 10003
[  137.092724] fs/cifs/inode.c: Getting info on 
[  137.093437] fs/cifs/smb2misc.c: Calculated size 190 length 192 mismatch mid 20
[  137.093439] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 21
[  137.093445] fs/cifs/inode.c: looking for uniqueid=123
[  137.093452] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 123
[  137.093452] fs/cifs/inode.c: cifs_revalidate_cache: inode 123 is new
[  137.093453] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 27) rc = 0
[  137.093455] fs/cifs/cifsfs.c: Get root dentry for \KAES6309
[  137.093456] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 28 with uid: 10003
[  137.093457] fs/cifs/dir.c: parent inode = 0x000000001835904b name is: KAES6309 and dentry = 0x0000000024c8b594
[  137.093458] fs/cifs/dir.c: name: \KAES6309
[  137.093459] fs/cifs/dir.c: NULL inode in lookup
[  137.093460] fs/cifs/dir.c: Full path: \KAES6309 inode = 0x00000000a979baf8
[  137.093460] fs/cifs/inode.c: Getting info on \KAES6309
[  137.094200] fs/cifs/inode.c: looking for uniqueid=124
[  137.094203] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 124
[  137.094203] fs/cifs/inode.c: cifs_revalidate_cache: inode 124 is new
[  137.094204] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 28) rc = 0
[  137.094205] fs/cifs/cifsfs.c: dentry root is: 0000000024c8b594
[  137.094211] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: cifs_dfs_do_mount:\DC03.Prodrive.nl\product\KAES6309 , mnt:000000001bbef447
[  137.094211] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_do_automount
[  137.094212] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_d_automount [ok]

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-07 16:13           ` Martijn de Gouw
@ 2020-01-08 17:46             ` Paulo Alcantara
  2020-01-09 12:27               ` Martijn de Gouw
  0 siblings, 1 reply; 12+ messages in thread
From: Paulo Alcantara @ 2020-01-08 17:46 UTC (permalink / raw)
  To: Martijn de Gouw, linux-cifs

Hi Martijn,

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

> I applied your patch to 5.4.6 and it seems to work. I attached
> the logs.
>
> Regards, Martijn
> [  136.127704] fs/cifs/cifsfs.c: Devname: //prodrive.nl/product flags: 0
> [  136.127730] fs/cifs/connect.c: Username: mdg
> [  136.127732] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
> [  136.127733] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 0 with uid: 0
> [  136.127734] fs/cifs/connect.c: UNC: \\prodrive.nl\product
> [  136.127738] fs/cifs/connect.c: Socket created
> [  136.127739] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
> [  136.218000] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x000000002e5e09ad/0x00000000a24dc876)
> [  136.218003] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 1 with uid: 0
> [  136.218004] fs/cifs/connect.c: Existing smb sess not found
> [  136.218006] fs/cifs/smb2pdu.c: Negotiate protocol
> [  136.218053] fs/cifs/transport.c: Sending smb: smb_len=106
> [  136.218092] fs/cifs/connect.c: Demultiplex PID: 997
> [  136.308600] fs/cifs/connect.c: RFC1002 header 0xf8
> [  136.308606] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
> [  136.308606] fs/cifs/smb2misc.c: SMB2 len 248
> [  136.308615] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
> [  136.308618] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.308620] fs/cifs/smb2pdu.c: mode 0x3
> [  136.308620] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
> [  136.308623] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
> [  136.308624] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
> [  136.308625] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
> [  136.308625] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
> [  136.308626] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
> [  136.308628] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
> [  136.308628] fs/cifs/smb2pdu.c: Session Setup
> [  136.308629] fs/cifs/smb2pdu.c: sess setup type 5
> [  136.308632] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=prodrive.nl;ip4=10.122.0.2;sec=krb5;uid=0x2713;creduid=0x2713;user=mdg;pid=0x3e3
> [  136.350435] fs/cifs/transport.c: Sending smb: smb_len=6934
> [  136.445159] fs/cifs/connect.c: RFC1002 header 0x5e
> [  136.445164] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
> [  136.445165] fs/cifs/smb2misc.c: SMB2 len 94
> [  136.445174] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
> [  136.445176] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.445447] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
> [  136.445468] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 1) rc = 0
> [  136.445471] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 2 with uid: 0
> [  136.445471] fs/cifs/smb2pdu.c: TCON
> [  136.445549] fs/cifs/transport.c: Sending smb: smb_len=114
> [  136.534452] fs/cifs/connect.c: RFC1002 header 0x50
> [  136.534457] fs/cifs/smb2misc.c: SMB2 len 80
> [  136.534459] fs/cifs/smb2ops.c: add 64 credits total=193
> [  136.534467] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
> [  136.534471] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.534473] fs/cifs/smb2pdu.c: connection to pipe share
> [  136.534474] fs/cifs/smb2pdu.c: validate negotiate
> [  136.534475] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  136.534483] fs/cifs/transport.c: Sending smb: smb_len=152
> [  136.623924] fs/cifs/connect.c: RFC1002 header 0x88
> [  136.623929] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
> [  136.623930] fs/cifs/smb2misc.c: SMB2 len 136
> [  136.623931] fs/cifs/smb2ops.c: add 10 credits total=202
> [  136.623940] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=3 state=4
> [  136.623944] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.623946] fs/cifs/smb2pdu.c: validate negotiate info successful
> [  136.623947] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 2) rc = 0
> [  136.623948] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
> [  136.623951] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 3 with uid: 0
> [  136.623951] fs/cifs/smb2pdu.c: TCON
> [  136.623958] fs/cifs/transport.c: Sending smb: smb_len=120
> [  136.713129] fs/cifs/connect.c: RFC1002 header 0x48
> [  136.713134] fs/cifs/smb2misc.c: SMB2 len 73
> [  136.713135] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 4
> [  136.713137] fs/cifs/smb2ops.c: add 64 credits total=265
> [  136.713145] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=4 state=4
> [  136.713150] Status code returned 0xc00000cc STATUS_BAD_NETWORK_NAME
> [  136.713152] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc00000cc to POSIX err -2
> [  136.713153] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.713155] CIFS VFS:  BAD_NETWORK_NAME: \\prodrive.nl\product
> [  136.713158] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 3) rc = -2
> [  136.713158] fs/cifs/connect.c: Tcon rc = -2
> [  136.713160] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
> [  136.713161] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
> [  136.713161] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\prodrive.nl\product
> [  136.713162] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \prodrive.nl\product
> [  136.713163] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
> [  136.713164] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \prodrive.nl\product
> [  136.713165] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \prodrive.nl\product
> [  136.713167] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  136.713175] fs/cifs/transport.c: Sending smb: smb_len=168
> [  136.808067] fs/cifs/connect.c: RFC1002 header 0x48
> [  136.808072] fs/cifs/smb2misc.c: SMB2 data length 0 offset 0
> [  136.808073] fs/cifs/smb2misc.c: SMB2 len 73
> [  136.808074] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 5
> [  136.849885] fs/cifs/connect.c: RFC1002 header 0x178
> [  136.849890] fs/cifs/smb2misc.c: SMB2 data length 264 offset 112
> [  136.849890] fs/cifs/smb2misc.c: SMB2 len 376
> [  136.849892] fs/cifs/smb2ops.c: add 0 credits total=274
> [  136.849900] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=5 state=4
> [  136.849904] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.849907] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
> [  136.849971] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
> [  136.849973] fs/cifs/dfs_cache.c: setup_ref: set up new ref
> [  136.854069] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC03.Prodrive.nl to 10.1.1.3
> [  136.854096] fs/cifs/connect.c: Username: mdg
> [  136.854098] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=1
> [  136.854099] fs/cifs/connect.c: CIFS VFS: in cifs_free_ipc as Xid: 4 with uid: 0
> [  136.854100] fs/cifs/smb2pdu.c: Tree Disconnect
> [  136.854100] fs/cifs/connect.c: CIFS VFS: leaving cifs_free_ipc (xid = 4) rc = -5
> [  136.854101] fs/cifs/connect.c: failed to disconnect IPC tcon (rc=-5)
> [  136.854102] fs/cifs/connect.c: CIFS VFS: in cifs_put_smb_ses as Xid: 5 with uid: 0
> [  136.854103] fs/cifs/smb2pdu.c: disconnect session 000000006a8935cd
> [  136.854113] fs/cifs/transport.c: Sending smb: smb_len=72
> [  136.943308] fs/cifs/connect.c: RFC1002 header 0x44
> [  136.943334] fs/cifs/smb2misc.c: SMB2 len 68
> [  136.943336] fs/cifs/smb2ops.c: add 2 credits total=275
> [  136.943346] fs/cifs/transport.c: cifs_sync_mid_result: cmd=2 mid=6 state=4
> [  136.943357] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x000000002e5e09ad/0x00000000a24dc876)
> [  136.943360] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 0) rc = 0
> [  136.943361] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 6 with uid: 0
> [  136.943362] fs/cifs/connect.c: UNC: \\DC03.Prodrive.nl\product
> [  136.943397] fs/cifs/connect.c: Socket created
> [  136.943398] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
> [  136.944679] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000a8a74f56/0x00000000f19082dc)
> [  136.944681] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 7 with uid: 0
> [  136.944682] fs/cifs/connect.c: Existing smb sess not found
> [  136.944684] fs/cifs/smb2pdu.c: Negotiate protocol
> [  136.944742] fs/cifs/transport.c: Sending smb: smb_len=106
> [  136.944797] fs/cifs/connect.c: Demultiplex PID: 1006
> [  136.946353] fs/cifs/connect.c: RFC1002 header 0xf8
> [  136.946357] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
> [  136.946357] fs/cifs/smb2misc.c: SMB2 len 248
> [  136.946361] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
> [  136.946365] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.946366] fs/cifs/smb2pdu.c: mode 0x3
> [  136.946366] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
> [  136.946368] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
> [  136.946369] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
> [  136.946370] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
> [  136.946370] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
> [  136.946371] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
> [  136.946372] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
> [  136.946373] fs/cifs/smb2pdu.c: Session Setup
> [  136.946374] fs/cifs/smb2pdu.c: sess setup type 5
> [  136.946376] 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=0x3e3
> [  136.970808] fs/cifs/transport.c: Sending smb: smb_len=6932
> [  136.974794] fs/cifs/connect.c: RFC1002 header 0x5e
> [  136.974799] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
> [  136.974799] fs/cifs/smb2misc.c: SMB2 len 94
> [  136.974807] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
> [  136.974808] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.974817] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
> [  136.974820] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 7) rc = 0
> [  136.974822] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 8 with uid: 0
> [  136.974823] fs/cifs/smb2pdu.c: TCON
> [  136.974918] fs/cifs/transport.c: Sending smb: smb_len=124
> [  136.975758] fs/cifs/smb2ops.c: add 64 credits total=193
> [  136.975763] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
> [  136.975765] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.975766] fs/cifs/smb2pdu.c: connection to pipe share
> [  136.975766] fs/cifs/smb2pdu.c: validate negotiate
> [  136.975767] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  136.976540] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
> [  136.976541] fs/cifs/smb2ops.c: add 10 credits total=202
> [  136.976547] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
> [  136.976548] fs/cifs/smb2pdu.c: validate negotiate info successful
> [  136.976549] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 8) rc = 0
> [  136.976550] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
> [  136.976552] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 9 with uid: 0
> [  136.976552] fs/cifs/smb2pdu.c: TCON
> [  136.977343] fs/cifs/smb2ops.c: add 64 credits total=265
> [  136.977349] fs/cifs/smb2pdu.c: connection to disk share
> [  136.977350] fs/cifs/smb2pdu.c: validate negotiate
> [  136.977350] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  136.978933] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
> [  136.978935] fs/cifs/smb2ops.c: add 10 credits total=274
> [  136.978941] fs/cifs/smb2pdu.c: validate negotiate info successful
> [  136.978942] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 9) rc = 0
> [  136.978942] fs/cifs/connect.c: Tcon rc = 0
> [  136.978945] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x00000000f19082dc/0x00000000655aa9a5)
> [  136.978946] fs/cifs/smb2pdu.c: create/open
> [  136.979795] fs/cifs/smb2misc.c: SMB2 data length 56 offset 152
> [  136.979797] fs/cifs/smb2ops.c: add 10 credits total=283
> [  136.979825] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  136.980780] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
> [  136.980781] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
> [  136.980782] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
> [  136.980782] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:6142:6b8c:505e:61e3
> [  136.980783] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
> [  136.980783] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
> [  136.980784] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
> [  136.980784] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.3
> [  136.980785] fs/cifs/smb2pdu.c: Query FSInfo level 5
> [  136.981679] fs/cifs/smb2pdu.c: Query FSInfo level 4
> [  136.982424] fs/cifs/smb2pdu.c: Query FSInfo level 1
> [  136.983120] fs/cifs/smb2pdu.c: Query FSInfo level 11
> [  136.983817] fs/cifs/smb2pdu.c: Close
> [  136.984520] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product
> [  136.984522] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
> [  136.984522] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
> [  136.984523] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC03.Prodrive.nl\product
> [  136.984524] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC03.Prodrive.nl\product
> [  136.984526] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  136.985285] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
> [  136.985305] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
> [  136.985308] fs/cifs/connect.c: is_path_remote: full_path: 
> [  136.985309] fs/cifs/smb2pdu.c: create/open
> [  136.986108] fs/cifs/smb2pdu.c: Close
> [  136.986899] fs/cifs/smb2pdu.c: create/open
> [  136.987694] fs/cifs/smb2pdu.c: Close
> [  136.988408] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
> [  136.988410] fs/cifs/dfs_cache.c: dfs_cache_add_vol: fullpath: \\prodrive.nl\product
> [  136.988411] fs/cifs/dfs_cache.c: dup_vol: vol->UNC: \\DC03.Prodrive.nl\product
> [  136.988413] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 6) rc = 0
> [  136.988466] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 10 with uid: 0
> [  136.988467] fs/cifs/inode.c: Getting info on 
> [  136.989266] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 20
> [  136.989277] fs/cifs/inode.c: looking for uniqueid=121
> [  136.989283] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 121
> [  136.989284] fs/cifs/inode.c: cifs_revalidate_cache: inode 121 is new
> [  136.989285] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 10) rc = 0
> [  136.989287] fs/cifs/cifsfs.c: Get root dentry for 
> [  136.989288] fs/cifs/cifsfs.c: dentry root is: 000000004f317897
> [  136.995007] fs/cifs/cifsfs.c: CIFS VFS: in cifs_statfs as Xid: 11 with uid: 0
> [  136.996207] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 23
> [  136.996217] fs/cifs/cifsfs.c: CIFS VFS: leaving cifs_statfs (xid = 11) rc = 0
> [  136.996494] =========================================
> [  136.996585] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 12 with uid: 10003
> [  136.996586] fs/cifs/dir.c: parent inode = 0x0000000074ab6cc8 name is: KAES6309 and dentry = 0x00000000f6dd221f
> [  136.996587] fs/cifs/dir.c: name: \KAES6309
> [  136.996588] fs/cifs/dir.c: NULL inode in lookup
> [  136.996588] fs/cifs/dir.c: Full path: \KAES6309 inode = 0x00000000a979baf8
> [  136.996590] fs/cifs/inode.c: Getting info on \KAES6309
> [  136.997333] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 24
> [  136.997336] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 25
> [  136.997337] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 26
> [  136.997344] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
> [  136.997346] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
> [  136.997349] fs/cifs/inode.c: creating fake fattr for DFS referral
> [  136.997350] fs/cifs/inode.c: looking for uniqueid=122
> [  136.997354] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 122
> [  136.997354] fs/cifs/inode.c: cifs_revalidate_cache: inode 122 is new
> [  136.997356] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 12) rc = 0
> [  136.997363] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_d_automount
> [  136.997364] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_do_automount
> [  136.997365] fs/cifs/dir.c: name: \KAES6309
> [  136.997365] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: full_path: \\DC03.Prodrive.nl\product\KAES6309
> [  136.997366] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: root path: \\DC03.Prodrive.nl\product
> [  136.997367] fs/cifs/cifs_dfs_ref.c: CIFS VFS: in cifs_dfs_do_automount as Xid: 13 with uid: 10003
> [  136.997368] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
> [  136.997369] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product\KAES6309
> [  136.997369] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
> [  136.997370] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC03.Prodrive.nl\product\KAES6309
> [  136.997371] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC03.Prodrive.nl\product\KAES6309
> [  136.997374] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  136.998437] fs/cifs/misc.c: num_referrals: 1 dfs flags: 0x2 ...
> [  136.998444] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
> [  136.998446] fs/cifs/cifs_dfs_ref.c: CIFS VFS: leaving cifs_dfs_do_automount (xid = 13) rc = 0
> [  136.998451] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC03.Prodrive.nl to 10.1.1.3
> [  136.998456] fs/cifs/cifsfs.c: Devname: //DC03.Prodrive.nl/product/KAES6309 flags: 67108864
> [  136.998480] fs/cifs/connect.c: Username: mdg
> [  136.998481] fs/cifs/connect.c: file mode: 0x180  dir mode: 0x1c0
> [  136.998483] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 14 with uid: 10003
> [  136.998483] fs/cifs/connect.c: UNC: \\DC03.Prodrive.nl\product
> [  136.998484] fs/cifs/connect.c: Existing tcp session with server found
> [  136.998485] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 15 with uid: 10003
> [  136.998486] fs/cifs/connect.c: Existing smb sess found (status=1)
> [  136.998486] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 15) rc = 0
> [  136.998487] fs/cifs/connect.c: Found match on UNC path
> [  136.998488] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=2
> [  136.998489] fs/cifs/smb2pdu.c: create/open
> [  136.999299] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  137.000037] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
> [  137.000038] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
> [  137.000038] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
> [  137.000039] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:6142:6b8c:505e:61e3
> [  137.000040] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
> [  137.000040] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
> [  137.000041] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
> [  137.000042] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.3
> [  137.000043] fs/cifs/smb2pdu.c: Query FSInfo level 5
> [  137.000707] fs/cifs/smb2pdu.c: Query FSInfo level 4
> [  137.001283] fs/cifs/smb2pdu.c: Query FSInfo level 1
> [  137.002059] fs/cifs/smb2pdu.c: Query FSInfo level 11
> [  137.002769] fs/cifs/smb2pdu.c: Close
> [  137.003707] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
> [  137.003709] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product
> [  137.003710] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product\KAES6309
> [  137.003710] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC03.Prodrive.nl\product\KAES6309
> [  137.003711] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC03.Prodrive.nl\product
> [  137.003712] fs/cifs/dfs_cache.c: setup_ref: set up new ref
> [  137.005919] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC01.Prodrive.nl to 10.1.1.14
> [  137.005945] fs/cifs/connect.c: Username: mdg
> [  137.005947] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
> [  137.005948] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 14) rc = 0
> [  137.005949] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 16 with uid: 10003
> [  137.005949] fs/cifs/connect.c: UNC: \\DC01.Prodrive.nl\product
> [  137.005954] fs/cifs/connect.c: Socket created
> [  137.005955] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
> [  137.006957] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x00000000a2b4dca0/0x00000000a7cf54d0)
> [  137.006959] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 17 with uid: 10003
> [  137.006960] fs/cifs/connect.c: Existing smb sess not found
> [  137.006961] fs/cifs/smb2pdu.c: Negotiate protocol
> [  137.007018] fs/cifs/connect.c: Demultiplex PID: 1009
> [  137.008087] fs/cifs/smb2pdu.c: mode 0x3
> [  137.008088] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
> [  137.008091] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300067 TimeAdjust: 0
> [  137.008092] fs/cifs/smb2pdu.c: Session Setup
> [  137.008092] fs/cifs/smb2pdu.c: sess setup type 5
> [  137.008095] 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=0x3c3
> [  137.035566] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
> [  137.035569] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 17) rc = 0
> [  137.035572] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 18 with uid: 10003
> [  137.035573] fs/cifs/smb2pdu.c: TCON
> [  137.036412] fs/cifs/smb2pdu.c: connection to pipe share
> [  137.036413] fs/cifs/smb2pdu.c: validate negotiate
> [  137.036414] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  137.037312] fs/cifs/smb2pdu.c: validate negotiate info successful
> [  137.037314] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 18) rc = 0
> [  137.037314] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
> [  137.037316] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 19 with uid: 10003
> [  137.037316] fs/cifs/smb2pdu.c: TCON
> [  137.038118] fs/cifs/smb2pdu.c: connection to disk share
> [  137.038119] fs/cifs/smb2pdu.c: validate negotiate
> [  137.038119] fs/cifs/smb2pdu.c: SMB2 IOCTL
> [  137.038970] fs/cifs/smb2pdu.c: validate negotiate info successful
> [  137.038972] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 19) rc = 0
> [  137.038972] fs/cifs/connect.c: Tcon rc = 0
> [  137.038975] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x00000000a7cf54d0/0x000000001c0618fa)
> [  137.038976] fs/cifs/smb2pdu.c: create/open
> [  137.040589] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
> [  137.040590] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
> [  137.040591] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
> [  137.040591] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:7d2b:8e78:9c7c:fc51
> [  137.040592] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
> [  137.040592] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
> [  137.040593] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
> [  137.040594] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.14
> [  137.040594] fs/cifs/smb2pdu.c: Query FSInfo level 5
> [  137.041182] fs/cifs/smb2pdu.c: Query FSInfo level 4
> [  137.043458] fs/cifs/smb2pdu.c: Close
> [  137.044105] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC01.Prodrive.nl\product
> [  137.044106] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product
> [  137.044107] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
> [  137.044108] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC01.Prodrive.nl\product
> [  137.044109] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC01.Prodrive.nl\product
> [  137.044857] fs/cifs/misc.c: num_referrals: 2 dfs flags: 0x3 ...
> [  137.044866] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
> [  137.044868] fs/cifs/connect.c: is_path_remote: full_path: \KAES6309
> [  137.044870] fs/cifs/smb2pdu.c: create/open
> [  137.045617] fs/cifs/smb2misc.c: Calculated size 73 length 72 mismatch mid 14
> [  137.045623] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
> [  137.045626] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
> [  137.045628] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC01.Prodrive.nl\product\KAES6309
> [  137.045628] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\DC01.Prodrive.nl\product\KAES6309
> [  137.045629] fs/cifs/dfs_cache.c: do_dfs_cache_find: search path: \DC01.Prodrive.nl\product\KAES6309
> [  137.045630] fs/cifs/dfs_cache.c: do_dfs_cache_find: cache miss
> [  137.045630] fs/cifs/dfs_cache.c: do_dfs_cache_find: DFS referral request for \DC01.Prodrive.nl\product\KAES6309
> [  137.045631] fs/cifs/smb2ops.c: smb2_get_dfs_refer: path: \DC01.Prodrive.nl\product\KAES6309
> [  137.046663] fs/cifs/misc.c: num_referrals: 1 dfs flags: 0x2 ...
> [  137.046669] fs/cifs/dfs_cache.c: do_dfs_cache_find: new cache entry
> [  137.046671] fs/cifs/dfs_cache.c: setup_ref: set up new ref
> [  137.048545] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: str02 to 10.1.1.6
> [  137.048570] fs/cifs/connect.c: Username: mdg
> [  137.048572] fs/cifs/connect.c: cifs_put_tcon: tc_count=2
> [  137.048573] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns (xid = 16) rc = 0
> [  137.048574] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as Xid: 20 with uid: 10003
> [  137.048574] fs/cifs/connect.c: UNC: \\str02\product1$
> [  137.048579] fs/cifs/connect.c: Socket created
> [  137.048580] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072 rcvtimeo 0x6d6
> [  137.049376] fs/cifs/fscache.c: cifs_fscache_get_client_cookie: (0x000000002233b96e/0x000000008c18fd1d)
> [  137.049378] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 21 with uid: 10003
> [  137.049379] fs/cifs/connect.c: Existing smb sess not found
> [  137.049380] fs/cifs/smb2pdu.c: Negotiate protocol
> [  137.049435] fs/cifs/connect.c: Demultiplex PID: 1012
> [  137.050549] fs/cifs/smb2pdu.c: mode 0x1
> [  137.050550] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
> [  137.050552] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300077 TimeAdjust: 0
> [  137.050553] fs/cifs/smb2pdu.c: Session Setup
> [  137.050554] fs/cifs/smb2pdu.c: sess setup type 5
> [  137.050556] 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=0x3c3
> [  137.076445] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
> [  137.076450] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 21) rc = 0
> [  137.076452] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 22 with uid: 10003
> [  137.076453] fs/cifs/smb2pdu.c: TCON
> [  137.077858] fs/cifs/smb2pdu.c: connection to pipe share
> [  137.077859] fs/cifs/smb2pdu.c: validate negotiate
> [  137.079297] fs/cifs/smb2pdu.c: validate negotiate info successful
> [  137.079299] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 22) rc = 0
> [  137.079300] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
> [  137.079302] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 23 with uid: 10003
> [  137.079302] fs/cifs/smb2pdu.c: TCON
> [  137.080133] fs/cifs/smb2pdu.c: connection to disk share
> [  137.080133] fs/cifs/smb2pdu.c: validate negotiate
> [  137.081124] fs/cifs/smb2pdu.c: validate negotiate info successful
> [  137.081125] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 23) rc = 0
> [  137.081125] fs/cifs/connect.c: Tcon rc = 0
> [  137.081128] fs/cifs/fscache.c: cifs_fscache_get_super_cookie: (0x000000008c18fd1d/0x000000008958ea4b)
> [  137.081128] fs/cifs/smb2pdu.c: create/open
> [  137.083082] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
> [  137.083083] fs/cifs/smb2ops.c: parse_server_interfaces: speed 20000000000 bps
> [  137.083084] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000001
> [  137.083085] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 10.1.1.6
> [  137.086177] fs/cifs/smb2pdu.c: Close
> [  137.086886] fs/cifs/connect.c: is_path_remote: full_path: \KAES6309
> [  137.086887] fs/cifs/smb2pdu.c: create/open
> [  137.087764] fs/cifs/smb2pdu.c: Close
> [  137.088474] fs/cifs/smb2pdu.c: create/open
> [  137.089175] fs/cifs/smb2pdu.c: Close
> [  137.089874] fs/cifs/smb2pdu.c: create/open
> [  137.090580] fs/cifs/smb2pdu.c: Close
> [  137.091293] fs/cifs/connect.c: cifs_put_tcon: tc_count=1
> [  137.091294] fs/cifs/connect.c: CIFS VFS: in cifs_put_tcon as Xid: 24 with uid: 10003
> [  137.091295] fs/cifs/smb2pdu.c: Tree Disconnect
> [  137.091964] fs/cifs/fscache.c: cifs_fscache_release_super_cookie: (0x000000001c0618fa)
> [  137.091966] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=1
> [  137.091967] fs/cifs/connect.c: CIFS VFS: in cifs_free_ipc as Xid: 25 with uid: 10003
> [  137.091967] fs/cifs/smb2pdu.c: Tree Disconnect
> [  137.091968] fs/cifs/connect.c: CIFS VFS: leaving cifs_free_ipc (xid = 25) rc = -5
> [  137.091968] fs/cifs/connect.c: failed to disconnect IPC tcon (rc=-5)
> [  137.091969] fs/cifs/connect.c: CIFS VFS: in cifs_put_smb_ses as Xid: 26 with uid: 10003
> [  137.091970] fs/cifs/smb2pdu.c: disconnect session 0000000009690d1e
> [  137.092635] fs/cifs/fscache.c: cifs_fscache_release_client_cookie: (0x00000000a2b4dca0/0x00000000a7cf54d0)
> [  137.092638] fs/cifs/dfs_cache.c: dfs_cache_add_vol: fullpath: \\DC01.Prodrive.nl\product\KAES6309
> [  137.092639] fs/cifs/dfs_cache.c: dup_vol: vol->UNC: \\str02\product1$
> [  137.092640] fs/cifs/dfs_cache.c: dup_vol: vol->prepath: KAES6309
> [  137.092641] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 20) rc = 0
> [  137.092722] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 27 with uid: 10003
> [  137.092724] fs/cifs/inode.c: Getting info on 
> [  137.093437] fs/cifs/smb2misc.c: Calculated size 190 length 192 mismatch mid 20
> [  137.093439] fs/cifs/smb2misc.c: Calculated size 124 length 128 mismatch mid 21
> [  137.093445] fs/cifs/inode.c: looking for uniqueid=123
> [  137.093452] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 123
> [  137.093452] fs/cifs/inode.c: cifs_revalidate_cache: inode 123 is new
> [  137.093453] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 27) rc = 0
> [  137.093455] fs/cifs/cifsfs.c: Get root dentry for \KAES6309
> [  137.093456] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 28 with uid: 10003
> [  137.093457] fs/cifs/dir.c: parent inode = 0x000000001835904b name is: KAES6309 and dentry = 0x0000000024c8b594
> [  137.093458] fs/cifs/dir.c: name: \KAES6309
> [  137.093459] fs/cifs/dir.c: NULL inode in lookup
> [  137.093460] fs/cifs/dir.c: Full path: \KAES6309 inode = 0x00000000a979baf8
> [  137.093460] fs/cifs/inode.c: Getting info on \KAES6309
> [  137.094200] fs/cifs/inode.c: looking for uniqueid=124
> [  137.094203] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 124
> [  137.094203] fs/cifs/inode.c: cifs_revalidate_cache: inode 124 is new
> [  137.094204] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 28) rc = 0
> [  137.094205] fs/cifs/cifsfs.c: dentry root is: 0000000024c8b594
> [  137.094211] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: cifs_dfs_do_mount:\DC03.Prodrive.nl\product\KAES6309 , mnt:000000001bbef447
> [  137.094211] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_do_automount
> [  137.094212] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_d_automount [ok]

Thanks for testing it!

So far so good?

Let me know so I can prepare a patch for upstream.

Thanks,

Paulo

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-08 17:46             ` Paulo Alcantara
@ 2020-01-09 12:27               ` Martijn de Gouw
  2020-01-09 13:06                 ` Paulo Alcantara
  0 siblings, 1 reply; 12+ messages in thread
From: Martijn de Gouw @ 2020-01-09 12:27 UTC (permalink / raw)
  To: Paulo Alcantara, linux-cifs

Hi Paulo

On 08-01-2020 18:46, Paulo Alcantara wrote:
> Hi Martijn,
> 
> Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com> writes:
> 
>> I applied your patch to 5.4.6 and it seems to work. I attached
>> the logs.
>>
>> Regards, Martijn

[..lots of logging..]

>> [  137.094211] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: cifs_dfs_do_mount:\DC03.Prodrive.nl\product\KAES6309 , mnt:000000001bbef447
>> [  137.094211] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_do_automount
>> [  137.094212] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_d_automount [ok]
> 
> Thanks for testing it!
> 
> So far so good?
> 
> Let me know so I can prepare a patch for upstream.

Yes, so far so good. Thanks a lot for the quick response! Not a trivial 
patch as far I as i can judge.

Also the machine we have running with your other DFS patches is running 
for 8 weeks now and survived several relocations of our dfs shares and 
adding/removal of DCs!

Is there any news on the acceptance of your [PATCH v4 0/6] DFS fixes?

Regards, Martijn

-- 
Martijn de Gouw
Designer
Prodrive Technologies
Mobile: +31 63 17 76 161
Phone:  +31 40 26 76 200

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-09 12:27               ` Martijn de Gouw
@ 2020-01-09 13:06                 ` Paulo Alcantara
  2020-01-30 17:46                   ` Jacob Shivers
  0 siblings, 1 reply; 12+ messages in thread
From: Paulo Alcantara @ 2020-01-09 13:06 UTC (permalink / raw)
  To: Martijn de Gouw, linux-cifs

Hi Martijn,

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

> Yes, so far so good. Thanks a lot for the quick response! Not a trivial 
> patch as far I as i can judge.

Cool! Thanks for the confirmation. Just sent a patch with this fix, BTW.

> Also the machine we have running with your other DFS patches is running 
> for 8 weeks now and survived several relocations of our dfs shares and 
> adding/removal of DCs!
>
> Is there any news on the acceptance of your [PATCH v4 0/6] DFS fixes?

I don't have any news, but I'll talk to Steve and Aurelien about them.

Thanks,
Paulo

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-09 13:06                 ` Paulo Alcantara
@ 2020-01-30 17:46                   ` Jacob Shivers
  2020-01-30 18:55                     ` Steve French
  0 siblings, 1 reply; 12+ messages in thread
From: Jacob Shivers @ 2020-01-30 17:46 UTC (permalink / raw)
  To: Paulo Alcantara; +Cc: Martijn de Gouw, linux-cifs

Hello Paulo,

I ran into this issue and noted that I can reproduce this 100% of the
time with a Samba SMB target. I tried with Windows SMB targets, even
when they are not part of the direct DFS namespace, but I have so far
been unable to reproduce that way.

Hello Martijn,
Would you mind stating who the provider is for the impacted SMB target
in your environment?

Thanks,
Jacob

On Thu, Jan 9, 2020 at 8:06 AM Paulo Alcantara <pc@cjr.nz> wrote:
>
> Hi Martijn,
>
> Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com> writes:
>
> > Yes, so far so good. Thanks a lot for the quick response! Not a trivial
> > patch as far I as i can judge.
>
> Cool! Thanks for the confirmation. Just sent a patch with this fix, BTW.
>
> > Also the machine we have running with your other DFS patches is running
> > for 8 weeks now and survived several relocations of our dfs shares and
> > adding/removal of DCs!
> >
> > Is there any news on the acceptance of your [PATCH v4 0/6] DFS fixes?
>
> I don't have any news, but I'll talk to Steve and Aurelien about them.
>
> Thanks,
> Paulo
>


^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-30 17:46                   ` Jacob Shivers
@ 2020-01-30 18:55                     ` Steve French
  2020-01-30 19:06                       ` Jacob Shivers
  0 siblings, 1 reply; 12+ messages in thread
From: Steve French @ 2020-01-30 18:55 UTC (permalink / raw)
  To: Jacob Shivers; +Cc: Paulo Alcantara, Martijn de Gouw, linux-cifs

Fix is already upstream, merged into mainline Linux (commit
5739375ee4230980166807d347cc21c305532bbc)

On Thu, Jan 30, 2020 at 11:47 AM Jacob Shivers <jshivers@redhat.com> wrote:
>
> Hello Paulo,
>
> I ran into this issue and noted that I can reproduce this 100% of the
> time with a Samba SMB target. I tried with Windows SMB targets, even
> when they are not part of the direct DFS namespace, but I have so far
> been unable to reproduce that way.
>
> Hello Martijn,
> Would you mind stating who the provider is for the impacted SMB target
> in your environment?
>
> Thanks,
> Jacob
>
> On Thu, Jan 9, 2020 at 8:06 AM Paulo Alcantara <pc@cjr.nz> wrote:
> >
> > Hi Martijn,
> >
> > Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com> writes:
> >
> > > Yes, so far so good. Thanks a lot for the quick response! Not a trivial
> > > patch as far I as i can judge.
> >
> > Cool! Thanks for the confirmation. Just sent a patch with this fix, BTW.
> >
> > > Also the machine we have running with your other DFS patches is running
> > > for 8 weeks now and survived several relocations of our dfs shares and
> > > adding/removal of DCs!
> > >
> > > Is there any news on the acceptance of your [PATCH v4 0/6] DFS fixes?
> >
> > I don't have any news, but I'll talk to Steve and Aurelien about them.
> >
> > Thanks,
> > Paulo
> >
>


-- 
Thanks,

Steve

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: cifs.upcall requests ticket for wrong host when using dfs
  2020-01-30 18:55                     ` Steve French
@ 2020-01-30 19:06                       ` Jacob Shivers
  0 siblings, 0 replies; 12+ messages in thread
From: Jacob Shivers @ 2020-01-30 19:06 UTC (permalink / raw)
  To: Steve French; +Cc: Paulo Alcantara, Martijn de Gouw, linux-cifs

I missed that.
I just checked again and I completely overlooked this.

Sorry for the confusion.


On Thu, Jan 30, 2020 at 1:55 PM Steve French <smfrench@gmail.com> wrote:
>
> Fix is already upstream, merged into mainline Linux (commit
> 5739375ee4230980166807d347cc21c305532bbc)
>
> On Thu, Jan 30, 2020 at 11:47 AM Jacob Shivers <jshivers@redhat.com> wrote:
> >
> > Hello Paulo,
> >
> > I ran into this issue and noted that I can reproduce this 100% of the
> > time with a Samba SMB target. I tried with Windows SMB targets, even
> > when they are not part of the direct DFS namespace, but I have so far
> > been unable to reproduce that way.
> >
> > Hello Martijn,
> > Would you mind stating who the provider is for the impacted SMB target
> > in your environment?
> >
> > Thanks,
> > Jacob
> >
> > On Thu, Jan 9, 2020 at 8:06 AM Paulo Alcantara <pc@cjr.nz> wrote:
> > >
> > > Hi Martijn,
> > >
> > > Martijn de Gouw <martijn.de.gouw@prodrive-technologies.com> writes:
> > >
> > > > Yes, so far so good. Thanks a lot for the quick response! Not a trivial
> > > > patch as far I as i can judge.
> > >
> > > Cool! Thanks for the confirmation. Just sent a patch with this fix, BTW.
> > >
> > > > Also the machine we have running with your other DFS patches is running
> > > > for 8 weeks now and survived several relocations of our dfs shares and
> > > > adding/removal of DCs!
> > > >
> > > > Is there any news on the acceptance of your [PATCH v4 0/6] DFS fixes?
> > >
> > > I don't have any news, but I'll talk to Steve and Aurelien about them.
> > >
> > > Thanks,
> > > Paulo
> > >
> >
>
>
> --
> Thanks,
>
> Steve
>


^ permalink raw reply	[flat|nested] 12+ messages in thread

end of thread, other threads:[~2020-01-30 19:07 UTC | newest]

Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-01-03 14:11 cifs.upcall requests ticket for wrong host when using dfs Martijn de Gouw
     [not found] ` <87png0boej.fsf@cjr.nz>
2020-01-03 16:30   ` Martijn de Gouw
2020-01-03 20:14     ` Paulo Alcantara
2020-01-06 15:07       ` Martijn de Gouw
2020-01-06 23:30         ` Paulo Alcantara
2020-01-07 16:13           ` Martijn de Gouw
2020-01-08 17:46             ` Paulo Alcantara
2020-01-09 12:27               ` Martijn de Gouw
2020-01-09 13:06                 ` Paulo Alcantara
2020-01-30 17:46                   ` Jacob Shivers
2020-01-30 18:55                     ` Steve French
2020-01-30 19:06                       ` Jacob Shivers

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).