[linux-cifs-client] DFS fails to follow remote links
Suresh Jayaraman
sjayaraman at suse.de
Thu Nov 27 11:33:18 GMT 2008
Suresh Jayaraman wrote:
> Igor Mammedov wrote:
>
ok, the entire file is 6k, won't hurt.
Packet capture attached.
>> 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
-------------- next part --------------
A non-text attachment was scrubbed...
Name: cifsdump.cap
Type: application/x-extension-cap
Size: 6146 bytes
Desc: not available
Url : http://lists.samba.org/archive/linux-cifs-client/attachments/20081127/b4904f9c/cifsdump-0001.bin
More information about the linux-cifs-client
mailing list