[Samba] Extremely slow Samba3 performance with ArcView/WinXP

Andreas Haumer andreas at xss.co.at
Mon Dec 12 15:46:20 GMT 2005


-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hi!

I have a user who is running a Samba server to store data
files for his ArcView 3.3 application. Client operating
system is Windows XP professional.

With Samba2 (2.2.8a) this was working quite fine, it usually
took less than a few seconds to load and render one of the
GIS presentations with ArcView.

We then did an upgrade to Samba3 (3.0.20b) and suddenly
the same operation now takes more than 20 seconds or even
minutes in some cases. You can even see the picture forming
slowly on the screen. Other applications do not suffer from
performance problems (The new Samba3 server is a really fast
Dual Opteron server with 4GB of RAM and a fast external U320
RAID running under Linux-2.4.31)

I took a IP traffic dump with tcpdump and also samba logs
with loglevel 10 and found that there are a _lot_ of small
packets going between the WinXP client and the Samba3 server.

Example:

No.     Time        Source                Destination           Protocol Info
[...]
  75260 81.686777   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x272f, 512 bytes at offset 720896
  75261 81.687706   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x272f, 512 bytes
  75262 81.687873   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x2738, 512 bytes at offset 116736
  75264 81.688963   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x272f, 512 bytes at offset 708608
  75265 81.689893   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x272f, 512 bytes
  75266 81.690100   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x2738, 512 bytes at offset 119296
  75267 81.691250   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x2738, 512 bytes
  75268 81.691412   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x272f, 512 bytes at offset 721408
  75269 81.692343   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x272f, 512 bytes
  75270 81.692509   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x272f, 512 bytes at offset 720896
  75271 81.693436   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x272f, 512 bytes
  75272 81.693587   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x272f, 512 bytes at offset 721408
  75273 81.694495   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x272f, 512 bytes
  75274 81.694687   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x2738, 512 bytes at offset 116736
  75275 81.695598   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x2738, 512 bytes
  75276 81.695752   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x2738, 512 bytes at offset 117248
  75277 81.696663   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x2738, 512 bytes
  75278 81.696822   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x272f, 512 bytes at offset 708608
  75279 81.697732   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x272f, 512 bytes
  75280 81.697941   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x2738, 512 bytes at offset 119296
  75281 81.698858   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x2738, 512 bytes
  75282 81.699024   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x272f, 512 bytes at offset 721408
  75283 81.699949   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x272f, 512 bytes
  75284 81.700116   aaa.bb.ccc.110        aaa.bb.ccc.1          SMB      Read AndX Request, FID: 0x2738, 512 bytes at offset 117248
  75285 81.701031   aaa.bb.ccc.1          aaa.bb.ccc.110        SMB      Read AndX Response, FID: 0x2738, 512 bytes
[...]

(aaa.bb.ccc.1 is the Samba3 server, aaa.bb.ccc.110 is the WinXP client)

In one test I had more than 280000 such lines, the whole
data transfer took about 3 minutes(!).

In the Samba3 logfile I see lots of the following lines:
[...]
[2005/12/12 14:37:16, 3] smbd/process.c:switch_message(900)
  switch message SMBreadX (pid 16879) conn 0x84431d0
[2005/12/12 14:37:16, 4] smbd/uid.c:change_to_user(217)
  change_to_user: Skipping user change - already user
[2005/12/12 14:37:16, 10] smbd/fileio.c:read_file(105)
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 831488, size = 512, returned 512
[2005/12/12 14:37:16, 3] smbd/reply.c:send_file_readX(2585)
  send_file_readX fnum=10031 max=512 nread=512
[2005/12/12 14:37:16, 5] lib/util.c:show_msg(454)
[2005/12/12 14:37:16, 5] lib/util.c:show_msg(464)
  size=571
  smb_com=0x2e
  smb_rcls=0
  smb_reh=0
  smb_err=0
  smb_flg=136
  smb_flg2=51201
  smb_tid=6
  smb_pid=65279
  smb_uid=109
  smb_mid=22528
  smt_wct=12
  smb_vwv[ 0]=  255 (0xFF)
  smb_vwv[ 1]=    0 (0x0)
  smb_vwv[ 2]=65535 (0xFFFF)
  smb_vwv[ 3]=    0 (0x0)
  smb_vwv[ 4]=    0 (0x0)
  smb_vwv[ 5]=  512 (0x200)
  smb_vwv[ 6]=   59 (0x3B)
  smb_vwv[ 7]=    0 (0x0)
  smb_vwv[ 8]=    0 (0x0)
  smb_vwv[ 9]=    0 (0x0)
  smb_vwv[10]=    0 (0x0)
  smb_vwv[11]=    0 (0x0)
  smb_bcc=512
[...]

Doing a grep for "read_file" I can see the following:
[...]
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 818688, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 137216, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 831488, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 830976, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 135168, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 818688, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 137216, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 831488, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 135168, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 818688, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 137216, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 831488, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 135168, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 818688, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 137216, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 831488, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 135168, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 819200, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 137216, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 831488, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 135168, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 819200, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/pal.adf): pos = 657408, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 137216, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 831488, size = 512, returned 512
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 832000, size = 512, returned 512
[...]


I did the same with the Samba 2.2.8a server and here the picture
is quite different:
[...]
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 167936, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 172032, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arx.adf): pos = 28672, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 176128, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 180224, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 184320, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 188416, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 192512, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/pal.adf): pos = 196608, size = 32768, returned 32768
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 196608, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 200704, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 229376, size = 32768, returned 32768
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 204800, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 208896, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/pax.adf): pos = 16384, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 212992, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 217088, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 221184, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 225280, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/pal.adf): pos = 229376, size = 32768, returned 32768
  read_file (daten/covers/dhm_offset/o1000c/pax.adf): pos = 20480, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 262144, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 266240, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 270336, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 274432, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 278528, size = 4096, returned 4096
  read_file (daten/covers/dhm_offset/o1000c/pal.adf): pos = 262144, size = 32768, returned 32768
  read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 282624, size = 4096, returned 4096
[...]

Not even the blocksizes are much bigger, with Samba2 it also
seems to read sequentially where with Samba3 it looks like it
does randomly read small blocks of 512 bytes. Needless to say
that with Samba2 the test only takes a few seconds where with
Samba3 it takes several minutes to complete!

Where does this difference come from?
It's exactly the same client, connecting either to the Samba3
or the Samba2 server and performing the same operation!


Here's the full list of all global samba parameters on the
Samba3 machine, just in case I did miss to set some important
configuration parameter correctly (IP addresses and domain
names are changed to protect the innocent ;-)

[global]
        dos charset = 850
        unix charset = ISO8859-1
        display charset = LOCALE
        workgroup = WG_TECH
        realm =
        netbios name = PDC
        netbios aliases =
        netbios scope =
        server string = WG_TECH Fileserver
        interfaces =
        bind interfaces only = No
        security = USER
        auth methods =
        encrypt passwords = Yes
        update encrypted = No
        client schannel = Auto
        server schannel = Auto
        allow trusted domains = Yes
        hosts equiv =
        map to guest = Never
        null passwords = No
        obey pam restrictions = No
        password server = *
        smb passwd file = /etc/samba/smbpasswd
        private dir = /etc/samba
        passdb backend = ldapsam:ldap://ldap.mydomain.de/
        algorithmic rid base = 1000
        root directory =
        guest account = nobody
        enable privileges = No
        pam password change = No
        passwd program =
        passwd chat = *new*password* %n\n *new*password* %n\n *changed*
        passwd chat debug = No
        passwd chat timeout = 2
        check password script =
        username map = /etc/samba/smbusers
        password level = 0
        username level = 0
        unix password sync = No
        restrict anonymous = 0
        lanman auth = Yes
        ntlm auth = Yes
        client NTLMv2 auth = No
        client lanman auth = Yes
        client plaintext auth = Yes
        preload modules =
        use kerberos keytab = No
        log level = 2
        syslog = 0
        syslog only = No
        log file = /var/log/samba/smbd.log.%m
        max log size = 10240
        debug timestamp = Yes
        debug hires timestamp = No
        debug pid = No
        debug uid = No
        smb ports = 445 139
        large readwrite = Yes
        max protocol = NT1
        min protocol = CORE
        read bmpx = No
        read raw = Yes
        write raw = Yes
        disable netbios = No
        acl compatibility =
        defer sharing violations = Yes
        nt pipe support = Yes
        nt status support = Yes
        announce version = 4.9
        announce as = NT
        max mux = 50
        max xmit = 16644
        name resolve order = lmhosts wins host bcast
        max ttl = 259200
        max wins ttl = 518400
        min wins ttl = 21600
        time server = Yes
        unix extensions = Yes
        use spnego = Yes
        client signing = auto
        server signing = No
        client use spnego = Yes
        enable asu support = Yes
        enable svcctl = Spooler, NETLOGON
        change notify timeout = 60
        deadtime = 0
        getwd cache = Yes
        keepalive = 300
        kernel change notify = Yes
        lpq cache time = 30
        max smbd processes = 0
        paranoid server security = Yes
        max disk size = 0
        max open files = 10000
        socket options = TCP_NODELAY SO_RCVBUF=8192 SO_SNDBUF=8192
        use mmap = Yes
        hostname lookups = No
        name cache timeout = 660
        load printers = Yes
        printcap cache time = 750
        printcap name = CUPS
        cups server =
        disable spoolss = No
        enumports command =
        addprinter command =
        deleteprinter command =
        show add printer wizard = Yes
        os2 driver map =
        mangling method = hash2
        mangle prefix = 1
        max stat cache size = 0
        stat cache = Yes
        machine password timeout = 604800
        add user script = /usr/sbin/smbldap-useradd -a -m '%u'
        delete user script = /usr/sbin/smbldap-userdel '%u'
        add group script = /usr/sbin/smbldap-groupadd -p  '%g'
        delete group script = /usr/sbin/smbldap-groupdel '%g'
        add user to group script = /usr/sbin/smbldap-groupmod -m '%u' '%g'
        delete user from group script = /usr/sbin/smbldap-groupmod -x '%u' '%g'
        set primary group script = /usr/sbin/smbldap-usermod -g '%g' '%u'
        add machine script = /usr/sbin/smbldap-useradd -w '%u'
        shutdown script =
        abort shutdown script =
        username map script =
        logon script = %m.bat
        logon path = \\%L\Profiles\%U
        logon drive = H:
        logon home = \\%L\%U
        domain logons = Yes
        os level = 65
        lm announce = Auto
        lm interval = 60
        preferred master = Yes
        local master = Yes
        domain master = Yes
        browse list = Yes
        enhanced browsing = Yes
        dns proxy = No
        wins proxy = No
        wins server = aaa.bb.ccc.222
        wins support = No
        wins hook =
        wins partners =
        kernel oplocks = Yes
        lock spin count = 3
        lock spin time = 10
        oplock break wait time = 0
        ldap admin dn = uid=samba,ou=DSA,ou=accounts,dc=mydomain,dc=de
        ldap delete dn = No
        ldap group suffix = ou=groups
        ldap idmap suffix = ou=idmap
        ldap machine suffix = ou=machines,ou=accounts
        ldap passwd sync = Yes
        ldap replication sleep = 1000
        ldap suffix = dc=mydomain,dc=de
        ldap ssl = start tls
        ldap timeout = 15
        ldap page size = 1024
        ldap user suffix = ou=people,ou=accounts
        add share command =
        change share command =
        delete share command =
        eventlog open command =
        eventlog read command =
        eventlog clear command =
        eventlog num records command =
        eventlog oldest record command =
        eventlog list =
        config file =
        preload =
        lock directory = /var/lib/samba
        pid directory = /var/run/samba
        utmp directory =
        wtmp directory =
        utmp = No
        default service =
        message command =
        dfree command =
        get quota command =
        set quota command =
        remote announce =
        remote browse sync =
        socket address = 0.0.0.0
        homedir map = auto.home
        afs username map =
        afs token lifetime = 604800
        log nt token command =
        time offset = 0
        NIS homedir = No
        panic action =
        host msdfs = No
        enable rid algorithm = Yes
        idmap backend =
        idmap uid =
        idmap gid =
        template homedir = /home/%D/%U
        template shell = /bin/false
        winbind separator = \
        winbind cache time = 300
        winbind enum users = Yes
        winbind enum groups = Yes
        winbind use default domain = No
        winbind trusted domains only = No
        winbind nested groups = No
        winbind max idle children = 3
        winbind nss info = template
        ldapsam:trusted = yes
        comment =
        path =
        username =
        invalid users =
        valid users =
        admin users =
        read list =
        write list =
        printer admin =
        force user =
        force group =
        read only = Yes
        acl check permissions = Yes
        acl group control = No
        acl map full control = Yes
        create mask = 0744
        force create mode = 00
        security mask = 0777
        force security mode = 00
        directory mask = 0755
        force directory mode = 00
        directory security mask = 0777
        force directory security mode = 00
        force unknown acl user = No
        inherit permissions = No
        inherit acls = No
        inherit owner = No
        guest only = No
        guest ok = No
        only user = No
        hosts allow =
        hosts deny =
        allocation roundup size = 1048576
        aio read size = 0
        aio write size = 0
        aio write behind =
        ea support = No
        nt acl support = Yes
        profile acls = No
        map acl inherit = No
        afs share = No
        block size = 1024
        max connections = 0
        min print space = 0
        strict allocate = No
        strict sync = No
        sync always = No
        use sendfile = No
        write cache size = 0
        max reported print jobs = 0
        max print jobs = 1000
        printable = No
        printing = cups
        cups options =
        print command =
        lpq command = %p
        lprm command =
        lppause command =
        lpresume command =
        queuepause command =
        queueresume command =
        printer name =
        use client driver = No
        default devmode = No
        force printername = No
        default case = lower
        case sensitive = Auto
        preserve case = Yes
        short preserve case = Yes
        mangling char = ~
        hide dot files = Yes
        hide special files = No
        hide unreadable = No
        hide unwriteable files = No
        delete veto files = No
        veto files =
        hide files =
        veto oplock files =
        map system = No
        map hidden = No
        map archive = Yes
        mangled names = Yes
        mangled map =
        store dos attributes = No
        browseable = Yes
        blocking locks = Yes
        csc policy = manual
        fake oplocks = No
        locking = Yes
        oplocks = Yes
        level2 oplocks = Yes
        oplock contention limit = 2
        posix locking = Yes
        strict locking = No
        share modes = Yes
        copy =
        include = /etc/samba/smb.pdc.shares
        preexec =
        preexec close = No
        postexec =
        root preexec =
        root preexec close = No
        root postexec =
        available = Yes
        volume =
        fstype = NTFS
        set directory = No
        wide links = Yes
        follow symlinks = Yes
        dont descend =
        magic script =
        magic output =
        delete readonly = No
        dos filemode = No
        dos filetimes = Yes
        dos filetime resolution = No
        fake directory create times = No
        vfs objects =
        msdfs root = No
        msdfs proxy =
[...]


The Samba3 server is acting as a LDAP based PDC and usually is
performing quite well (apart from the problem described above).
This is a network with about 130 Windos Client PC's and there
are usually about 20-30 Users connected to the Samba server and
working at the same time. The server load is almost zero most
of the time.

Do I miss something here?
Does anyone have any idea or suggestion to solve this mystery?

Thanks!

- - andreas

- --
Andreas Haumer                     | mailto:andreas at xss.co.at
*x Software + Systeme              | http://www.xss.co.at/
Karmarschgasse 51/2/20             | Tel: +43-1-6060114-0
A-1100 Vienna, Austria             | Fax: +43-1-6060114-71
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.2 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://enigmail.mozdev.org

iD8DBQFDnZtGxJmyeGcXPhERAt3jAJ4p9hz+J5vhJ8RsflPlpOb2ujc6KwCeKeEs
X0GW0g4UDIbvjhMVZJc/Ynk=
=IL5j
-----END PGP SIGNATURE-----


More information about the samba mailing list