[linux-cifs-client] DFS fails to follow remote links

Suresh Jayaraman sjayaraman at suse.de
Thu Nov 27 11:31:16 GMT 2008


Igor Mammedov wrote:


> Could you gather a little more info on a problem?
> Enable logging in cifs module:
> "echo 1 > /proc/fs/cifs/cifsFYI"
> Repeat test case and get logs of what's going on there.
> Providing tcpdump's dump of client <-> servers conversation will not hurt either.
> Something like "tcpdump -s0 -w mydump.pcap port 445"

Sorry about the delay (setup took sometime). I also applied the patch
suggested by Jeff and Steve but the error remains the same - object is
remote followed by an oops when tried the second time.

I think the oops is occuring the second time we do ls and the real issue
is before that when ls fails. Also, the DFS calls seems fine

Here is the network trace (tshark -r of cap file - since ppl might see
emails on mobile):

---
 1   0.000000 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request,
QUERY_PATH_INFO, Query File All Info, Path: \\w2003ent-2.ad.suse.cz\ns1
  2   0.000879  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
QUERY_PATH_INFO
  4   0.553491 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request, FIND_FIRST2,
Pattern: \\w2003ent-2.ad.suse.cz\ns1\*
  5   0.554601  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
FIND_FIRST2,
Files: . .. apps
  7   2.639671 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request,
QUERY_PATH_INFO, Query File All Info, Path: \\w2003ent-2.ad.suse.cz\ns1
  8   2.640464  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
QUERY_PATH_INFO
 10   2.641413 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request, FIND_FIRST2,
Pattern: \\w2003ent-2.ad.suse.cz\ns1\*
 11   2.642237  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
FIND_FIRST2,
Files: . .. apps
 13   3.504577 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request, FIND_FIRST2,
Pattern: \\w2003ent-2.ad.suse.cz\ns1\apps\*
 14   3.505438  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
FIND_FIRST2,
Files: . .. putty
 16   4.475227 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request,
QUERY_PATH_INFO, Query File All Info, Path: \\w2003ent-2.ad.suse.cz\ns1\apps
 17   4.475969  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
QUERY_PATH_INFO
 19   4.476264 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request, FIND_FIRST2,
Pattern: \\w2003ent-2.ad.suse.cz\ns1\apps\putty\*
 20   4.476682  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
FIND_FIRST2,
Error: STATUS_PATH_NOT_COVERED
 22   6.292587 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request,
QUERY_PATH_INFO, Query File All Info, Path: \\w2003ent-2.ad.suse.cz\ns1\apps
 23   6.293433  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
QUERY_PATH_INFO
 25   6.293679 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request,
QUERY_PATH_INFO, Query File All Info, Path:
\\w2003ent-2.ad.suse.cz\ns1\apps\putty
 26   6.294180  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
QUERY_PATH_INFO, Error: STATUS_PATH_NOT_COVERED
 27   6.294257 192.168.1.64 -> 192.168.1.2  SMB Tree Connect AndX Request,
Path: \\192.168.1.2\IPC$
 28   6.294583  192.168.1.2 -> 192.168.1.64 SMB Tree Connect AndX Response
 29   6.294645 192.168.1.64 -> 192.168.1.2  SMB Trans2 Request,
GET_DFS_REFERRAL, File: \\w2003ent-2.ad.suse.cz\ns1\apps\putty
 30   6.296037  192.168.1.2 -> 192.168.1.64 SMB Trans2 Response,
GET_DFS_REFERRAL

---

cifsFYI o/p


Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/cifsfs.c: Devname:
//w2003ent-2.ad.suse.cz/ns1 flags: 64
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: CIFS VFS: in
cifs_mount as Xid: 0 with uid: 0
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: Domain name set
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: Username:
Administrator
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: UNC:
\\w2003ent-2.ad.suse.cz\ns1 ip: 192.168.1.2
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: Socket created
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: sndbuf 16384
rcvbuf 87380 rcvtimeo 0x7fffffffffffffff
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: Existing smb sess
not found
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/cifssmb.c: secFlags 0x7
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 114
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 78
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: Demultiplex PID: 3599
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0x6d
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/cifssmb.c: Dialect: 2
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/cifssmb.c: negprot rc 0
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: Security Mode:
0x3 Capabilities: 0x1f3fd TimeAdjust: -3600
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/sess.c: sess setup type 2
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 115
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb:
total_len 266
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0xbf
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/misc.c: Null buffer passed
to cifs_small_buf_release
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/sess.c: ssetup rc from
sendrecv2 is 0
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/sess.c: UID = 2048
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/sess.c: bleft 146
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/sess.c: words left: -1
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/sess.c: ssetup freeing small
buf ffff88002d1ac140
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: CIFS Session
Established successfully
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: file mode: 0x5f7
 dir mode: 0x1ff
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 117
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 106
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0x42
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: disk share connection
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: Tcon flags: 0x3
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: CIFS Tcon rc = 0
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/cifssmb.c: In QFSDeviceInfo
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 68
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0x44
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/cifssmb.c: In QFSAttributeInfo
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 68
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0x50
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: CIFS VFS: leaving
cifs_mount (xid = 0) rc = 0
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_iget as Xid: 1 with uid: 0
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/inode.c: Getting info on
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 74
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0xa2
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/inode.c: Old time 0
Nov 26 18:01:07 linux-d4xt kernel:  fs/cifs/inode.c: New time 4294973892
Nov 26 18:01:32 linux-d4xt dhcpcd[2760]: eth0: renewing lease of
192.168.1.11
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 2 with uid: 0
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1 inode 0xffff88002d8d4cb8 count 1 dentry:
0xffff880037592a40 d_time 6582955728264977243 jiffies 4294986269
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/inode.c: Getting info on
\\w2003ent-2.ad.suse.cz\ns1
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 128
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0xa2
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/inode.c: Old time 4294973892
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/inode.c: New time 4294986269
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/inode.c: cifs_revalidate -
inode unchanged
Nov 26 18:01:57 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 2) rc = 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 3 with uid: 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1 inode 0xffff88002d8d4cb8 count 1 dentry:
0xffff880037592a40 d_time 6582955728264977243 jiffies 4294987176
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: Getting info on
\\w2003ent-2.ad.suse.cz\ns1
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 128
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0xa2
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: Old time 4294986269
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: New time 4294987176
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: cifs_revalidate -
inode unchanged
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 3) rc = 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 4 with uid: 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1 inode 0xffff88002d8d4cb8 count 1 dentry:
0xffff880037592a40 d_time 6582955728264977243 jiffies 4294987177
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 4) rc = 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: in
cifs_readdir as Xid: 5 with uid: 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: Full path:
\\w2003ent-2.ad.suse.cz\ns1 start at: 2
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/cifssmb.c: In FindFirst for
\\w2003ent-2.ad.suse.cz\ns1
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 138
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0x11c
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: initiate cifs
search rc 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: found entry -
pos_in_buf 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: entry 2 found
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: loop through 3
times filling dir for net buf ffff88002b4201c0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: new entry
ffff88002b42024c old entry ffff88002b420208
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: new entry
ffff88002b420294 old entry ffff88002b42024c
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: For apps
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: File Size 0 and
blocks 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: Directory inode
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: last entry in buf
at pos 5 apps
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: leaving
cifs_readdir (xid = 5) rc = 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 6 with uid: 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987178 jiffies 4294987178
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 6) rc = 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 7 with uid: 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987178 jiffies 4294987178
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 7) rc = 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: in
cifs_readdir as Xid: 8 with uid: 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: index not in
buffer - could not findnext into it
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: could not find entry
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: leaving
cifs_readdir (xid = 8) rc = 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/file.c: Closedir inode =
0xffff88002d8d4cb8
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/file.c: CIFS VFS: in
cifs_closedir as Xid: 9 with uid: 0
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/file.c: Freeing private data
in close dir
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/file.c: closedir free smb
buf in srch struct
Nov 26 18:02:00 linux-d4xt kernel:  fs/cifs/file.c: CIFS VFS: leaving
cifs_closedir (xid = 9) rc = 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 10 with uid: 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1 inode 0xffff88002d8d4cb8 count 1 dentry:
0xffff880037592a40 d_time 6582955728264977243 jiffies 4294987779
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: Getting info on
\\w2003ent-2.ad.suse.cz\ns1
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 128
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0xa2
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: Old time 4294987176
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: New time 4294987779
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: cifs_revalidate -
inode unchanged
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 10) rc = 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 11 with uid: 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1 inode 0xffff88002d8d4cb8 count 1 dentry:
0xffff880037592a40 d_time 6582955728264977243 jiffies 4294987779
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 11) rc = 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: in
cifs_readdir as Xid: 12 with uid: 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: Full path:
\\w2003ent-2.ad.suse.cz\ns1 start at: 2
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/cifssmb.c: In FindFirst for
\\w2003ent-2.ad.suse.cz\ns1
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 138
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0x11c
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: initiate cifs
search rc 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: found entry -
pos_in_buf 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: entry 2 found
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: loop through 3
times filling dir for net buf ffff88002b4201c0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: new entry
ffff88002b42024c old entry ffff88002b420208
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: new entry
ffff88002b420294 old entry ffff88002b42024c
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: For apps
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: File Size 0 and
blocks 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: Directory inode
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: last entry in buf
at pos 5 apps
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: leaving
cifs_readdir (xid = 12) rc = 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: in
cifs_readdir as Xid: 13 with uid: 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: index not in
buffer - could not findnext into it
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: could not find entry
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: leaving
cifs_readdir (xid = 13) rc = 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/file.c: Closedir inode =
0xffff88002d8d4cb8
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/file.c: CIFS VFS: in
cifs_closedir as Xid: 14 with uid: 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/file.c: Freeing private data
in close dir
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/file.c: closedir free smb
buf in srch struct
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/file.c: CIFS VFS: leaving
cifs_closedir (xid = 14) rc = 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 15 with uid: 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987780 jiffies 4294987781
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 15) rc = 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 16 with uid: 0
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987780 jiffies 4294987781
Nov 26 18:02:03 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 16) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 17 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987780 jiffies 4294987976
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 17) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 18 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987780 jiffies 4294987976
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 18) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 19 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987780 jiffies 4294987976
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 19) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 20 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987780 jiffies 4294987976
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 20) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: in
cifs_readdir as Xid: 21 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: Full path:
\\w2003ent-2.ad.suse.cz\ns1\apps start at: 2
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/cifssmb.c: In FindFirst for
\\w2003ent-2.ad.suse.cz\ns1\apps
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/transport.c: For smb_command 50
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/transport.c: Sending smb of
length 148
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/connect.c: rfc1002 length 0x128
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: initiate cifs
search rc 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: found entry -
pos_in_buf 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: entry 2 found
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: loop through 3
times filling dir for net buf ffff88002b4201c0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: new entry
ffff88002b420250 old entry ffff88002b420208
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: new entry
ffff88002b420298 old entry ffff88002b420250
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: For putty
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: File Size 0 and
blocks 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: Directory inode
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: last entry in buf
at pos 5 putty
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: leaving
cifs_readdir (xid = 21) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 22 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps inode 0xffff88002d8d4088 count 1
dentry: 0xffff880037592e50 d_time 4294987780 jiffies 4294987977
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 22) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 23 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps\putty inode 0xffff88002d8d42f8 count 1
dentry: 0xffff8800375922f0 d_time 4294987977 jiffies 4294987977
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 23) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: in
cifs_revalidate as Xid: 24 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: Revalidate:
\\w2003ent-2.ad.suse.cz\ns1\apps\putty inode 0xffff88002d8d42f8 count 1
dentry: 0xffff8800375922f0 d_time 4294987977 jiffies 4294987977
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/inode.c: CIFS VFS: leaving
cifs_revalidate (xid = 24) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: in
cifs_readdir as Xid: 25 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: index not in
buffer - could not findnext into it
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: could not find entry
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/readdir.c: CIFS VFS: leaving
cifs_readdir (xid = 25) rc = 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/file.c: Closedir inode =
0xffff88002d8d4088
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/file.c: CIFS VFS: in
cifs_closedir as Xid: 26 with uid: 0
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/file.c: Freeing private data
in close dir
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/file.c: closedir free smb
buf in srch struct
Nov 26 18:02:04 linux-d4xt kernel:  fs/cifs/file.c: CIFS VFS: leaving
cifs_closedir (xid = 26) rc = 0

The oops is still occuring. Server is Windows2k3 R2. Does it work for
others with 2k3 R2 ?


Thanks,

> cifs.upcall writes errors to syslog on facility DAEMON level WARNING, so you could find its messages in logs as well.
> 
> 
> Suresh Jayaraman wrote:
>> Trying to get cifs DFS working..
>>
>> 2 Windows 2003R2 servers:
>>
>> Server1: DFS namespace server, standalone, no AD integration with dfs namespace 'ns1'. Namespace ns1 contains dfs folder folder_on_2 which is dfs link to shared folder 'shared' on server2.
>>
>> Server2: contains share folder 'shared' which is accessible via DFS from server1
>>
>> All addressing is done with ip addresses to make sure problem is not
>> netbios/wins related.
>>
>> mount -t cifs -ouser=Administrator,domain=DFSST \\\\server1\\ns1 /mnt
>>
>> "ls /mnt" works fine
>>
>> Trying to access 'folder_on_2' gives the error:
>> ls /mnt/folder_on_2
>> ls: reading directory /mnt/folder_on_2: Object is remote
>>
>> If I try ls again, I get the following oops:
>>
>> ---
>> Oct 22 16:37:34 linux-kocf kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
>> Oct 22 16:37:34 linux-kocf kernel: IP: [<ffffffff803206a4>] call_sbin_request_key+0x16d/0x28d
>> Oct 22 16:37:34 linux-kocf kernel: PGD 88c7067 PUD 41a6067 PMD 0 
>> Oct 22 16:37:34 linux-kocf kernel: Oops: 0000 [1] SMP linux-cifs-client at lists.samba.org
>> Oct 22 16:37:34 linux-kocf kernel: last sysfs file: /sys/devices/pci0000:00/0000:00:11.0/net/eth0/statistics/collisions
>> Oct 22 16:37:34 linux-kocf kernel: CPU 0 
>> Oct 22 16:37:34 linux-kocf kernel: Modules linked in: cifs(X) nls_utf8 ipv6 af_packet microcode fuse loop dm_mod ppdev rtc_cmos rtc_core rtc_lib parport_pc parport pcspkr sg container sr_mod cdrom ac button e1000 i2c_piix4 shpchp intel_agp pci_hotplug i2c_core sd_mod crc_t10dif edd ext3 mbcache jbd fan ide_pci_generic pata_acpi ata_generic piix ide_core mptspi mptscsih mptbase scsi_transport_spi ata_piix libata scsi_mod dock thermal processor thermal_sys hwmon
>> Oct 22 16:37:34 linux-kocf kernel: Supported: Yes, External
>> Oct 22 16:37:34 linux-kocf kernel: Pid: 3757, comm: ls Tainted: G        W 2.6.27.1-2-default #1
>> Oct 22 16:37:34 linux-kocf kernel: RIP: 0010:[<ffffffff803206a4>]  [<ffffffff803206a4>] call_sbin_request_key+0x16d/0x28d
>> Oct 22 16:37:34 linux-kocf kernel: RSP: 0018:ffff8800088db9a8  EFLAGS: 00010246
>> Oct 22 16:37:34 linux-kocf kernel: RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
>> Oct 22 16:37:34 linux-kocf kernel: RDX: 00000000fffffffb RSI: 0000000000000000 RDI: 00000000ffffffff
>> Oct 22 16:37:34 linux-kocf kernel: RBP: ffff8800041a2300 R08: 00000000ffffffff R09: 0000000000000000
>> Oct 22 16:37:34 linux-kocf kernel: R10: 000000000000000a R11: 0000000000018600 R12: ffff8800040c1a40
>> Oct 22 16:37:34 linux-kocf kernel: R13: ffff8800088dba14 R14: ffff8800040c1bc0 R15: ffff880004107e00
>> Oct 22 16:37:34 linux-kocf kernel: FS:  00007faf38936780(0000) GS:ffffffff80844a00(0000) knlGS:0000000000000000
>> Oct 22 16:37:34 linux-kocf kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
>> Oct 22 16:37:34 linux-kocf kernel: CR2: 0000000000000004 CR3: 0000000013cce000 CR4: 00000000000006e0
>> Oct 22 16:37:34 linux-kocf kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>> Oct 22 16:37:34 linux-kocf kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 000cifs dfs requires keyutils package to work properly. Could you check whether
>> these packages are installed0000000000400
>> Oct 22 16:37:34 linux-kocf kernel: Process ls (pid: 3757, threadinfo ffff8800088da000, task ffff8800041a2300)
>> Oct 22 16:37:34 linux-kocf kernel: Stack:  00000000000000d0 ffffffff805cedf5 0000000000000000 0000000000000000
>> Oct 22 16:37:34 linux-kocf kernel:  0000000000000000 ffffffff804a0452 ffff8800040c1b00 ffff8800040c1b04
>> Oct 22 16:37:34 linux-kocf kernel:  ffff8800040c1b00 ffffffff8031ccf6 ffff8800088dba98 0000000000000000
>> Oct 22 16:37:34 linux-kocf kernel: Call Trace:
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff803202f0>] construct_key+0xa1/0xd4
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff803203e1>] request_key_and_link+0xbe/0xfa
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff803204c8>] request_key+0x37/0x67
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffffa0334845>] dns_resolve_server_name_to_ip+0x22d/0x250 [cifs]
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffffa033499d>] compose_mount_options+0x4c/0x248 [cifs]
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffffa0334de1>] cifs_dfs_follow_mountpoint+0x216/0x412 [cifs]
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff802c3342>] __link_path_walk+0xaee/0xe0b
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff802c382a>] path_walk+0x5e/0xb9
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff802c39e7>] do_path_lookup+0x162/0x1b9
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff802c4380>] user_path_at+0x48/0x79
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff802bcd99>] vfs_stat_fd+0x18/0x44
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff802bce21>] sys_newstat+0x19/0x31
>> Oct 22 16:37:34 linux-kocf kernel:  [<ffffffff8020c37a>] system_call_fastpath+0x16/0x1b
>> Oct 22 16:37:34 linux-kocf kernel:  [<00007faf37e73af5>] 0x7faf37e73af5
>> Oct 22 16:37:34 linux-kocf kernel: 
>> Oct 22 16:37:34 linux-kocf kernel: 
>> Oct 22 16:37:34 linux-kocf kernel: Code: ef e8 c3 8e 04 00 48 8b 85 68 05 00 00 48 83 b8 30 03 00 00 00 74 09 48 8b 80 30 03 00 00 eb 0b 48 8b 85 48 04 00 00 48 8b 40 30 <8b> 50 04 48 8d 5c 24 78 48 c7 c6 0b 6cifs dfs requires keyutils package to work properly. Could you check whether
>> these packages are installed6 5c 80 31 c0 48 89 df e8 
>> Oct 22 16:37:34 linux-kocf kernel: RIP  [<ffffffff803206a4>] call_sbin_request_key+0x16d/0x28d
>> Oct 22 16:37:34 linux-kocf kernel:  RSP <ffff8800088db9a8>
>> Oct 22 16:37:34 linux-kocf kernel: CR2: 0000000000000004
>> Oct 22 16:37:34 linux-kocf kernel: ---[ end trace 4eaa2a86a8e2da22 ]---
>> ---
>>
>> kernel version - 2.6.27.1
>> Pkgs keyutils, keyutils-libs installed
>> and /etc/request.conf configured like below:
>>
>> create      cifs.spnego    * * /usr/sbin/cifs.upcall -c %k
>> create      dns_resolver   * * /usr/sbin/cifs.upcall %k
>>
>> Is this a known issue or am I missing something in the configuration?
>> Any clues?
>>
>> Thanks,
>>
> 


-- 
Suresh Jayaraman


More information about the linux-cifs-client mailing list