Hi Pavel,
> It seems that you didn't do:
>
> # echo 'module cifs +p' > /sys/kernel/debug/dynamic_debug/control
> # echo 'file fs/cifs/* +p' > /sys/kernel/debug/dynamic_debug/control
>
> which is essential to get debug logs.The logs you obtained show only
> error codes which is not very informative. Please repeat the repro
> with the debug logs enabled.
Yes. Thought a higher-level view would be a good first step for you.
I append the dmesg output with debug enabled. I had to redact specifics
about our servers (names, IPs) and also removed the SPNEGO dump blobs.
The dumps reflect listing the directory (in DATA) two times: Once it
succeeded, second time it hung.
Thanks and best regards,
Bernd
[ 88.029589] fs/cifs/cifsfs.c: Devname: //dc1/Group flags: 0
[ 88.029600] address conversion returned 1 for xxx
[ 88.029617] fs/cifs/connect.c: iocharset set to utf8
[ 88.029626] fs/cifs/connect.c: Username: root
[ 88.031066] fs/cifs/connect.c: file mode: 0x180 dir mode: 0x1c0
[ 88.031069] fs/cifs/connect.c: CIFS VFS: in cifs_mount as Xid: 0 with uid: 0
[ 88.031070] fs/cifs/connect.c: UNC: \\dc1\Group
[ 88.031083] fs/cifs/connect.c: Socket created
[ 88.031085] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
[ 88.031432] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 1 with uid: 0
[ 88.031434] fs/cifs/connect.c: Demultiplex PID: 4511
[ 88.031436] fs/cifs/connect.c: Existing smb sess not found
[ 88.031439] fs/cifs/smb2pdu.c: Negotiate protocol
[ 88.031449] fs/cifs/transport.c: Sending smb: smb_len=108
[ 88.031999] fs/cifs/connect.c: RFC1002 header 0xf8
[ 88.032003] fs/cifs/smb2misc.c: SMB2 data length 120 offset 128
[ 88.032004] fs/cifs/smb2misc.c: SMB2 len 248
[ 88.032010] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0 mid=0 state=4
[ 88.032011] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.032013] fs/cifs/smb2pdu.c: mode 0x3
[ 88.032014] fs/cifs/smb2pdu.c: negotiated smb3.02 dialect
[ 88.032018] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[ 88.032020] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[ 88.032021] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[ 88.032023] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[ 88.032024] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[ 88.032026] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300047 TimeAdjust: 0
[ 88.032027] fs/cifs/smb2pdu.c: Session Setup
[ 88.032028] fs/cifs/smb2pdu.c: sess setup type 5
[ 88.032033] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=dc1;ip4=xxx;sec=krb5;uid=0x3e8;creduid=0x3e8;user=root;pid=0x119b
[ 88.042116] SPNEGO reply blob:: dump of 1024 bytes of data at 0x0000000039d223fb
...
[ 88.042230] fs/cifs/transport.c: Sending smb: smb_len=2427
[ 88.043566] fs/cifs/connect.c: RFC1002 header 0x5e
[ 88.043571] fs/cifs/smb2misc.c: SMB2 data length 22 offset 72
[ 88.043572] fs/cifs/smb2misc.c: SMB2 len 94
[ 88.043580] fs/cifs/transport.c: cifs_sync_mid_result: cmd=1 mid=1 state=4
[ 88.043583] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.049688] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[ 88.049696] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 1) rc = 0
[ 88.051132] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 2 with uid: 0
[ 88.051135] fs/cifs/smb2pdu.c: TCON
[ 88.051156] fs/cifs/transport.c: Sending smb: smb_len=120
[ 88.051478] fs/cifs/connect.c: RFC1002 header 0x50
[ 88.051484] fs/cifs/smb2misc.c: SMB2 len 80
[ 88.051492] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=2 state=4
[ 88.051497] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.051499] fs/cifs/smb2pdu.c: connection to pipe share
[ 88.051500] fs/cifs/smb2pdu.c: validate negotiate
[ 88.051502] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.051509] fs/cifs/transport.c: Sending smb: smb_len=152
[ 88.051782] fs/cifs/connect.c: RFC1002 header 0x88
[ 88.051786] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[ 88.051787] fs/cifs/smb2misc.c: SMB2 len 136
[ 88.051794] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=3 state=4
[ 88.051799] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.051802] fs/cifs/smb2pdu.c: validate negotiate info successful
[ 88.051804] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 2) rc = 0
[ 88.051805] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[ 88.051808] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 3 with uid: 0
[ 88.051809] fs/cifs/smb2pdu.c: TCON
[ 88.051817] fs/cifs/transport.c: Sending smb: smb_len=158
[ 88.052078] fs/cifs/connect.c: RFC1002 header 0x50
[ 88.052081] fs/cifs/smb2misc.c: SMB2 len 80
[ 88.052087] fs/cifs/transport.c: cifs_sync_mid_result: cmd=3 mid=4 state=4
[ 88.052091] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.052092] fs/cifs/smb2pdu.c: connection to disk share
[ 88.052093] fs/cifs/smb2pdu.c: validate negotiate
[ 88.052094] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.052100] fs/cifs/transport.c: Sending smb: smb_len=152
[ 88.052393] fs/cifs/connect.c: RFC1002 header 0x88
[ 88.052398] fs/cifs/smb2misc.c: SMB2 data length 24 offset 112
[ 88.052400] fs/cifs/smb2misc.c: SMB2 len 136
[ 88.052412] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=5 state=4
[ 88.052419] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.052422] fs/cifs/smb2pdu.c: validate negotiate info successful
[ 88.052424] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 3) rc = 0
[ 88.052426] fs/cifs/connect.c: Tcon rc = 0
[ 88.052427] fs/cifs/smb2pdu.c: create/open
[ 88.052443] fs/cifs/transport.c: Sending smb: smb_len=284
[ 88.053023] fs/cifs/connect.c: RFC1002 header 0xe8
[ 88.053029] fs/cifs/smb2misc.c: SMB2 data length 80 offset 152
[ 88.053031] fs/cifs/smb2misc.c: SMB2 len 232
[ 88.053038] fs/cifs/transport.c: cifs_sync_mid_result: cmd=5 mid=6 state=4
[ 88.053044] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.053046] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.053053] fs/cifs/transport.c: Sending smb: smb_len=125
[ 88.053331] fs/cifs/connect.c: RFC1002 header 0x108
[ 88.053334] fs/cifs/smb2misc.c: SMB2 data length 152 offset 112
[ 88.053335] fs/cifs/smb2misc.c: SMB2 len 264
[ 88.053343] fs/cifs/transport.c: cifs_sync_mid_result: cmd=11 mid=7 state=4
[ 88.053348] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.053351] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[ 88.053352] fs/cifs/smb2ops.c: parse_server_interfaces: speed 2000000000 bps
[ 88.053354] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000001
[ 88.053356] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 xxx
[ 88.053357] fs/cifs/smb2pdu.c: Query FSInfo level 5
[ 88.053363] fs/cifs/transport.c: Sending smb: smb_len=109
[ 88.053645] fs/cifs/connect.c: RFC1002 header 0x5c
[ 88.053649] fs/cifs/smb2misc.c: SMB2 data length 20 offset 72
[ 88.053650] fs/cifs/smb2misc.c: SMB2 len 92
[ 88.053657] fs/cifs/transport.c: cifs_sync_mid_result: cmd=16 mid=8 state=4
[ 88.053661] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.053663] fs/cifs/smb2pdu.c: Query FSInfo level 4
[ 88.053669] fs/cifs/transport.c: Sending smb: smb_len=109
[ 88.053943] fs/cifs/connect.c: RFC1002 header 0x50
[ 88.053947] fs/cifs/smb2misc.c: SMB2 data length 8 offset 72
[ 88.053948] fs/cifs/smb2misc.c: SMB2 len 80
[ 88.053955] fs/cifs/transport.c: cifs_sync_mid_result: cmd=16 mid=9 state=4
[ 88.053959] fs/cifs/misc.c: Null buffer passed to cifs_small_buf_release
[ 88.053960] fs/cifs/smb2pdu.c: Query FSInfo level 1
[ 88.054261] fs/cifs/smb2misc.c: SMB2 data length 30 offset 72
[ 88.054279] fs/cifs/smb2pdu.c: Query FSInfo level 11
[ 88.054591] fs/cifs/smb2misc.c: SMB2 data length 28 offset 72
[ 88.054610] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\dc1\Group
[ 88.054613] fs/cifs/smb2ops.c: smb2_get_dfs_refer path <\dc1\Group>
[ 88.054620] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.054982] fs/cifs/misc.c: num_referrals: 5 dfs flags: 0x3 ...
[ 88.055029] address conversion returned 0 for DC3
[ 88.055031] address conversion returned 0 for DC3
[ 88.064923] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: DC3 to yyy
[ 88.064951] fs/cifs/connect.c: iocharset set to utf8
[ 88.064965] address conversion returned 1 for yyy
[ 88.064966] fs/cifs/connect.c: Username: root
[ 88.064970] fs/cifs/connect.c: cifs_put_tcon: tc_count=1
[ 88.064971] fs/cifs/connect.c: CIFS VFS: in cifs_put_tcon as Xid: 4 with uid: 0
[ 88.064973] fs/cifs/smb2pdu.c: Tree Disconnect
[ 88.065343] fs/cifs/connect.c: cifs_put_smb_ses: ses_count=1
[ 88.065346] fs/cifs/connect.c: CIFS VFS: in cifs_free_ipc as Xid: 5 with uid: 0
[ 88.065347] fs/cifs/smb2pdu.c: Tree Disconnect
[ 88.065349] fs/cifs/connect.c: CIFS VFS: leaving cifs_free_ipc (xid = 5) rc = -5
[ 88.065350] fs/cifs/connect.c: failed to disconnect IPC tcon (rc=-5)
[ 88.065352] fs/cifs/connect.c: CIFS VFS: in cifs_put_smb_ses as Xid: 6 with uid: 0
[ 88.065353] fs/cifs/smb2pdu.c: disconnect session 00000000c9ca55b1
[ 88.065758] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 0) rc = 0
[ 88.065760] fs/cifs/connect.c: CIFS VFS: in cifs_mount as Xid: 7 with uid: 0
[ 88.065761] fs/cifs/connect.c: UNC: \\DC3\Group
[ 88.065775] fs/cifs/connect.c: Socket created
[ 88.065777] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
[ 88.067082] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 8 with uid: 0
[ 88.067084] fs/cifs/connect.c: Demultiplex PID: 4539
[ 88.067086] fs/cifs/connect.c: Existing smb sess not found
[ 88.067089] fs/cifs/smb2pdu.c: Negotiate protocol
[ 88.067668] fs/cifs/smb2pdu.c: mode 0x3
[ 88.067670] fs/cifs/smb2pdu.c: negotiated smb3.02 dialect
[ 88.067675] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[ 88.067677] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
[ 88.067679] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
[ 88.067680] fs/cifs/asn1.c: OID len = 8 oid = 0x1 0x2 0x348 0x1bb92
[ 88.067682] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
[ 88.067684] fs/cifs/connect.c: Security Mode: 0x3 Capabilities: 0x300047 TimeAdjust: 0
[ 88.067685] fs/cifs/smb2pdu.c: Session Setup
[ 88.067686] fs/cifs/smb2pdu.c: sess setup type 5
[ 88.067691] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=DC3;ip4=yyy;sec=krb5;uid=0x3e8;creduid=0x3e8;user=root;pid=0x119b
[ 88.076475] SPNEGO reply blob:: dump of 1024 bytes of data at 0x000000007db38079
...
[ 88.078251] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[ 88.078261] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 8) rc = 0
[ 88.078267] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 9 with uid: 0
[ 88.078269] fs/cifs/smb2pdu.c: TCON
[ 88.078642] fs/cifs/smb2pdu.c: connection to pipe share
[ 88.078645] fs/cifs/smb2pdu.c: validate negotiate
[ 88.078647] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.079022] fs/cifs/smb2pdu.c: validate negotiate info successful
[ 88.079026] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 9) rc = 0
[ 88.079028] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[ 88.079032] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 10 with uid: 0
[ 88.079033] fs/cifs/smb2pdu.c: TCON
[ 88.079391] fs/cifs/smb2pdu.c: connection to disk share
[ 88.079393] fs/cifs/smb2pdu.c: validate negotiate
[ 88.079394] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.079724] fs/cifs/smb2pdu.c: validate negotiate info successful
[ 88.079726] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 10) rc = 0
[ 88.079728] fs/cifs/connect.c: Tcon rc = 0
[ 88.079730] fs/cifs/smb2pdu.c: create/open
[ 88.080465] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.080876] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 0
[ 88.080878] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[ 88.080879] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[ 88.080881] fs/cifs/smb2ops.c: parse_server_interfaces: ipv4 yyy
[ 88.080882] fs/cifs/smb2ops.c: parse_server_interfaces: adding iface 1
[ 88.080884] fs/cifs/smb2ops.c: parse_server_interfaces: speed 10000000000 bps
[ 88.080885] fs/cifs/smb2ops.c: parse_server_interfaces: capabilities 0x00000000
[ 88.080887] fs/cifs/smb2ops.c: parse_server_interfaces: ipv6 fe80:0000:0000:0000:91e8:288f:23ca:5cd5
[ 88.080889] fs/cifs/smb2pdu.c: Query FSInfo level 5
[ 88.081200] fs/cifs/smb2pdu.c: Query FSInfo level 4
[ 88.081508] fs/cifs/smb2pdu.c: Query FSInfo level 1
[ 88.081802] fs/cifs/smb2pdu.c: Query FSInfo level 11
[ 88.082152] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 7) rc = 0
[ 88.082249] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 11 with uid: 0
[ 88.082251] fs/cifs/inode.c: Getting info on
[ 88.082254] fs/cifs/smb2ops.c: found a cached root file handle
[ 88.082256] fs/cifs/smb2pdu.c: Query Info
[ 88.083446] fs/cifs/inode.c: looking for uniqueid=281474976823914
[ 88.083459] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 281474976823914
[ 88.083461] fs/cifs/inode.c: cifs_revalidate_cache: inode 281474976823914 is new
[ 88.083464] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 11) rc = 0
[ 88.083466] fs/cifs/cifsfs.c: Get root dentry for
[ 88.083468] fs/cifs/cifsfs.c: dentry root is: 00000000351ca600
[ 88.092779] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 12 with uid: 1000
[ 88.092783] fs/cifs/dir.c: parent inode = 0x000000000e3e22bf name is: DATA and dentry = 0x00000000a0e964ca
[ 88.092785] fs/cifs/dir.c: name: \DATA
[ 88.092786] fs/cifs/dir.c: NULL inode in lookup
[ 88.092787] fs/cifs/dir.c: Full path: \DATA inode = 0x (null)
[ 88.092789] fs/cifs/inode.c: Getting info on \DATA
[ 88.092795] fs/cifs/smb2pdu.c: create/open
[ 88.093733] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
[ 88.093739] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
[ 88.093742] fs/cifs/inode.c: creating fake fattr for DFS referral
[ 88.093744] fs/cifs/inode.c: looking for uniqueid=18446612166559357568
[ 88.093753] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 18446612166559357568
[ 88.093754] fs/cifs/inode.c: cifs_revalidate_cache: inode 18446612166559357568 is new
[ 88.093756] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 12) rc = 0
[ 88.093758] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_d_automount
[ 88.093759] fs/cifs/cifs_dfs_ref.c: in cifs_dfs_do_automount
[ 88.093760] fs/cifs/dir.c: name: \DATA
[ 88.093762] fs/cifs/cifs_dfs_ref.c: CIFS VFS: in cifs_dfs_do_automount as Xid: 13 with uid: 1000
[ 88.093763] fs/cifs/smb2ops.c: smb2_get_dfs_refer path <\DC3\Group\DATA>
[ 88.093767] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.094602] fs/cifs/misc.c: num_referrals: 1 dfs flags: 0x2 ...
[ 88.094614] fs/cifs/cifs_dfs_ref.c: CIFS VFS: leaving cifs_dfs_do_automount (xid = 13) rc = 0
[ 88.094615] fs/cifs/cifs_dfs_ref.c: DFS: ref path: \DC3\Group\DATA
[ 88.094616] fs/cifs/cifs_dfs_ref.c: DFS: node path: \fsgroup4\group\DATA
[ 88.094617] fs/cifs/cifs_dfs_ref.c: DFS: fl: 2, srv_type: 0
[ 88.094618] fs/cifs/cifs_dfs_ref.c: DFS: ref_flags: 0, path_consumed: 63
[ 88.094621] address conversion returned 0 for fsgroup4
[ 88.094622] address conversion returned 0 for fsgroup4
[ 88.099802] fs/cifs/dns_resolve.c: dns_resolve_server_name_to_ip: resolved: fsgroup4 to yyy9
[ 88.099808] fs/cifs/cifsfs.c: Devname: //fsgroup4/group/DATA flags: 67108864
[ 88.099820] fs/cifs/connect.c: iocharset set to utf8
[ 88.099827] address conversion returned 1 for yyy9
[ 88.099828] fs/cifs/connect.c: Username: root
[ 88.099829] fs/cifs/connect.c: file mode: 0x180 dir mode: 0x1c0
[ 88.099831] fs/cifs/connect.c: CIFS VFS: in cifs_mount as Xid: 14 with uid: 1000
[ 88.099831] fs/cifs/connect.c: UNC: \\fsgroup4\group
[ 88.099836] fs/cifs/connect.c: Socket created
[ 88.099837] fs/cifs/connect.c: sndbuf 16384 rcvbuf 87380 rcvtimeo 0x1b58
[ 88.100984] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as Xid: 15 with uid: 1000
[ 88.100986] fs/cifs/connect.c: Existing smb sess not found
[ 88.100987] fs/cifs/connect.c: Demultiplex PID: 4543
[ 88.100990] fs/cifs/smb2pdu.c: Negotiate protocol
[ 88.101362] fs/cifs/smb2pdu.c: mode 0x1
[ 88.101363] fs/cifs/smb2pdu.c: negotiated smb3.0 dialect
[ 88.101378] fs/cifs/connect.c: Security Mode: 0x1 Capabilities: 0x300053 TimeAdjust: 0
[ 88.101378] fs/cifs/smb2pdu.c: Session Setup
[ 88.101380] fs/cifs/smb2pdu.c: sess setup type 5
[ 88.101383] fs/cifs/cifs_spnego.c: key description = ver=0x2;host=fsgroup4;ip4=yyy9;sec=krb5;uid=0x3e8;creduid=0x3e8;user=root;pid=0x1191
[ 88.108011] SPNEGO reply blob:: dump of 1024 bytes of data at 0x000000002f33df36
...
[ 88.123996] fs/cifs/smb2pdu.c: SMB2/3 session established successfully
[ 88.124006] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses (xid = 15) rc = 0
[ 88.124009] fs/cifs/connect.c: CIFS VFS: in cifs_setup_ipc as Xid: 16 with uid: 1000
[ 88.124010] fs/cifs/smb2pdu.c: TCON
[ 88.124408] fs/cifs/smb2pdu.c: connection to pipe share
[ 88.124410] fs/cifs/smb2pdu.c: validate negotiate
[ 88.124412] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.124927] fs/cifs/smb2pdu.c: validate negotiate info successful
[ 88.124930] fs/cifs/connect.c: CIFS VFS: leaving cifs_setup_ipc (xid = 16) rc = 0
[ 88.124931] fs/cifs/connect.c: IPC tcon rc = 0 ipc tid = 1
[ 88.124934] fs/cifs/connect.c: CIFS VFS: in cifs_get_tcon as Xid: 17 with uid: 1000
[ 88.124935] fs/cifs/smb2pdu.c: TCON
[ 88.126027] fs/cifs/smb2pdu.c: connection to disk share
[ 88.126029] fs/cifs/smb2pdu.c: validate negotiate
[ 88.126040] fs/cifs/smb2pdu.c: SMB2 IOCTL
[ 88.126594] fs/cifs/smb2pdu.c: validate negotiate info successful
[ 88.126607] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_tcon (xid = 17) rc = 0
[ 88.126608] fs/cifs/connect.c: Tcon rc = 0
[ 88.126610] fs/cifs/smb2pdu.c: create/open
[ 88.127759] Status code returned 0xc0000010 STATUS_INVALID_DEVICE_REQUEST
[ 88.127778] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000010 to POSIX err -95
[ 88.127780] CIFS VFS: error -95 on ioctl to get interface list
[ 88.127782] fs/cifs/smb2pdu.c: Query FSInfo level 5
[ 88.128175] fs/cifs/smb2pdu.c: Query FSInfo level 4
[ 88.129538] fs/cifs/connect.c: build_unc_path_to_root: full_path=\\fsgroup4\group\DATA
[ 88.129550] fs/cifs/smb2ops.c: smb2_get_dfs_refer path <\fsgroup4\group>
[ 88.130012] Status code returned 0xc0000225 STATUS_NOT_FOUND
[ 88.130015] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000225 to POSIX err -2
[ 88.130031] fs/cifs/smb2pdu.c: create/open
[ 88.130490] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 13
[ 88.130555] fs/cifs/smb2pdu.c: Close
[ 88.131034] fs/cifs/smb2pdu.c: create/open
[ 88.131687] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 15
[ 88.131703] fs/cifs/smb2pdu.c: Close
[ 88.132087] fs/cifs/connect.c: CIFS VFS: leaving cifs_mount (xid = 14) rc = 0
[ 88.132148] fs/cifs/inode.c: CIFS VFS: in cifs_root_iget as Xid: 18 with uid: 1000
[ 88.132150] fs/cifs/inode.c: Getting info on
[ 88.132153] fs/cifs/smb2ops.c: found a cached root file handle
[ 88.132165] fs/cifs/smb2pdu.c: Query Info
[ 88.132701] fs/cifs/inode.c: looking for uniqueid=6572968437415411776
[ 88.132711] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6572968437415411776
[ 88.132712] fs/cifs/inode.c: cifs_revalidate_cache: inode 6572968437415411776 is new
[ 88.132714] fs/cifs/inode.c: CIFS VFS: leaving cifs_root_iget (xid = 18) rc = 0
[ 88.132716] fs/cifs/cifsfs.c: Get root dentry for \DATA
[ 88.132719] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 19 with uid: 1000
[ 88.132721] fs/cifs/dir.c: parent inode = 0x000000004aa531c0 name is: DATA and dentry = 0x0000000098307509
[ 88.132723] fs/cifs/dir.c: name: \DATA
[ 88.132723] fs/cifs/dir.c: NULL inode in lookup
[ 88.132725] fs/cifs/dir.c: Full path: \DATA inode = 0x (null)
[ 88.132726] fs/cifs/inode.c: Getting info on \DATA
[ 88.132729] fs/cifs/smb2pdu.c: create/open
[ 88.133203] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 18
[ 88.133226] fs/cifs/smb2pdu.c: Query Info
[ 88.133701] fs/cifs/smb2pdu.c: Close
[ 88.134074] fs/cifs/inode.c: looking for uniqueid=6269537983034710380
[ 88.134077] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6269537983034710380
[ 88.134078] fs/cifs/inode.c: cifs_revalidate_cache: inode 6269537983034710380 is new
[ 88.134080] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 19) rc = 0
[ 88.134082] fs/cifs/cifsfs.c: dentry root is: 0000000098307509
[ 88.134085] fs/cifs/cifs_dfs_ref.c: cifs_dfs_do_automount: cifs_dfs_do_refmount:\fsgroup4\group\DATA , mnt:00000000b1215b36
[ 88.134086] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_do_automount
[ 88.134088] fs/cifs/cifs_dfs_ref.c: leaving cifs_dfs_d_automount [ok]
[ 88.134126] fs/cifs/dir.c: CIFS VFS: in cifs_lookup as Xid: 20 with uid: 1000
[ 88.134128] fs/cifs/dir.c: parent inode = 0x000000002567105e name is: tab_slx and dentry = 0x000000005c93055f
[ 88.134130] fs/cifs/dir.c: name: \tab_slx
[ 88.134131] fs/cifs/dir.c: name: \DATA\tab_slx
[ 88.134132] fs/cifs/dir.c: NULL inode in lookup
[ 88.134133] fs/cifs/dir.c: Full path: \DATA\tab_slx inode = 0x (null)
[ 88.134134] fs/cifs/inode.c: Getting info on \DATA\tab_slx
[ 88.134139] fs/cifs/smb2pdu.c: create/open
[ 88.134638] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 21
[ 88.134646] fs/cifs/smb2pdu.c: Query Info
[ 88.135153] fs/cifs/smb2pdu.c: Close
[ 88.135531] fs/cifs/inode.c: looking for uniqueid=6273124014440705861
[ 88.135548] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6273124014440705861
[ 88.135550] fs/cifs/inode.c: cifs_revalidate_cache: inode 6273124014440705861 is new
[ 88.135554] fs/cifs/dir.c: CIFS VFS: leaving cifs_lookup (xid = 20) rc = 0
[ 88.135571] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 21 with uid: 1000
[ 88.135574] fs/cifs/dir.c: name: \tab_slx
[ 88.135576] fs/cifs/dir.c: name: \DATA\tab_slx
[ 88.135578] fs/cifs/readdir.c: Full path: \DATA\tab_slx start at: 0
[ 88.135585] fs/cifs/smb2pdu.c: create/open
[ 88.136135] fs/cifs/smb2misc.c: Calculated size 153 length 152 mismatch mid 24
[ 88.137463] fs/cifs/smb2pdu.c: num entries 157 last_index 157 srch start 00000000052f8244 srch end 00000000d37a5f52
[ 88.137466] fs/cifs/readdir.c: initiate cifs search rc 0
[ 88.137470] fs/cifs/readdir.c: found entry - pos_in_buf 2
[ 88.137472] fs/cifs/readdir.c: new entry 000000009970344e old entry 00000000052f8244
[ 88.137475] fs/cifs/readdir.c: new entry 000000008cf097fb old entry 000000009970344e
[ 88.137477] fs/cifs/readdir.c: entry 2 found
[ 88.137479] fs/cifs/readdir.c: loop through 155 times filling dir for net buf 000000005d84284c
[ 88.137483] fs/cifs/readdir.c: cifs_prime_dcache: for .bpo
[ 88.137487] fs/cifs/inode.c: looking for uniqueid=6273124040210509638
[ 88.137493] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6273124040210509638
[ 88.137495] fs/cifs/inode.c: cifs_revalidate_cache: inode 6273124040210509638 is new
[ 88.137499] fs/cifs/readdir.c: new entry 0000000057dc14b1 old entry 000000008cf097fb
[ 88.137502] fs/cifs/readdir.c: cifs_prime_dcache: for .de
[ 88.137504] fs/cifs/inode.c: looking for uniqueid=6273124044505476935
[ 88.137507] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6273124044505476935
[ 88.137509] fs/cifs/inode.c: cifs_revalidate_cache: inode 6273124044505476935 is new
[ 88.137512] fs/cifs/readdir.c: new entry 00000000ee729e3b old entry 0000000057dc14b1
[ 88.137515] fs/cifs/readdir.c: cifs_prime_dcache: for .sl3
[ 88.137517] fs/cifs/inode.c: looking for uniqueid=6273124061685346120
[ 88.137520] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6273124061685346120
[ 88.137522] fs/cifs/inode.c: cifs_revalidate_cache: inode 6273124061685346120 is new
[ 88.137525] fs/cifs/readdir.c: new entry 00000000e193a21a old entry 00000000ee729e3b
[ 88.137528] fs/cifs/readdir.c: cifs_prime_dcache: for 1E9BA949.dep
[ 88.137530] fs/cifs/inode.c: looking for uniqueid=6273124087455149897
[ 88.137534] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6273124087455149897
[ 88.137536] fs/cifs/inode.c: cifs_revalidate_cache: inode 6273124087455149897 is new
[ 88.137538] fs/cifs/readdir.c: new entry 00000000934e236f old entry 00000000e193a21a
[ 88.137541] fs/cifs/readdir.c: cifs_prime_dcache: for 1E9BA949.ff
[ 88.137543] fs/cifs/inode.c: looking for uniqueid=6273124108929986378
[ 88.137547] fs/cifs/inode.c: cifs_revalidate_cache: revalidating inode 6273124108929986378
[ 88.137549] fs/cifs/inode.c: cifs_revalidate_cache: inode 6273124108929986378 is new
[ 88.137551] fs/cifs/readdir.c: new entry 0000000006f4264a old entry 00000000934e236f
[ 88.137554] fs/cifs/readdir.c: cifs_prime_dcache: for 1E9BA949.ffl
[ 88.137559] fs/cifs/readdir.c: new entry 000000008e78c567 old entry 0000000006f4264a
[ 88.137562] fs/cifs/readdir.c: cifs_prime_dcache: for 30549.sl3
[ 88.137567] fs/cifs/readdir.c: new entry 000000006a486503 old entry 000000008e78c567
[ 88.137569] fs/cifs/readdir.c: cifs_prime_dcache: for 3314A.sl3
[ 88.137574] fs/cifs/readdir.c: new entry 0000000075944219 old entry 000000006a486503
[ 88.137577] fs/cifs/readdir.c: cifs_prime_dcache: for 3549.sl3
[ 88.137583] fs/cifs/readdir.c: cifs_prime_dcache: for 40700.sl3
[ 88.138192] fs/cifs/readdir.c: last entry in buf at pos 157 A0147.sl3
[ 88.138197] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 21) rc = 0
[ 88.138279] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 22 with uid: 1000
[ 88.138281] fs/cifs/readdir.c: calling findnext2
[ 88.139553] fs/cifs/smb2pdu.c: num entries 156 last_index 313 srch start 000000001de70e3a srch end 0000000090d263cc
[ 88.139557] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.139560] fs/cifs/readdir.c: entry 157 found
[ 88.139562] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 0000000042d77a42
[ 88.140249] fs/cifs/readdir.c: last entry in buf at pos 313 A0299.sl3
[ 88.140252] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 22) rc = 0
[ 88.140344] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 23 with uid: 1000
[ 88.140346] fs/cifs/readdir.c: calling findnext2
[ 88.141638] fs/cifs/smb2pdu.c: num entries 156 last_index 469 srch start 0000000054816ba9 srch end 00000000a3d9b42f
[ 88.141641] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.141643] fs/cifs/readdir.c: entry 313 found
[ 88.141645] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 000000001dd3f55e
[ 88.142304] fs/cifs/readdir.c: last entry in buf at pos 469 A0439.sl3
[ 88.142307] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 23) rc = 0
[ 88.142387] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 24 with uid: 1000
[ 88.142390] fs/cifs/readdir.c: calling findnext2
[ 88.143692] fs/cifs/smb2pdu.c: num entries 156 last_index 625 srch start 00000000e5c4a654 srch end 0000000089d8bb8c
[ 88.143694] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.143695] fs/cifs/readdir.c: entry 469 found
[ 88.143697] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 000000000aec537e
[ 88.144116] fs/cifs/readdir.c: last entry in buf at pos 625 A0573.sl3
[ 88.144118] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 24) rc = 0
[ 88.144176] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 25 with uid: 1000
[ 88.144177] fs/cifs/readdir.c: calling findnext2
[ 88.145637] fs/cifs/smb2pdu.c: num entries 156 last_index 781 srch start 00000000a4f2d350 srch end 000000004db89f0e
[ 88.145639] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.145640] fs/cifs/readdir.c: entry 625 found
[ 88.145641] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 0000000088f154d0
[ 88.146058] fs/cifs/readdir.c: last entry in buf at pos 781 A0686.sl3
[ 88.146060] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 25) rc = 0
[ 88.146113] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 26 with uid: 1000
[ 88.146114] fs/cifs/readdir.c: calling findnext2
[ 88.147591] fs/cifs/smb2pdu.c: num entries 156 last_index 937 srch start 00000000bd373789 srch end 00000000b9a44219
[ 88.147593] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.147593] fs/cifs/readdir.c: entry 781 found
[ 88.147595] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 00000000c1b57800
[ 88.147947] fs/cifs/readdir.c: last entry in buf at pos 937 A0807.ox3
[ 88.147948] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 26) rc = 0
[ 88.147988] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 27 with uid: 1000
[ 88.147989] fs/cifs/readdir.c: calling findnext2
[ 88.149250] fs/cifs/smb2pdu.c: num entries 156 last_index 1093 srch start 0000000037103ead srch end 00000000547acac7
[ 88.149252] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.149253] fs/cifs/readdir.c: entry 937 found
[ 88.149254] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 00000000411dbbff
[ 88.149606] fs/cifs/readdir.c: last entry in buf at pos 1093 A0918.sl3
[ 88.149607] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 27) rc = 0
[ 88.149644] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 28 with uid: 1000
[ 88.149645] fs/cifs/readdir.c: calling findnext2
[ 88.150940] fs/cifs/smb2pdu.c: num entries 156 last_index 1249 srch start 00000000affb0738 srch end 0000000052563ce4
[ 88.150942] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.150943] fs/cifs/readdir.c: entry 1093 found
[ 88.150944] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 00000000477f6916
[ 88.151295] fs/cifs/readdir.c: last entry in buf at pos 1249 A1024.ox3
[ 88.151297] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 28) rc = 0
[ 88.151343] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 29 with uid: 1000
[ 88.151344] fs/cifs/readdir.c: calling findnext2
[ 88.152715] fs/cifs/smb2pdu.c: num entries 156 last_index 1405 srch start 00000000a4f2d350 srch end 000000004db89f0e
[ 88.152717] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.152718] fs/cifs/readdir.c: entry 1249 found
[ 88.152728] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 0000000088f154d0
[ 88.153073] fs/cifs/readdir.c: last entry in buf at pos 1405 A1124.ox3
[ 88.153074] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 29) rc = 0
[ 88.153113] fs/cifs/readdir.c: CIFS VFS: in cifs_readdir as Xid: 30 with uid: 1000
[ 88.153113] fs/cifs/readdir.c: calling findnext2
[ 88.154575] fs/cifs/smb2pdu.c: num entries 156 last_index 1561 srch start 00000000e5c4a654 srch end 0000000089d8bb8c
[ 88.154577] fs/cifs/readdir.c: found entry - pos_in_buf 0
[ 88.154577] fs/cifs/readdir.c: entry 1405 found
[ 88.154578] fs/cifs/readdir.c: loop through 156 times filling dir for net buf 000000000aec537e
[ 88.154820] fs/cifs/readdir.c: last entry in buf at pos 1561 A1225.ox3
[ 88.154821] fs/cifs/readdir.c: CIFS VFS: leaving cifs_readdir (xid = 30) rc = 0
[ 88.154842] fs/cifs/readdir.c: calling findnext2
[ 89.082006] Status code returned 0x80000006 STATUS_NO_MORE_FILES
[ 89.082017] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0x80000006 to POSIX err -61
[ 89.082022] fs/cifs/readdir.c: index not in buffer - could not findnext into it
[ 89.082023] fs/cifs/readdir.c: could not find entry
[ 89.082034] fs/cifs/file.c: Closedir inode = 0x0000000018187729
[ 89.082036] fs/cifs/file.c: CIFS VFS: in cifs_closedir as Xid: 452 with uid: 1000
[ 89.082038] fs/cifs/file.c: Freeing private data in close dir
[ 89.082040] fs/cifs/smb2pdu.c: Close
[ 89.082691] fs/cifs/file.c: Closing uncompleted readdir with rc 0
[ 89.082693] fs/cifs/file.c: closedir free smb buf in srch struct
[ 89.082698] fs/cifs/file.c: CIFS VFS: leaving cifs_closedir (xid = 452) rc = 0
[ 90.968502] fs/cifs/inode.c: CIFS VFS: in cifs_revalidate_dentry_attr as Xid: 453 with uid: 1000
[ 90.968504] fs/cifs/dir.c: name: \DATA
[ 90.968506] fs/cifs/inode.c: Update attributes: \DATA inode 0x00000000e003cbf1 count 1 dentry: 0x00000000a0e964ca d_time 4294755796 jiffies 4294758671
[ 90.968507] fs/cifs/inode.c: Getting info on \DATA
[ 90.968512] fs/cifs/smb2pdu.c: create/open
[ 90.969081] Status code returned 0xc0000257 STATUS_PATH_NOT_COVERED
[ 90.969085] fs/cifs/smb2maperror.c: Mapping SMB2 status code 0xc0000257 to POSIX err -66
[ 90.969098] fs/cifs/inode.c: creating fake fattr for DFS referral
[ 90.969100] fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate_dentry_attr (xid = 453) rc = -116
[ 152.135169] fs/cifs/smb2pdu.c: In echo request
[ 152.135176] __smb_send_rqst: 478 callbacks suppressed
[ 152.135187] fs/cifs/transport.c: Sending smb: smb_len=72
[ 152.135480] cifs_demultiplex_thread: 478 callbacks suppressed
[ 152.135481] fs/cifs/connect.c: RFC1002 header 0x44
[ 152.135485] smb2_calc_size: 1338 callbacks suppressed
[ 152.135485] fs/cifs/smb2misc.c: SMB2 len 68
[ 152.135521] fs/cifs/connect.c: RFC1002 header 0x44
[ 152.135524] fs/cifs/smb2misc.c: SMB2 len 68
[ 213.570341] fs/cifs/smb2pdu.c: In echo request
[ 213.570343] fs/cifs/smb2pdu.c: In echo request
[ 213.570350] fs/cifs/transport.c: Sending smb: smb_len=72
[ 213.570351] fs/cifs/transport.c: Sending smb: smb_len=72
[ 213.570648] fs/cifs/connect.c: RFC1002 header 0x44
[ 213.570652] fs/cifs/smb2misc.c: SMB2 len 68
[ 213.570715] fs/cifs/connect.c: RFC1002 header 0x44
[ 213.570718] fs/cifs/smb2misc.c: SMB2 len 68
[ 275.010050] fs/cifs/smb2pdu.c: In echo request
[ 275.010054] fs/cifs/smb2pdu.c: In echo request
[ 275.010069] fs/cifs/transport.c: Sending smb: smb_len=72
[ 275.010069] fs/cifs/transport.c: Sending smb: smb_len=72
[ 275.010449] fs/cifs/connect.c: RFC1002 header 0x44
[ 275.010453] fs/cifs/smb2misc.c: SMB2 len 68
[ 275.010753] fs/cifs/connect.c: RFC1002 header 0x44
[ 275.010765] fs/cifs/smb2misc.c: SMB2 len 68
