DOS clients slow on Samba 4.1.7+ (bug 10422)

Discussion:

Dominic Raferd

2014-10-10 13:08:30 UTC

Sorry I am not a Samba technical expert, but I believe there is a new
and quite severe bug for Samba 4.1.7+ introduced by bug fix 10422.
Although intended to cope with max xmit > 64kb it is having unintended
negative consequences for legacy client machines using DOS.

This message appears hundreds of thousands of times in logs (even with
log level 0), and file accesses are slow slow slow:

reply_read: requested read size (1024) is greater than maximum
allowed (972/1024). Returning short read of maximum allowed for
compatibility with Windows 2000.

The problem seems to be that samba has max_send is 972 and the new
bugfix code therefore blocks a *read* size of 1024. However the
connections for these clients always worked perfectly before with the
old test (which was against *max_recv* instead of max_send) (e.g. with
Samba 4.1.5).

The protocol my DOS clients are using is what Samba calls 'LANMAN2'
(Microsoft Networking).

I have tried different smb.conf settings (max xmit, socket options
SO_SNDBUG and SO_RCVBUF) and also varied settings on the DOS clients,
all to no avail. My conclusion is that Samba 4.1.7+ is broken, or at
least badly wounded, for these clients.

I would be very grateful if it could be fixed!

Dominic

Volker Lendecke

2014-10-10 13:26:51 UTC

Permalink

Post by Dominic Raferd
Sorry I am not a Samba technical expert, but I believe there is a
new and quite severe bug for Samba 4.1.7+ introduced by bug fix
10422. Although intended to cope with max xmit > 64kb it is having
unintended negative consequences for legacy client machines using
DOS.
This message appears hundreds of thousands of times in logs (even
reply_read: requested read size (1024) is greater than maximum
allowed (972/1024). Returning short read of maximum allowed for
compatibility with Windows 2000.
The problem seems to be that samba has max_send is 972 and the new
bugfix code therefore blocks a *read* size of 1024. However the
connections for these clients always worked perfectly before with
the old test (which was against *max_recv* instead of max_send)
(e.g. with Samba 4.1.5).
The protocol my DOS clients are using is what Samba calls 'LANMAN2'
(Microsoft Networking).
I have tried different smb.conf settings (max xmit, socket options
SO_SNDBUG and SO_RCVBUF) and also varied settings on the DOS
clients, all to no avail. My conclusion is that Samba 4.1.7+ is
broken, or at least badly wounded, for these clients.
I would be very grateful if it could be fixed!

Can you send a network trace of such a client? Please
include the start of the connection. Please see

https://wiki.samba.org/index.php/Capture_Packets

Thanks,

Volker

--
SerNet GmbH, Bahnhofsallee 1b, 37081 G?ttingen
phone: +49-551-370000-0, fax: +49-551-370000-9
AG G?ttingen, HRB 2816, GF: Dr. Johannes Loxen
http://www.sernet.de, mailto:kontakt at sernet.de

Dominic Raferd

2014-10-10 13:41:52 UTC

Permalink

Post by Volker Lendecke

Can you send a network trace of such a client? Please
include the start of the connection. Please see
https://wiki.samba.org/index.php/Capture_Packets
Thanks,
Volker

Hi Volker,

Yes I think I can do that with tcpdump, do I just zip it up and post it
here?

Dominic

Volker Lendecke

2014-10-10 14:06:07 UTC

Permalink

Post by Dominic Raferd
Yes I think I can do that with tcpdump, do I just zip it up and post
it here?

Sure. If you think it's too large, send it to me directly.

Volker

--
SerNet GmbH, Bahnhofsallee 1b, 37081 G?ttingen
phone: +49-551-370000-0, fax: +49-551-370000-9
AG G?ttingen, HRB 2816, GF: Dr. Johannes Loxen
http://www.sernet.de, mailto:kontakt at sernet.de

Dominic Raferd

2014-10-10 14:24:24 UTC

Permalink

Post by Volker Lendecke

Post by Dominic Raferd
Yes I think I can do that with tcpdump, do I just zip it up and post
it here?

Sure. If you think it's too large, send it to me directly.
Volker

OK, sent it to you direct. Dominic

Dominic Raferd

2014-10-10 15:22:22 UTC

Permalink

Post by Volker Lendecke

Post by Dominic Raferd
Yes I think I can do that with tcpdump, do I just zip it up and post
it here?

Sure. If you think it's too large, send it to me directly.
Volker

Sorry not sure what you mean, what is 'read raw'? Should I have used
different settings for tcpdump? I have not made any changes to my client
network settings since trying to move from Samba 4.1.5 to 4.1.12 (that
is, I have tried various changes but reverted to the original settings,
and I have also confirmed today with another server that 4.1.5 still
works fast with the DOS client, and doesn't produce all these messages
in the log).

(BTW I am subscribed to the mailing list, so no need to email me
directly...)

Dominic

Volker Lendecke

2014-10-10 14:47:50 UTC

Permalink

Post by Volker Lendecke

Post by Dominic Raferd
Yes I think I can do that with tcpdump, do I just zip it up and post
it here?

Sure. If you think it's too large, send it to me directly.

So you depend on the "read raw"? Without that your client is
unusably slow?

Volker

--
SerNet GmbH, Bahnhofsallee 1b, 37081 G?ttingen
phone: +49-551-370000-0, fax: +49-551-370000-9
AG G?ttingen, HRB 2816, GF: Dr. Johannes Loxen
http://www.sernet.de, mailto:kontakt at sernet.de

Dominic Raferd

2014-10-11 04:51:40 UTC

Permalink

Post by Volker Lendecke

Post by Dominic Raferd
Yes I think I can do that with tcpdump, do I just zip it up and post
it here?

Sure. If you think it's too large, send it to me directly.

So you depend on the "read raw"? Without that your client is
unusably slow?
Volker

Now I look at the trace in Wireshark I begin to understand what you
mean. I attach the first 200 packets of the original trace and also the
first 200 packets of an identical series of actions initiated from the
same client machine but to a server running samba 4.1.5 instead of
4.1.12. Looking at the full packet trace (not attached) shows that the
complete sequence took 13.3 seconds with 4.1.5 but took 49.4 seconds
with 4.1.12. The time does not just depend on the network communication,
but this is the only factor that has changed between the two traces.

You are the expert, but from what I can see the problem starts at line
128/129 (129/130 for 4.1.5). At line 128 the client requests a read of
1024 bytes, but Samba responds (line 129) with 972 bytes, whereas Samba
4.1.5 responds with 1024 bytes. In both cases the client then switches
to 'read raw', so this behaviour seems to be normal.

Dominic
--
*TimeDicer* <http://www.timedicer.co.uk>: Free File Recovery from Whenever
-------------- next part --------------
A non-text attachment was scrubbed...
Name: samba4.1.5-dos.pcap
Type: application/octet-stream
Size: 98816 bytes
Desc: not available
URL: <http://lists.samba.org/pipermail/samba-technical/attachments/20141011/5681427c/attachment-0002.obj>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: samba4.1.12-dos.pcap
Type: application/octet-stream
Size: 124951 bytes
Desc: not available
URL: <http://lists.samba.org/pipermail/samba-technical/attachments/20141011/5681427c/attachment-0003.obj>

Jeremy Allison

2014-10-10 18:33:52 UTC

Permalink

Can you log a bug in buzilla and upload a wireshark
packet capture trace (including negprot onwards) to
the bug report please.

In the meantime, and after reading the MS-CIFS doc
I'm wondering if the server is over protecting
the client from its own folly here.

After all, SMB_COM_READ (and SMB_COM_LOCK_AND_READ) state:

CountOfBytesToRead (2 bytes): This field is a 16-bit unsigned integer indicating the number of
bytes to be read from the file. The client MUST ensure that the amount of data requested will fit in
the negotiated maximum buffer size.

So it is the client, not server responsibility
to send a correct size here.

Given that, you could try the following (untested)
patch...

Jeremy.
-------------- next part --------------
diff --git a/source3/smbd/reply.c b/source3/smbd/reply.c
index 3f5b950..93675b4 100644
--- a/source3/smbd/reply.c
+++ b/source3/smbd/reply.c
@@ -3534,11 +3534,23 @@ void reply_lockread(struct smb_request *req)
maxtoread = sconn->smb1.sessions.max_send - (smb_size + 5*2 + 3);

if (numtoread > maxtoread) {
- DEBUG(0,("reply_lockread: requested read size (%u) is greater than maximum allowed (%u/%u). \
-Returning short read of maximum allowed for compatibility with Windows 2000.\n",
+ /*
+ * Just log the message but don't reduce the size.
+ *
+ * MS-CIFS states: SMB_COM_LOCK_AND_READ:
+ * CountOfBytesToRead (2 bytes): This field is a
+ * 16-bit unsigned integer indicating the number of
+ * bytes to be read from the file. The client MUST
+ * ensure that the amount of data requested will fit in
+ * the negotiated maximum buffer size.
+ *
+ * So for old clients this isn't our problem. As
+ * this command can never be chained (we check), this is safe.
+ */
+
+ DEBUG(2,("reply_lockread: requested read size (%u) is greater than maximum allowed (%u/%u).\n",
(unsigned int)numtoread, (unsigned int)maxtoread,
(unsigned int)sconn->smb1.sessions.max_send));
- numtoread = maxtoread;
}

reply_outbuf(req, 5, numtoread + 3);
@@ -3617,11 +3629,23 @@ void reply_read(struct smb_request *req)
maxtoread = sconn->smb1.sessions.max_send - (smb_size + 5*2 + 3);

if (numtoread > maxtoread) {
- DEBUG(0,("reply_read: requested read size (%u) is greater than maximum allowed (%u/%u). \
-Returning short read of maximum allowed for compatibility with Windows 2000.\n",
+ /*
+ * Just log the message but don't reduce the size.
+ *
+ * MS-CIFS states: SMB_COM_READ:
+ * CountOfBytesToRead (2 bytes): This field is a
+ * 16-bit unsigned integer indicating the number of
+ * bytes to be read from the file. The client MUST
+ * ensure that the amount of data requested will fit in
+ * the negotiated maximum buffer size.
+ *
+ * So for old clients this isn't our problem. As
+ * this command can never be chained (we check), this is safe.
+ */
+
+ DEBUG(2,("reply_read: requested read size (%u) is greater than maximum allowed (%u/%u).\n",
(unsigned int)numtoread, (unsigned int)maxtoread,
(unsigned int)sconn->smb1.sessions.max_send));
- numtoread = maxtoread;
}

reply_outbuf(req, 5, numtoread+3);

Dominic Raferd

2014-10-14 16:21:00 UTC

Permalink

Post by Jeremy Allison

Can you log a bug in buzilla and upload a wireshark
packet capture trace (including negprot onwards) to
the bug report please.
In the meantime, and after reading the MS-CIFS doc
I'm wondering if the server is over protecting
the client from its own folly here.
CountOfBytesToRead (2 bytes): This field is a 16-bit unsigned integer indicating the number of
bytes to be read from the file. The client MUST ensure that the amount of data requested will fit in
the negotiated maximum buffer size.
So it is the client, not server responsibility
to send a correct size here.
Given that, you could try the following (untested)
patch...
Jeremy.

Thanks Jeremy for this suggestion.

On closer investigation at my end it appears that the slowdown that I
have observed may have different causes, possibly hardware related
(cabling).

The debug messages are still appearing in the logs but at least
sometimes the connection is running at a healthy speed with Samba 4.1.12.

I will post here and/or log a bug if/when I have further information
that indicates it really is a problem with samba. Sorry for the
(possible) false alarm.

Dominic