Samba write performance anomaly

[Richard Sharpe]

At 07:34 AM 5/25/00 +1000, David Collier-Brown wrote:
>Steve Snyder wrote:
>> Every few months I get sick of the miserable write performance on my
>> Samba servers and vow to fix it.  It's that time again.
>
>	And he was kind enough to provide enough information
>	to expose some rather **odd** symptoms....
>
>
>recv(6, "\0\0\354\0", 4, 0)             = 4
>read(6, "\377u\10\377\25(\343@\0\213\330\353"..., 16384) = 5836
>write(8, "\377u\10\377\25(\343@\0\213\330\353"..., 5836) = 5836
>read(6, "W\353\3\200\3030\210\36F\205\311"..., 16384) = 5840
>write(8, "W\353\3\200\3030\210\36F\205\311"..., 5840) = 5840

...

>read(6, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384) = 1823
>write(8, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1823) = 1823
>read(6, "\0\0\0\0\0\204\340\0\0\0\0\0\0\0"..., 16384) = 1460
>write(8, "\0\0\0\0\0\204\340\0\0\0\0\0\0\0"..., 1460) = 1460
>read(6, "ndowsDirectoryA\0\0KERNEL32.dll\0"..., 16384) = 5840
>write(8, "ndowsDirectoryA\0\0KERNEL32.dll\0"..., 5840) = 5840
>read(6, "\0s\0.\0 \0D\0o\0 \0y\0o\0u\0 \0"..., 16257) = 5840
>write(8, "\0s\0.\0 \0D\0o\0 \0y\0o\0u\0 \0"..., 5840) = 5840
>read(6, "PG\34\323\263\261O\315\223\260r\24"..., 10417) = 5840
>write(8, "PG\34\323\263\261O\315\223\260r\24"..., 5840) = 5840
>read(6, "\r\10\16\n\260%h\201\245L\242\34"..., 4577) = 4577
>write(8, "\r\10\16\n\260%h\201\245L\242\34"..., 4577) = 4577

...

>read(6, "\215\30\vi\302\354P\260\263\1\304"..., 16384) = 5836
>write(8, "\215\30\vi\302\354P\260\263\1\304"..., 5836) = 5836
>read(6, "aGB\304\306@\231\22\4J\22\27D`0\255"..., 16384) = 5840
>write(8, "aGB\304\306@\231\22\4J\22\27D`0\255"..., 5840) = 5840

...

>  I know there are supposed to be read/read-raw alternatiuons
>but what looks suspicious to me are:
>
>     1) the size of the reads alternates, bouncing between
>	16384 and 5840 (or whatever's left over from the
>	last read).  This looks like old DSA code reading
>	implied records whose size is floating between 5840
>	5836 and 4577... Is there something that limits the
>	protocol to such short reads? I'd have expected to
>	see a normal TCP stream read cycle, with reads of, say,
>	16384 bytes in rapid sucession, followed by only one
>	read which gets fewer bytes, at the end of the file.

Well, I have seen Win9X behaviour where MAX WRITE or MAX SEND was 2920
before. 5840 is twice that, so maybe it is Win98 and they have doubled this
value.

There are some interesting numbers above, but 5836 is simply 5840 minus 4,
which may allow for the NetBIOS header, or the code may be confused and may
be allowing for that at times when it should not (Win9X's VNETSUP code).

The 1460 looks interesting as well, being a full Etherent frame.

>     2) the sizes are much smaller than on my Slolaris box,
>	and my machine doesn't alternate sizes:   

But below, you are only looking at reads, and you appear to have MAX SEND
set to 8192 ...

I would be really interested to see a tcpdump capture so I can look to see
if things like the NODELAY option has been set, and exactly what the timing
relationships are between the response to the writeraw is and the next
SMBwrite or writeraw coming from the client.

And remember, there is a known problem with Win9X around retransmitting too
soon, which may be causing this. We cannot see the tcp segments at this
level, but a packet trace would tell us the whole story.

  
>320.3457        send(4, "\0\004 +FF S M B /\0\0\0".., 1071, 0)  = 1071
>320.3489        poll(0xFFBED378, 1, 20000)                      = 1
>320.3491        read(4, "\0\0\0 /", 4)                          = 4
>320.3494        read(4, "FF S M B /\0\0\0\08801\0".., 47)       = 47
>320.3498        read(5, "88 5B2 & v $E9 x fC8C0 .".., 8192)     = 8192
>320.3502        read(5, "A014 y83C59F89E414DFB0 T".., 8192)     = 8192
>320.3506        read(5, " F069B19B4 1D8C5A093 A17".., 8192)     = 8192
>320.3509        read(5, "FBFEE0\0A5CFD3EA 9F2E1 @".., 8192)     = 8192
>320.3513        read(5, " _FD f9D I p g 1F9CCE7 4".., 8192)     = 8192
>320.3517        read(5, " ' 81E c 4 b\fD51803A5 T".., 8192)     = 8192
>320.3521        read(5, "91 IDEFA V 4\f96 ( ? v j".., 8192)     = 8192
>320.3525        read(5, " n Y F89 3AC U1505 MDE c".., 8192)     = 8192
>320.4046        send(4, "\0\0FC ;FF S M B /\0\0\0".., 64575, 0) =
>64575
>
>	Anyone recognize a cause for slow write-to-server performance?


Regards
-------
Richard Sharpe, sharpe at ns.aus.com
Samba (Team member, www.samba.org), Ethereal (Team member, www.zing.org)
Co-author, SAMS Teach Yourself Samba in 24 Hours
Author: First Australian 5-day, intensive, hands-on Linux SysAdmin course
Author: First Australian 2-day, intensive, hands-on Samba course