Re: Process hangs copying large file to cifs

Re: Process hangs copying large file to cifs

[Steve French]

 > This is copying a 197Mb from an my laptop's IDE hardisk to a cifs 
mounted share that's on a Win2000 Server

This seems strange - looks like cifs simply called generic_write which 
goes to the page manager which in this case had to
rebalance/free up some pages which hung in local filesys routine outside 
of my code which I do not recognize.

[<c028dae0>] schedule_timeout+0x60/0xc0
[<c0131541>] __alloc_pages+0x2c1/0x300
[<c011eb00>] process_timeout+0x0/0x10
[<c028da3e>] io_schedule_timeout+0xe/0x50
[<c01ebe02>] blk_congestion_wait+0x72/0x90
[<c0116470>] autoremove_wake_function+0x0/0x50
[<c0116470>] autoremove_wake_function+0x0/0x50
[<c0132212>] get_dirty_limits+0x12/0xd0
[<c013238d>] balance_dirty_pages+0xbd/0x110
[<c012f5ad>] generic_file_aio_write_nolock+0x3ed/0x980
[<c012e2d0>] file_read_actor+0xc0/0xd0
[<c012e477>] __generic_file_aio_read+0x197/0x1d0
[<c012e210>] file_read_actor+0x0/0xd0
[<c012fb9f>] generic_file_write_nolock+0x5f/0x80
[<c014623f>] do_sync_read+0x6f/0xb0
[<c01060a3>] do_IRQ+0x113/0x150
[<c012fc8e>] generic_file_write+0x3e/0x60
[<de9c05bc>] cifs_write_wrapper+0x4c/0xb0 [cifs]

As you mentioned the vi thread is another one of the threads blocked in 
the local call "blk_congestion_wait" which may be useful to understand.

I don't see any interesting threads in cifs at first glance, although 
the call stack for the cifsoplock thread is a little odd looking (perhaps
some junk being misinterpreted on the call stack).

Could you take a look at the /proc/fs/cifs/DebugData,  which (at least 
on current 2.6.7) displays some often useful debug data
including the lists of "MIDs" (multiplex ids - pending network 
operations on the wire) if any and also /proc/fs/cifs/Stats and 
SimultaneousOps
which display counts of number of operations pending in the vfs which 
looks like only one - in this case - which is blocked outside the cifs code.

My guess is that there actually aren't any interesting threads in cifs 
at the moment, and that we need to understand the
blk_congestion_wait calls are trying to do

Re: Process hangs copying large file to cifs

[Nuno Ferreira]

CCing linux kernel ML because this might not be cifs related. I messed
up and sent the first email separately, sorry.

On Qua, 2004-06-23 at 22:16 -0500, Steve French wrote:
>  > This is copying a 197Mb from an my laptop's IDE hardisk to a cifs 
> mounted share that's on a Win2000 Server
> 
> This seems strange - looks like cifs simply called generic_write which 
> goes to the page manager which in this case had to
> rebalance/free up some pages which hung in local filesys routine outside 
> of my code which I do not recognize.

This apparently is memory pressure related, this never happened with
small files and this time around, when testing to get the info you
requested, I could copy the same file. Then I tried to copy a larger
(650Mb) file and it hang again.

> 
> [<c028dae0>] schedule_timeout+0x60/0xc0
> [<c0131541>] __alloc_pages+0x2c1/0x300
> [<c011eb00>] process_timeout+0x0/0x10
> [<c028da3e>] io_schedule_timeout+0xe/0x50
> [<c01ebe02>] blk_congestion_wait+0x72/0x90
> [<c0116470>] autoremove_wake_function+0x0/0x50
> [<c0116470>] autoremove_wake_function+0x0/0x50
> [<c0132212>] get_dirty_limits+0x12/0xd0
> [<c013238d>] balance_dirty_pages+0xbd/0x110
> [<c012f5ad>] generic_file_aio_write_nolock+0x3ed/0x980
> [<c012e2d0>] file_read_actor+0xc0/0xd0
> [<c012e477>] __generic_file_aio_read+0x197/0x1d0
> [<c012e210>] file_read_actor+0x0/0xd0
> [<c012fb9f>] generic_file_write_nolock+0x5f/0x80
> [<c014623f>] do_sync_read+0x6f/0xb0
> [<c01060a3>] do_IRQ+0x113/0x150
> [<c012fc8e>] generic_file_write+0x3e/0x60
> [<de9c05bc>] cifs_write_wrapper+0x4c/0xb0 [cifs]
> 
> As you mentioned the vi thread is another one of the threads blocked in 
> the local call "blk_congestion_wait" which may be useful to understand.

The vi isn't responsible for the problem, it's just that I run vi on a
file every now and then while testing to detect when the hang occurs. If
I can open (or close) the file with vi, it's still running, if the open
or close operation using vi hangs I know it will not recover anymore.
So it's not a problem, its a symptom.

> 
> I don't see any interesting threads in cifs at first glance, although 
> the call stack for the cifsoplock thread is a little odd looking (perhaps
> some junk being misinterpreted on the call stack).
> 
> Could you take a look at the /proc/fs/cifs/DebugData,  which (at least 
> on current 2.6.7) displays some often useful debug data
> including the lists of "MIDs" (multiplex ids - pending network 
> operations on the wire) if any and also /proc/fs/cifs/Stats and 
> SimultaneousOps
> which display counts of number of operations pending in the vfs which 
> looks like only one - in this case - which is blocked outside the cifs code.

Here's the requested data:
taz:/home/nmf# cat /proc/fs/cifs/DebugData
Display Internal CIFS Data Structures for Debugging
---------------------------------------------------
Servers:

1) Name: 10.1.1.1  Domain: GRAYCELL Mounts: 1 ServerOS: Windows 5.0
        ServerNOS: Windows 2000 LAN Manager     Capabilities: 0xf3fd
        SMB session status: 1   TCP status: 1
        Local Users To Server: 1 SecMode: 0x3 Req Active: 0

Shares:

1) \\ODIE\GRAYCELL Uses: 1 Type: NTFS Characteristics: 0x20 Attributes: 0x700ff
PathComponentMax: 255 Status: 1 type: DISK
taz:/home/nmf# cat /proc/fs/cifs/Stats
Resources in use
CIFS Session: 1
Share (unique mount targets): 1
SMB Request/Response Buffer: 1
Operations (MIDs): 0

0 session 0 share reconnects

1) \\ODIE\GRAYCELL
SMBs: 49779 Oplock Breaks: 0
Reads: 0 Bytes 0
Writes: 49741 Bytes: 2taz:/home/nmf# cat /proc/fs/cifs/SimultaneousOps
Total vfs operations: 199171 and maximum simultaneous serviced by this filesystem: 4


By the way, it appears like there is some problem with the /proc/fs/
cifs/Stats output.

> 
> My guess is that there actually aren't any interesting threads in cifs 
> at the moment, and that we need to understand the
> blk_congestion_wait calls are trying to do
> 
-- 
Nuno Ferreira

Re: Process hangs copying large file to cifs

[Steve French]

>  > This is copying a 197Mb from an my laptop's IDE hardisk to a cifs 
> mounted share that's on a Win2000 Server

Linus had suggested hashing cifs inodes, which makes sense as related to
the problem that you reported.  I have coded that and it tested out ok
today. If you have a chance could you try the patch at:

http://cifs.bkbits.net:8080/linux-2.5cifs/gnupatch@40e0925dAlasT6JDoPqQE2q3e-zYiw

Re: Process hangs copying large file to cifs

[Nuno Ferreira]

On Seg, 2004-06-28 at 16:58 -0500, Steve French wrote:
> >  > This is copying a 197Mb from an my laptop's IDE hardisk to a cifs 
> > mounted share that's on a Win2000 Server
> 
> Linus had suggested hashing cifs inodes, which makes sense as related to
> the problem that you reported.  I have coded that and it tested out ok
> today. If you have a chance could you try the patch at:
> 
> http://cifs.bkbits.net:8080/linux-2.5cifs/gnupatch@40e0925dAlasT6JDoPqQE2q3e-zYiw

I applied it by hand to plain 2.6.7 (had some rejects) and it appears to
work. Thank you.
I just copied a 600Mb from my laptop to the server with no problems,
continued to work on my desktop with no visible effects.
Great work.
-- 
Nuno Ferreira

Re: Process hangs copying large file to cifs

[Nuno Ferreira]

On Ter, 2004-06-29 at 12:12 +0100, Nuno Ferreira wrote:
> On Seg, 2004-06-28 at 16:58 -0500, Steve French wrote:
> > >  > This is copying a 197Mb from an my laptop's IDE hardisk to a cifs 
> > > mounted share that's on a Win2000 Server
> > 
> > Linus had suggested hashing cifs inodes, which makes sense as related to
> > the problem that you reported.  I have coded that and it tested out ok
> > today. If you have a chance could you try the patch at:
> > 
> > http://cifs.bkbits.net:8080/linux-2.5cifs/gnupatch@40e0925dAlasT6JDoPqQE2q3e-zYiw
> 
> I applied it by hand to plain 2.6.7 (had some rejects) and it appears to
> work. Thank you.
> I just copied a 600Mb from my laptop to the server with no problems,
> continued to work on my desktop with no visible effects.

Unfortunately it appears the problem still exists, or maybe it's another
one with the same visible effects.
I don't use the windows share very often, and with large files it's even
less often, so I just found out today.
Trying to copy a ~180Mb file from the same machine (still using the same
kernel) to the same share, I had the same problem. Eventually, after
30min and lot's of freezes the file was copied but corrupted.
Here 
One thing is different, this time I got messages in the system logs,
they repeat for the whole time the file was copying.
Also, after copying the file I had this strange (-6) ReqActive count, is
it expected? Now (about 10 min later) it shows 0;

nmf@taz:~/Desktop/Downloads$ cat /proc/fs/cifs/DebugData
Display Internal CIFS Data Structures for Debugging
---------------------------------------------------
Servers:

1) Name: 10.1.1.14  Domain: GRAYCELL Mounts: 1 ServerOS: Windows 5.0
        ServerNOS: Windows 2000 LAN Manager     Capabilities: 0xf3fd
        SMB session status: 1   TCP status: 1
        Local Users To Server: 1 SecMode: 0x3 Req Active: -6
2) Name: 10.1.1.1  Domain: GRAYCELL Mounts: 1 ServerOS: Windows 5.0
        ServerNOS: Windows 2000 LAN Manager     Capabilities: 0xf3fd
        SMB session status: 3   TCP status: 1
        Local Users To Server: 1 SecMode: 0x3 Req Active: 0

Shares:

1) \\pepe\nmf Uses: 1 Type: FAT Characteristics: 0x20 Attributes: 0x6
PathComponentMax: 255 Status: 1 type: DISK
2) \\ODIE\GRAYCELL Uses: 1 Type: NTFS Characteristics: 0x20 Attributes: 0x700ff
PathComponentMax: 255 Status: 3 type: DISK      DISCONNECTED

Here are the errors
syslog
------
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: No task to wake, unknown frame rcvd!
Aug 12 16:13:00 taz kernel: Received Data is: : dump of 37 bytes of data at 0xd9e10660
Aug 12 16:13:00 taz kernel:
Aug 12 16:13:00 taz kernel:  2f000000 424d53ff 0000002f c0018000 . . . / \xff S M B / . . . . . . \xc0
Aug 12 16:13:00 taz kernel:  00000000 00000000 00000000 0c796002 . . . . . . . . . . . . . ` y .
Aug 12 16:13:00 taz kernel:  0b39d000 2f00ff06 . \xd0 9 . .
Aug 12 16:13:02 taz kernel:  CIFS VFS: No response buffer
Aug 12 16:13:07 taz last message repeated 5 times
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: No task to wake, unknown frame rcvd!
Aug 12 16:14:00 taz kernel:
Aug 12 16:14:00 taz kernel:  2f000000 424d53ff 0000002f c0018000 . . . / \xff S M B / . . . . . . \xc0
Aug 12 16:14:00 taz kernel:  00000000 00000000 00000000 0c796000 . . . . . . . . . . . . . ` y .
Aug 12 16:14:00 taz kernel:  0cbeb800 2f00ff06 . \xb8 \xbe . .
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:02 taz kernel:  CIFS VFS: No response buffer
Aug 12 16:14:07 taz last message repeated 7 times

-- 
Nuno Ferreira

Re: Process hangs copying large file to cifs

[Nuno Ferreira]

On Ter, 2004-06-29 at 12:12 +0100, Nuno Ferreira wrote:
> On Seg, 2004-06-28 at 16:58 -0500, Steve French wrote:
> > >  > This is copying a 197Mb from an my laptop's IDE hardisk to a cifs 
> > > mounted share that's on a Win2000 Server
> > 
> > Linus had suggested hashing cifs inodes, which makes sense as related to
> > the problem that you reported.  I have coded that and it tested out ok
> > today. If you have a chance could you try the patch at:
> > 
> > http://cifs.bkbits.net:8080/linux-2.5cifs/gnupatch@40e0925dAlasT6JDoPqQE2q3e-zYiw
> 
> I applied it by hand to plain 2.6.7 (had some rejects) and it appears to
> work. Thank you.
> I just copied a 600Mb from my laptop to the server with no problems,
> continued to work on my desktop with no visible effects.

Unfortunately it appears the problem still exists, or maybe it's another
one with the same visible effects.
I don't use the windows share very often, and with large files it's even
less often, so I just found out today.
Trying to copy a ~180Mb file from the same machine (still using the same
kernel) to the same share, I had the same problem. Eventually, after
30min and lot's of freezes the file was copied but corrupted.
Here 
One thing is different, this time I got messages in the system logs,
they repeat for the whole time the file was copying.
Also, after copying the file I had this strange (-6) ReqActive count, is
it expected? Now (about 10 min later) it shows 0;

nmf@taz:~/Desktop/Downloads$ cat /proc/fs/cifs/DebugData
Display Internal CIFS Data Structures for Debugging
---------------------------------------------------
Servers:

1) Name: 10.1.1.14  Domain: GRAYCELL Mounts: 1 ServerOS: Windows 5.0
        ServerNOS: Windows 2000 LAN Manager     Capabilities: 0xf3fd
        SMB session status: 1   TCP status: 1
        Local Users To Server: 1 SecMode: 0x3 Req Active: -6
2) Name: 10.1.1.1  Domain: GRAYCELL Mounts: 1 ServerOS: Windows 5.0
        ServerNOS: Windows 2000 LAN Manager     Capabilities: 0xf3fd
        SMB session status: 3   TCP status: 1
        Local Users To Server: 1 SecMode: 0x3 Req Active: 0

Shares:

1) \\pepe\nmf Uses: 1 Type: FAT Characteristics: 0x20 Attributes: 0x6
PathComponentMax: 255 Status: 1 type: DISK
2) \\ODIE\GRAYCELL Uses: 1 Type: NTFS Characteristics: 0x20 Attributes: 0x700ff
PathComponentMax: 255 Status: 3 type: DISK      DISCONNECTED

Here are the errors
syslog
------
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:13:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:13:00 taz kernel:  CIFS VFS: No task to wake, unknown frame rcvd!
Aug 12 16:13:00 taz kernel: Received Data is: : dump of 37 bytes of data at 0xd9e10660
Aug 12 16:13:00 taz kernel:
Aug 12 16:13:00 taz kernel:  2f000000 424d53ff 0000002f c0018000 . . . / \xff S M B / . . . . . . \xc0
Aug 12 16:13:00 taz kernel:  00000000 00000000 00000000 0c796002 . . . . . . . . . . . . . ` y .
Aug 12 16:13:00 taz kernel:  0b39d000 2f00ff06 . \xd0 9 . .
Aug 12 16:13:02 taz kernel:  CIFS VFS: No response buffer
Aug 12 16:13:07 taz last message repeated 5 times
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: No task to wake, unknown frame rcvd!
Aug 12 16:14:00 taz kernel:
Aug 12 16:14:00 taz kernel:  2f000000 424d53ff 0000002f c0018000 . . . / \xff S M B / . . . . . . \xc0
Aug 12 16:14:00 taz kernel:  00000000 00000000 00000000 0c796000 . . . . . . . . . . . . . ` y .
Aug 12 16:14:00 taz kernel:  0cbeb800 2f00ff06 . \xb8 \xbe . .
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:00 taz kernel:  CIFS VFS: sends on sock dc041620 stuck for 30 seconds
Aug 12 16:14:00 taz kernel:  CIFS VFS: Error -11 sending data on socket to server.
Aug 12 16:14:02 taz kernel:  CIFS VFS: No response buffer
Aug 12 16:14:07 taz last message repeated 7 times

-- 
Nuno Ferreira

Re: Process hangs copying large file to cifs

[Nuno Ferreira]

On Sex, 2004-08-13 at 01:34 -0500, Steve French (IBM LTC) wrote:
> Your log entries indicate that the socket was dead, so the patch you hand applied for hashing of inodes
> appears unrelated.

I just mentioned the previous problem because the behaviour was pretty
much the same as before, long times of no TCP traffic, intermittent
freezes apparently of all the processes trying to do IO to the disk.

> Many (including myself copy) much larger files regularly via CIFS.

It appears (purely speculation, no hard facts to back it up) related to
memory pressure, it doesn't happen with smaller files (my laptop has
512Mb) and it happens less often on the second copy if the file fits on
cache. 

> I don't know
> whether the best approach is to backport the other fixes that could affect this code path to your kernel
> so we can see if this is a current problem in some recovery path or has already been fixed.   There are
> only three to four global changes in the kernel (that hit the fs/cifs directory) since 2.6.6 that would
> have to be dealt with to compile the current 2.6.8 fs/cifs directory on an older 2.6.6 kernel.

I'm running 2.6.7, are the changes contained in 2.6.8-rc(something)? I
cant try them or an -mm kernel if you prefer.

-- 
Nuno Ferreira

Re: Process hangs copying large file to cifs

[Steve French (IBM LTC)]

Your log entries indicate that the socket was dead, so the patch you hand applied for hashing of inodes
appears unrelated.   Many (including myself copy) much larger files regularly via CIFS.   I don't know
whether the best approach is to backport the other fixes that could affect this code path to your kernel
so we can see if this is a current problem in some recovery path or has already been fixed.   There are
only three to four global changes in the kernel (that hit the fs/cifs directory) since 2.6.6 that would
have to be dealt with to compile the current 2.6.8 fs/cifs directory on an older 2.6.6 kernel.

Nuno Ferreira wrote:

> On Ter, 2004-06-29 at 12:12 +0100, Nuno Ferreira wrote:
> > On Seg, 2004-06-28 at 16:58 -0500, Steve French wrote:
> > > >  > This is copying a 197Mb from an my laptop's IDE hardisk to a cifs
> > > > mounted share that's on a Win2000 Server
> > >
>

Re: Process hangs copying large file to cifs

[Nuno Ferreira]

On Qui, 2004-08-12 at 21:06 +0100, Nuno Ferreira wrote:
> On Sex, 2004-08-13 at 01:34 -0500, Steve French (IBM LTC) wrote:
> > Your log entries indicate that the socket was dead, so the patch you hand applied for hashing of inodes
> > appears unrelated.
> 
> I just mentioned the previous problem because the behaviour was pretty
> much the same as before, long times of no TCP traffic, intermittent
> freezes apparently of all the processes trying to do IO to the disk.
> 
> > Many (including myself copy) much larger files regularly via CIFS.
> 
> It appears (purely speculation, no hard facts to back it up) related to
> memory pressure, it doesn't happen with smaller files (my laptop has
> 512Mb) and it happens less often on the second copy if the file fits on
> cache. 

I've now reproduced it with 2.6.8-rc4. Just after boot I could not
reproduce it with the previous file, but trying with a larger (350Mb)
file it happened again. Another hint to memory pressure? I will try
again in a few hours with the smaller file to see if it happens...
Just tried, this time it happened with the first (smaller) file.
What info can I try to collect to help you find the problem?
-- 
Nuno Ferreira