Still no solution after 5 months(!) - Transfer speed problems (oplocks?) with Samba 2.0.7 and Win2K Pro

infernix infernix at infernix.nl
Tue Dec 19 09:09:14 GMT 2000


Dear readers of the mailing list, co-troubleshooters,


I am posting this for the third time now. In the past few months I have had
quite a few reactions, and I am positive many others share our problem but
cannot find a solution either.

Therefore I hope that after 5 months of staring in the dark, someone could
finally shed some light on this issue. Here is my second posting, with a few
adjustments here and there. Currently, I am running a brand new Debian 2.2
distro on a P2-266 and I still experience the same slow transfer speeds.
Others have found transferring from the Win2K client to the Samba server is
fast but from Samba to Win2K is dead slow. A few quotes:

"i have the same problem ... w2k --> samba works fine (nearly 50M in 30sec)
but samba --> w2k is a pitty :(( (50M in more than 26 MINUTES !!)"
"mocht je een oplossing vinden voor de trage browsing/transfer door je samba
shares enzo... Wil je me dan ook mailen.. ik ben er ook al 2 maanden naar
opzoek!" (Translation: having same problems, been looking for 2 months).
"The problem you described is becoming a chronic problem for me as well ...
major oplock problems. I couldn't find any responses to it."

I know this posting is a pain in the ass to read through, but please, if
anyone knows more than we do, help us out. Thanks.


infernix at infernix.nl


My second posting begins here, dated September 1st 2000. The
logs are still retrievable. Please read the Anders Öhrt posting too (it's
after this post), it contains some more debugging data.


Hi,

This was posted in august and july, but i have had no reaction since. I
didn't really mind then, because i just blamed my old P120 server. Hoewever,
things changed: I installed a new server at work and at home, and with all
those different configurations, the problem still persists!

Let me sum up what the problem is. I have two machines here.

The SERVER, a P133 (or 150) with 64MB ram. This machine has a 3com 3c905c
NIC.

The CLIENT, a dual 366 (BP6) with 256MB ram. I have overclocked them to 533
(97mhz bus speed), but this is not the issue here, since that would affect
windows 98 as well, which it doesnt. Besides, the same problem occurs when
not overclocked and on different machines. It has a 3com 3c905C NIC.

On my CLIENT, i can dual-boot to Windows 2000 or Windows 98. I did a speed
test by booting to Windows 2000, running the test, rebooting to Windows 98
and doing the exact same test again. I copied a 107MB mp3 file from my
SERVER to my CLIENT, which gave me the following results:

Windows 2000:
    Samba:    almost 4 minutes (238 seconds)
    FTP:        27 seconds.
    238 divided by 27 = 8.5 times slower.

Windows 98:
    Samba:    26 seconds.
    FTP:        20 seconds.
    26 divided by 20 = 1.3.

Conclusion: Samba is 1.3 times slower than FTP in Windows 98, and 8.5 times
slower in Windows 2000.

Originally, I was hoping that this is a Windows 2000 client issue.
Unfortunately, I have not found a way to tweak Windows 2000 to speed up the
SMB transfers at all. I have tried to change settings as described in MS
Knowledgebase document
Q169789, but since this didnt affect FTP, it didnt affect Samba either.


At that time, I had contacted David Collier-Brown. He compared the logs
between the transfer of the file in Windows 98 and Windows 2000. This is
what came out of that:

Good news and bad news:
  I've got comparative logs for win2k vs NT 4.0, and win2k is
doing things **very** differently and as much as 8.5 times slower.
  The bad news is that the cause of problem hasn't jumped out at me!

  Windows 2000 takes 4 minutes 29 seconds to read a file that NT 4.0
reads in 1 minute 10 seconds.

  We've narrowed it down to Samba (ftp is fine) and eliminated
obvious hardware/networking problems, so I'm now sitting here
in filemerge (the Sun visual diff) with snippits of two smbd logs...
which I'm about to inflict on you!

>From Win2k
----------
[2000/08/01 18:23:11, 3] smbd/reply.c:reply_sesssetup_and_X(805)
Domain=[INFERNIX]  NativeOS=[Windows 2000 2195] NativeLanMan=[Windows  2000
5.0]

>From NT 4.0
-----------
[2000/08/01 18:18:47, 3] smbd/reply.c: reply_sesssetup_and_X(805)
Domain=[WORKGROUP] NativeOS=[Windows 4.0] NativeLanMan=[Windows 4.0]

My Notes
--------
The domains are different,
which may interfere.  Infernix,
they are really the same machine,
aren't they?

[ Response by infernix: Yes, I set my domain to Workgroup in both Windows 98
and Windows 2000.
However, since Windows 2000 cannot login to the Samba domain (This is not
supported in the regular branch of Samba, only in TNG, as you probably know)
the Windows 2000 machine logs in to its own local domain which it calls
INFERNIX, the machinename. ]

[2000/08/01 18:23:11, 2] lib/access.c:check_access(258) Allowed connection
from infernix.ggmc.nl (192.168.0.17) [2000/08/01 18:18:47, 2] lib/access.c:
check_access(258)  Allowed connection from
infernix2.ggmc.nl (192.168.0.21)

infernix is the win2k
infernix2 is nt 4.0

[ Response by infernix: No, infernix is Windows 98 and infernix2 is Windows
2000. In windows 2000
i use ip address .21 and in Windows 98 i use .17. Mind you, I am still
talking about the same machine here! Both Windows 98 and Windows 2000 run on
the same machine because I dual boot them. ]

[2000/08/01 18:23:39, 3] smbd/process.c:switch_message(448)  switch message
SMBntcreateX (pid 1511)
[2000/08/01 18:23:39, 3] lib/util.c:unix_clean_name(522) unix_clean_name
[/Trance/ferry_corsten-live_at_trance_energy-30-04-2000-2db/ferry_corsten-li
ve_at_trance_energy__30-04-2000_2db.mp3]
[2000/08/01 18:19:08, 3] smbd/process.c:switch_message(448) switch message
SMBreadbraw (pid 1435)

Win2k is about to open (create?) the
file, at 28 seconds into the log, NT 4 just
opened it, 21 seconds into the log.


At this point, win2k goes into a loop doing oplocks 4 times:
--
[2000/08/01 18:23:39, 3] smbd/oplock.c:initial_break_processing(702)
initial_break_processing: called for dev = 900, inode = 338018 tv_sec =
3986f98b, tv_usec = 639c5.
  Current oplocks_open (exclusive = 1, levelII = 0)
[2000/08/01 18:23:39, 3] lib/doscalls.c:dos_ChDir(342)
  dos_ChDir to /var/log
[2000/08/01 18:23:39, 3] smbd/oplock.c:initial_break_processing(702)
  initial_break_processing: called for dev = 900, inode = 338018
tv_sec = 3986f98b, tv_usec = 639c5.
  Current oplocks_open (exclusive = 1, levelII = 0)
[2000/08/01 18:23:39, 3] smbd/process.c:process_smb(618)
  Transaction 244 of length 45
[2000/08/01 18:23:39, 3] smbd/process.c:switch_message(448)
  switch message SMBclose (pid 1511)
---

After the 4 tries, it starts reading at 18:23:41, one second later
--
[2000/08/01 18:23:41, 3] smbd/process.c:switch_message(448)
  switch message SMBreadX (pid 1511)
[2000/08/01 18:23:41, 3] smbd/reply.c:reply_read_and_X(2322)
  readX fnum=4401 min=61440 max=61440 nread=61440
[2000/08/01 18:23:41, 3] smbd/process.c:process_smb(618)
  Transaction 255 of length 63
[2000/08/01 18:23:41, 3] smbd/process.c:switch_message(448)
  switch message SMBreadX (pid 1511)
---

It transfers in a pattern I don't happen to grok:
---
 [2000/08/01 18:23:41, 3] smbd/process.c:process_smb(618)
  Transaction 257 of length 63
[2000/08/01 18:23:41, 3] smbd/process.c:switch_message(448)
  switch message SMBreadX (pid 1511)
[2000/08/01 18:23:41, 3] smbd/reply.c:reply_read_and_X(2322)
  readX fnum=4401 min=61440 max=61440 nread=61440
[2000/08/01 18:23:41, 3] smbd/process.c:process_smb(618)
  Transaction 258 of length 63
[2000/08/01 18:23:41, 3] smbd/process.c:switch_message(448)
  switch message SMBreadX (pid 1511)
[2000/08/01 18:23:41, 3] smbd/reply.c:reply_read_and_X(2322)
  readX fnum=4401 min=16384 max=16384 nread=16384
[2000/08/01 18:23:42, 3] smbd/process.c:process_smb(618)
  Transaction 259 of length 63
[2000/08/01 18:23:42, 3] smbd/process.c:switch_message(448)
  switch message SMBreadX (pid 1511)
[2000/08/01 18:23:42, 3] smbd/reply.c:reply_read_and_X(2322)
  readX fnum=4401 min=45056 max=45056 nread=45056
[2000/08/01 18:23:42, 3] smbd/process.c:process_smb(618)
  Transaction 260 of length 63
[2000/08/01 18:23:42, 3] smbd/process.c:switch_message(448)
  switch message SMBreadX (pid 1511)
[2000/08/01 18:23:42, 3] smbd/reply.c:reply_read_and_X(2322)
  readX fnum=4401 min=61440 max=61440 nread=61440
--
Anyone know if this indicates a problem?
It **looks** like its restarting, but there isn't enough
info to tell me...


NT 4.0 is similar, but the start value keeps increasing,
which isn't a threatening (;-))
--
[2000/08/01 18:19:08, 3] smbd/reply.c:reply_readbraw(2112)
  readbraw fnum=4730 start=917504 max=65520 min=0 nread=65520
[2000/08/01 18:19:08, 3] smbd/process.c:process_smb(618)
  Transaction 154 of length 49
[2000/08/01 18:19:08, 3] smbd/process.c:switch_message(448)
  switch message SMBread (pid 1435)
[2000/08/01 18:19:08, 3] smbd/reply.c:reply_read(2258)
  read fnum=4730 num=16 nread=16
[2000/08/01 18:19:08, 3] smbd/process.c:process_smb(618)
  Transaction 155 of length 55
[2000/08/01 18:19:08, 3] smbd/process.c:switch_message(448)
  switch message SMBreadbraw (pid 1435)
[2000/08/01 18:19:08, 3] smbd/reply.c:reply_readbraw(2112)
  readbraw fnum=4730 start=983040 max=65520 min=0 nread=65520
---


Windows 2000 finishes up at 18:27:47, while NT does many
more pages of read-raws, but ends at 18:19:55
---
[2000/08/01 18:27:40, 2] smbd/server.c:exit_server(408)
  Closing connections
[2000/08/01 18:27:40, 1] smbd/service.c:close_cnum(583)
  infernix (192.168.0.17) closed connection to service mp3

[2000/08/01 , 2] smbd/server.c:exit_server(408)
Closing connections
[2000/08/01 18:19:55, 1] smbd/service.c:close_cnum(583)
infernix (192.168.0.21) closed connection to service mp3

win2k has taken 4 minutes 1 second,
NT 4.0 only 47 seconds to get here.

---
Conclusion: win2k is slow, but I don't yet know why. Anyone here
able to comment?

David Collier-Brown.
----------------------------------------------------------------------------
-

All this has not helped much yet. I really think that there is a serious
problem with either how Samba talks to Windows 2000 or how Windows 2000
talks to Samba (which might still be solvable on just the client or just the
server).

I didn't really mind that there was no solid solution yet, but now that I am
experiencing the same slow transfers at work and on my freshly installed
server, I am beginning to wonder what on earth is going on here. Regarding
my smb.conf, here are the options which I think might be relevant:

[global]
socket options = TCP_NODELAY
# using any of IPTOS_NODELAY SO_SNDBUF=8192 SO_RCVBUF=8192 didnt have any
effect.
[mp3]
fstype = "FAT"
oplocks = true
level2 oplocks = true


I have plenty options to test further, by either using tcpdump or more log
dumps. The log dumps are available at
http://www.infernix.nl/samba/sambalogs.infernix.tgz if you need more info.

Please, try to look further into this. I have no idea how or why this is
happening, but for me it has grown out to be a real problem, since we are
planning a migration to Windows 2000 clients at work, and i _really_ can't
tell my boss that this is all the speed we can expect ;(

Thank you in advance.

Yours sincerely,

infernix


------------------ Anders Öhrt's post:

I'm having some trouble with my net which seems to have started when I
changed by workstation from NT4 to W2k. I have two servers running
debian with samba 2.0.7. The servers are a P100 (locutus) and an
Athlon 500 (motherbrain), and my workstation (doas-place) is a P2-350.
There is almost no other trafic on the net, which is a 100 mb/s
switched net.


Sending from locutus to motherbrain I get ~3 mb/s, the other way I get
~600 kb/s. Sending from motherbrain to doas-place I get ~3 mb/s, and
about the same the other way. Sending from locutus to my workstation I
get about 60 kb/s!

The low speed from motherbrain to locutus is strange, because there
are fast disks in it, and the CPU is about 85% idle which
downloading...

The low speed from locutus to doas-place is of course the problem...
I've tcpdumped a bit which might help... Seems like all datapackets
are 44 byte, but should be ~1k5... Is that the (only) problem and how
do I solve it?

dump;
----
17:35:21.501168 locutus.metroid.net.netbios-ssn >
doas-place.metroid.net.1260: P 401241:402701(1460) ack 3177 win 26532
>>> NBT Packet
flags=0x1
NBT Session Packet
Flags=0x140
Length=1116 (0x45c)
Session packet:(raw data?)

 (DF) [tos 0x10]

17:35:21.501305 locutus.metroid.net.netbios-ssn >
doas-place.metroid.net.1260: P 402701:404161(1460) ack 3177 win 26532
>>> NBT Packet
flags=0xfd
NBT - Unknown packet type
Type=0xFDB66D9F
Data: (44 bytes)
[000] F7 D8 2C 2E 91 BF 56 84  FE 94 FF D1 AD 9F 9F E5  ..,...V.
........
[010] FF FE FF FA 79 7F 36 A4  EF 3D CE 3D E8 4A B2 32  ....y.6.
.=.=.J.2
[020] 56 C5 F3 AB 4F 1B 6E 0D  33 BC 11 91              V...O.n. 3...

 (DF) [tos 0x10]


// Anders Öhrt

-----------------------------------------------




Regards,

infernix at infernix.nl







More information about the samba-technical mailing list