5005 – Cifs + Apache = Borked?

Bug 5005 - Cifs + Apache = Borked?

Summary: Cifs + Apache = Borked?

Status:	RESOLVED WONTFIX

Alias:	None

Product:	CifsVFS
Classification:	Unclassified
Component:	kernel fs (show other bugs)
Version:	2.6
Hardware:	x64 Linux

Importance:	P3 normal
Target Milestone:	---
Assignee:	Steve French
QA Contact:

URL:
Keywords:

Depends on:
Blocks:

Reported:	2007-10-03 18:36 UTC by Hagan Franks
Modified:	2007-10-10 15:24 UTC (History)
CC List:	0 users

See Also:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.

Description Hagan Franks 2007-10-03 18:36:34 UTC

My apologies if this problem has already been discussed; I've searched the net and have yet found a solution to this seemingly simple problem.  I've got a windows file server (2003) sharing video files.... I can successfully connect to this share and transfer,edit,delete etc files to my hearts content.  However, when i try to transfer anything via apache, after about 30-150k, the transfer stops and no matter where i look i can't find a log suggesting anything is wrong. (So I am hoping this is a bug and not me being dumb and wasting your time)

The mount command i'm using:
//myvideoserver/online_videos /mnt/video cifs user,file_mode=0664,dir_mode=0775,uid=48,gid=48,rw,noauto,credentials=/etc/smb.auth 0 0

uid, gid are set to 'apache' so apache can read these files, and it can because i'm not having an access denied error.  I've modified the selinux policy to allow cifs_t through... But to be sure, i've disabled selinux.

To test i'm using the following httpd.conf addition so i can make sure this isn't all apaches fault.... (works when video is local and not a remote share)

<Directory "/mnt/video">
    Options Indexes MultiViews
    AllowOverride None
    Order allow,deny
    Allow from all
</Directory>

I've checked these logs and found nothing:

 /var/log/messages, /var/log/httpd/access_log, /var/log/httpd/error_log, /var/log/audit/audit.log etc.... 

After setting the debug flags for cifs, dmesg reports the following when apache pushes a file....
  "GET /videos/dailydose/dd-2007-10-01.flv HTTP/1.1"

fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51531 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose inode 0xffff8800052f9d38 count 1 dentry: 0xffff88001d293d20 d_time 4297829556 jiffies 4298606305
 fs/cifs/inode.c: Getting info on \dailydose
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 94
 fs/cifs/connect.c: rfc1002 length 0xc2)
 fs/cifs/inode.c: Old time 4298549150
 fs/cifs/inode.c: New time 4298606305
 fs/cifs/inode.c: Directory inode
 fs/cifs/inode.c: cifs_revalidate - inode unchanged
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51531) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51532 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose\dd-2007-10-01.flv inode 0xffff880003ba6d78 count 1 dentry: 0xffff880002f32810 d_time 4298526848 jiffies 4298606305
 fs/cifs/inode.c: Getting info on \dailydose\dd-2007-10-01.flv
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 130
 fs/cifs/connect.c: rfc1002 length 0xe6)
 fs/cifs/inode.c: Old time 4298526848
 fs/cifs/inode.c: New time 4298606305
 fs/cifs/inode.c: File inode
 fs/cifs/inode.c: cifs_revalidate - inode unchanged
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51532) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51533 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose\dd-2007-10-01.flv inode 0xffff880003ba6d78 count 1 dentry: 0xffff880002f32810 d_time 4298526848 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51533) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51534 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose inode 0xffff8800052f9d38 count 1 dentry: 0xffff88001d293d20 d_time 4297829556 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51534) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51535 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose inode 0xffff8800052f9d38 count 1 dentry: 0xffff88001d293d20 d_time 4297829556 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51535) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51536 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose inode 0xffff8800052f9d38 count 1 dentry: 0xffff88001d293d20 d_time 4297829556 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51536) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51537 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose\dd-2007-10-01.flv inode 0xffff880003ba6d78 count 1 dentry: 0xffff880002f32810 d_time 4298526848 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51537) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51538 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose\dd-2007-10-01.flv inode 0xffff880003ba6d78 count 1 dentry: 0xffff880002f32810 d_time 4298526848 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51538) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51539 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose inode 0xffff8800052f9d38 count 1 dentry: 0xffff88001d293d20 d_time 4297829556 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51539) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 51540 with uid: 48
 fs/cifs/inode.c: Revalidate: \dailydose\dd-2007-10-01.flv inode 0xffff880003ba6d78 count 1 dentry: 0xffff880002f32810 d_time 4298526848 jiffies 4298606305
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 51540) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_open as Xid: 51541 with uid: 48
 fs/cifs/file.c:  inode = 0xffff880003ba6d78 file flags are 0x8000 for \dailydose\dd-2007-10-01.flv
 fs/cifs/transport.c: For smb_command 162
 fs/cifs/transport.c: Sending smb of length 142
 fs/cifs/connect.c: rfc1002 length 0x6b)
 fs/cifs/file.c: inode unchanged on server
 fs/cifs/inode.c: Getting info on \dailydose\dd-2007-10-01.flv
 fs/cifs/inode.c: Old time 4298606305
 fs/cifs/inode.c: New time 4298606305
 fs/cifs/inode.c: File inode
 fs/cifs/file.c: Exclusive Oplock granted on inode ffff880003ba6d78
 fs/cifs/file.c: CIFS VFS: leaving cifs_open (xid = 51541) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_readpages as Xid: 51542 with uid: 48
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/file.c: CIFS VFS: leaving cifs_readpages (xid = 51542) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_readpages as Xid: 51543 with uid: 48
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/cifssmb.c: Reading 16384 bytes on fid 16390
 fs/cifs/transport.c: For smb_command 46
 fs/cifs/transport.c: Sending smb:  total_len 63
 fs/cifs/connect.c: rfc1002 length 0x403f)
 fs/cifs/file.c: CIFS VFS: leaving cifs_readpages (xid = 51543) rc = 0
 fs/cifs/file.c: CIFS VFS: in cifs_writepages as Xid: 51544 with uid: 48
 fs/cifs/file.c: CIFS VFS: leaving cifs_writepages (xid = 51544) rc = 0
 fs/cifs/file.c: Flush inode ffff880003ba6d78 file ffff88000eb8c4c0 rc 0
 fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 51545 with uid: 48
 fs/cifs/cifssmb.c: In CIFSSMBClose
 fs/cifs/transport.c: For smb_command 4
 fs/cifs/transport.c: Sending smb of length 41
 fs/cifs/connect.c: rfc1002 length 0x27)
 fs/cifs/file.c: closing last open instance for inode ffff880003ba6d78
 fs/cifs/file.c: CIFS VFS: leaving cifs_close (xid = 51545) rc = 0
-------------------Stops here after pushing about 35k of data--------------------------------

The following is debug output of the file successfully getting copied from the comand line.....
 fs/cifs/file.c: CIFS VFS: leaving cifs_readpages (xid = 52349) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 52350 with uid: 0
 fs/cifs/inode.c: Revalidate: \dailydose inode 0xffff8800052f9d38 count 1 dentry: 0xffff88001d293d20 d_time 4297829556 jiffies 4298662539
 fs/cifs/inode.c: Getting info on \dailydose
 fs/cifs/transport.c: For smb_command 50
 fs/cifs/transport.c: Sending smb of length 94
 fs/cifs/connect.c: rfc1002 length 0xc2)
 fs/cifs/inode.c: Old time 4298661602
 fs/cifs/inode.c: New time 4298662539
 fs/cifs/inode.c: Directory inode
 fs/cifs/inode.c: cifs_revalidate - inode unchanged
 fs/cifs/inode.c: CIFS VFS: leaving cifs_revalidate (xid = 52350) rc = 0
 fs/cifs/xattr.c: CIFS VFS: in cifs_getxattr as Xid: 52351 with uid: 0
 fs/cifs/xattr.c: CIFS VFS: leaving cifs_getxattr (xid = 52351) rc = -95
 fs/cifs/file.c: CIFS VFS: in cifs_writepages as Xid: 52352 with uid: 0
 fs/cifs/file.c: CIFS VFS: leaving cifs_writepages (xid = 52352) rc = 0
 fs/cifs/file.c: Flush inode ffff880003ba6d78 file ffff88000ea0ca80 rc 0
 fs/cifs/file.c: CIFS VFS: in cifs_close as Xid: 52353 with uid: 0
 fs/cifs/cifssmb.c: In CIFSSMBClose
 fs/cifs/transport.c: For smb_command 4
 fs/cifs/transport.c: Sending smb of length 41
 fs/cifs/connect.c: rfc1002 length 0x27)
 fs/cifs/file.c: closing last open instance for inode ffff880003ba6d78
 fs/cifs/file.c: CIFS VFS: leaving cifs_close (xid = 52353) rc = 0
 fs/cifs/inode.c: CIFS VFS: in cifs_revalidate as Xid: 52354 with uid: 0
 fs/cifs/inode.c: Revalidate: \dailydose inode 0xffff8800052f9d38 count 1 dentry: 0xffff88001d293d20 d_time 4297829556 jiffies 4298662541
------------------------------------------------------------------

I don't know what i'm looking for in the debug statements.. else i probably wouldn't be posting this...

Oh, i'm running centos 5 with 2.6.18-8.1.8.el5xen kernel, x86_64 connecting to a windows 2003 server.  

thanks,

hagan

Comment 1 Hagan Franks 2007-10-10 15:24:10 UTC

I found a solution to my problem... Looks like an apache bug/feature I missed on apache's own site....  If anyone else has them problem goto:

http://issues.apache.org/bugzilla/show_bug.cgi?id=42751

for a fix.