[Samba] Please help: Re: Samba 2.0.6-3 (productive env.) slow down
dramticaly
Heiko Boeringer
heiko.boeringer at epost.de
Thu Sep 16 19:21:21 GMT 2004
Hello together,
please help!!!
I made some more traces and test today.
The logon process from an Windows XP machines needs aprox. 7 Minutes.
Then the machine is able to browse through the domain, can open shares e.g.
Wenn I copy a file from a share there happends nothing for round about 1
minute - then windows means that the File could not be copied because
the sourcefile or directory could not be read.
In the meantime Strace shows what happens within the smb-process:
After the Strace you can find a tcpdump - but for both, I´m not
technical enough to read in detail.
I would be very appreciated to get help from this community-
Regards,
Heiko
--------
lx2-rvmo-02:~# cat /tmp/strace.log
2419 select(25, [20 23 24], NULL, NULL, {48, 830000}) = 1 (in [23],
left {35, 840000})
2419 read(23, 0x40510008, 4) = -1 ECONNRESET (Connection
reset by peer)
2419 time(NULL) = 1095364795
2419 time([1095364795]) = 1095364795
2419 getpid() = 2419
2419 rt_sigaction(SIGPIPE, {0x40262be0, [], 0x4000000}, {SIG_DFL}, 8) = 0
2419 send(4, "<27>Sep 16 21:59:55 smbd[2419]: "..., 95, 0) = 95
2419 rt_sigaction(SIGPIPE, {SIG_DFL}, NULL, 8) = 0
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 0] lib/uti"..., 63) = 63
2419 time([1095364795]) = 1095364795
2419 getpid() = 2419
2419 rt_sigaction(SIGPIPE, {0x40262be0, [], 0x4000000}, {SIG_DFL}, 8) = 0
2419 send(4, "<27>Sep 16 21:59:55 smbd[2419]: "..., 105, 0) = 105
2419 rt_sigaction(SIGPIPE, {SIG_DFL}, NULL, 8) = 0
2419 geteuid32() = 0
2419 write(27, " read_socket_data: recv failure"..., 73) = 73
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/pr"..., 65) = 65
2419 geteuid32() = 0
2419 write(27, " timeout_processing: receive_sm"..., 75) = 75
2419 munmap(0x40505000, 696) = 0
2419 close(14) = 0
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/se"..., 57) = 57
2419 geteuid32() = 0
2419 write(27, " setting sec ctx (0, 0) - sec_c"..., 49) = 49
2419 geteuid32() = 0
2419 getegid32() = 5021
2419 setresgid32(0xffffffff, 0, 0xffffffff) = 0
2419 getegid32() = 0
2419 getegid32() = 0
2419 setgroups32(0, 0) = 0
2419 setresgid32(0xffffffff, 0, 0xffffffff) = 0
2419 getegid32() = 0
2419 setresuid32(0, 0, 0xffffffff) = 0
2419 geteuid32() = 0
2419 time(NULL) = 1095364795
2419 time([1095364795]) = 1095364795
2419 getpid() = 2419
2419 rt_sigaction(SIGPIPE, {0x40262be0, [], 0x4000000}, {SIG_DFL}, 8) = 0
2419 send(4, "<29>Sep 16 21:59:55 smbd[2419]: "..., 88, 0) = 88
2419 rt_sigaction(SIGPIPE, {SIG_DFL}, NULL, 8) = 0
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 2] smbd/se"..., 56) = 56
2419 time([1095364795]) = 1095364795
2419 getpid() = 2419
2419 rt_sigaction(SIGPIPE, {0x40262be0, [], 0x4000000}, {SIG_DFL}, 8) = 0
2419 send(4, "<29>Sep 16 21:59:55 smbd[2419]: "..., 54, 0) = 54
2419 rt_sigaction(SIGPIPE, {SIG_DFL}, NULL, 8) = 0
2419 geteuid32() = 0
2419 write(27, " Closing connections\n", 22) = 22
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/se"..., 57) = 57
2419 geteuid32() = 0
2419 write(27, " setting sec ctx (0, 0) - sec_c"..., 49) = 49
2419 geteuid32() = 0
2419 getegid32() = 0
2419 setgroups32(0, 0) = 0
2419 setresgid32(0xffffffff, 0, 0xffffffff) = 0
2419 getegid32() = 0
2419 setresuid32(0, 0, 0xffffffff) = 0
2419 geteuid32() = 0
2419 time(NULL) = 1095364795
2419 time([1095364795]) = 1095364795
2419 getpid() = 2419
2419 rt_sigaction(SIGPIPE, {0x40262be0, [], 0x4000000}, {SIG_DFL}, 8) = 0
2419 send(4, "<28>Sep 16 21:59:55 smbd[2419]: "..., 88, 0) = 88
2419 rt_sigaction(SIGPIPE, {SIG_DFL}, NULL, 8) = 0
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 1] smbd/se"..., 56) = 56
2419 time([1095364795]) = 1095364795
2419 getpid() = 2419
2419 rt_sigaction(SIGPIPE, {0x40262be0, [], 0x4000000}, {SIG_DFL}, 8) = 0
2419 send(4, "<28>Sep 16 21:59:55 smbd[2419]: "..., 96, 0) = 96
2419 rt_sigaction(SIGPIPE, {SIG_DFL}, NULL, 8) = 0
2419 geteuid32() = 0
2419 write(27, " rvmo1018 (192.168.1.54) closed"..., 64) = 64
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/co"..., 64) = 64
2419 geteuid32() = 0
2419 write(27, " Yielding connection to NETLOGO"..., 34) = 34
2419 fcntl64(10, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=352,
len=1}, 0xbffff170) = 0
2419 fcntl64(10, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=1944,
len=1}, 0xbffff160) = 0
2419 fcntl64(10, F_SETLK64, {type=F_UNLCK, whence=SEEK_SET, start=1944,
len=1}, 0xbffff160) = 0
2419 fcntl64(10, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=164,
len=1}, 0xbffff0d0) = 0
2419 fcntl64(10, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=164,
len=1}, 0xbffff0d0) = 0
2419 fcntl64(10, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=352,
len=1}, 0xbffff1b0) = 0
2419 chdir("/") = 0
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/se"..., 57) = 57
2419 geteuid32() = 0
2419 write(27, " setting sec ctx (0, 0) - sec_c"..., 49) = 49
2419 geteuid32() = 0
2419 getegid32() = 0
2419 setgroups32(0, 0) = 0
2419 setresgid32(0xffffffff, 0, 0xffffffff) = 0
2419 getegid32() = 0
2419 setresuid32(0, 0, 0xffffffff) = 0
2419 geteuid32() = 0
2419 fcntl64(9, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, start=332,
len=1}, 0xbffff480) = 0
2419 fcntl64(9, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=332,
len=1}, 0xbffff4c0) = 0
2419 fcntl64(9, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=332,
len=1}, 0xbffff480) = 0
2419 fcntl64(9, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=696,
len=1}, 0xbffff470) = 0
2419 fcntl64(9, F_SETLK64, {type=F_UNLCK, whence=SEEK_SET, start=696,
len=1}, 0xbffff470) = 0
2419 fcntl64(9, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=164,
len=1}, 0xbffff3e0) = 0
2419 fcntl64(9, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=164,
len=1}, 0xbffff3e0) = 0
2419 fcntl64(9, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=332,
len=1}, 0xbffff4c0) = 0
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/co"..., 64) = 64
2419 geteuid32() = 0
2419 write(27, " Yielding connection to \n", 26) = 26
2419 fcntl64(10, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=340,
len=1}, 0xbffff9d0) = 0
2419 fcntl64(10, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=340,
len=1}, 0xbffff9d0) = 0
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/co"..., 64) = 64
2419 geteuid32() = 0
2419 write(27, " yield_connection: tdb_delete f"..., 82) = 82
2419 time(NULL) = 1095364795
2419 select(25, [20 24], NULL, NULL, {0, 1000}) = 0 (Timeout)
2419 munmap(0x40501000, 696) = 0
2419 close(11) = 0
2419 munmap(0x40554000, 8192) = 0
2419 close(12) = 0
2419 time(NULL) = 1095364795
2419 geteuid32() = 0
2419 write(27, "[2004/09/16 21:59:55, 3] smbd/se"..., 56) = 56
2419 geteuid32() = 0
2419 write(27, " Server exit (normal exit)\n", 28) = 28
2419 semget(IPC_PRIVATE, 0, 0) = -1 ENOSYS (Function not
implemented)
2419 _exit(0) = ?
The tcpdump is attached to this mail.
------------------------
Heiko Boeringer wrote:
> Hello together,
>
> since today morning I have an massive performance issue with samba
> 2.0.6-3 (Debian - Testing-Tree) in my samba production environment.
>
> Samba responds very slowly within the logon process (2-3 Minutes for
> each line in the netlogon.cmd). Later during normal operations opening
> from files works very slowly and often breaks connection.
>
> There is no cpu or memory load on the system. Also the network traffic
> is low. The network connections between the server and the clients is
> fine. FTP Transfer works with high speed.
>
> The last thing I´ve done is to install the nagios-mysql package (debian,
> unstable tree). But I´m not sure if there are dependencies.
>
> I do all the things from DIAGNOSIS.TXT and many others - but I have no
> mor idea where !
>
> Does anybody has an idea what´s going wrong here. I have atteched a the
> log.smbd, log.nmdd and from an machine - showing the logon process .
> Hope that helps by analyzing the issue.
>
> Here some informations regarding the system.
>
> I would be very thankful for all help & support
>
> regards,
> Heiko
>
>
> Systemconfiguration
> ################################################################
> - Debian 3.0 (Woody)
> - Samba with an the samba3.0.6-3.deb from the testing tree (but happends
> with all other versions too)
> - Configured als PDC with SMBPASSWD Authentification (no windbind,
> kerberos, ldap..)
> - Client: Windows XP Germany, SP1
>
> TOP (means the machine hs nothing to do)
> #################################################################
> 99 processes: 98 sleeping, 1 running, 0 zombie, 0 stopped
> CPU states: 0.4% user, 0.4% system, 0.0% nice, 99.2% idle
> Mem: 516100K total, 510616K used, 5484K free, 69040K buffers
> Swap: 385552K total, 1652K used, 383900K free, 376280K cached
>
> PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
> 7181 netinsta 16 0 3620 3616 3268 S 0.3 0.7 0:00 smbd
> 235 root 10 0 592 592 512 S 0.1 0.1 1:37 syslogd
> 7035 root 12 0 1028 1028 804 R 0.1 0.1 0:00 top
> 1 root 8 0 496 492 448 S 0.0 0.0 0:00 init
>
>
> SMB.CONF
> ################################################################
> [global]
> unix charset = ISO8859-1
> display charset = ISO8859-1
> workgroup = RVMO.DE
> server string = %h
> obey pam restrictions = Yes
> # unix password sync = false
> # encrypt passwords = yes
> passwd program = /usr/bin/passwd %u
> passwd chat = *Enter\snew\sUNIX\spassword:* %n\n
> *Retype\snew\sUNIX\spassword:* %n\n .
> #For verbose debug: 10
> #For Standard logging: 3
> log level = 3
> syslog = 3
> # End logging section
> log file = /var/log/samba/log.%m
> max log size = 1000
> logon script = netlogon.cmd
> logon path =
> logon drive = L:
> logon home =
> domain logons = Yes
> # wins support = Yes
> os level = 40
> preferred master = Yes
> domain master = Yes
> dns proxy = No
> ldap ssl = no
> panic action = /usr/share/samba/panic-action %d
> idmap uid = 100-20000
> idmap gid = 100-20000
> admin users = @smb-o-admin-it
> hosts allow = 127.0.0.1, 192.168.1.0/255.255.0.0
> printing = cups
> printer admin = @smb-o-basisarbeitsplatz
> printcap name = /etc/printcap.cups
> # print command = lpr-cups -P %p -o raw %s -r
> load printers = Yes
> use client driver = No
>
> [print$]
> comment = Samba printer drivers
> path = /home/samba/print
> valid users = +smb-o-basisarbeitsplatz
> admin users = @smb-o-admin-it
> read list = @smb-o-basisarbeitsplatz
> write list = @smb-o-admin-it
> force user = nobody
> force group = nogroup
> # guest ok = Yes
> writeable = Yes
>
> [printers]
> comment = All Printers
> path = /var/spool/samba
> valid users = +smb-o-basisarbeitsplatz
> admin users = @smb-o-admin-it
> read list = @smb-o-basisarbeitsplatz
> write list = @smb-o-basisarbeitsplatz
> force user = nobody
> force group = nogroup
> printer admin = @smb-o-basisarbeitsplatz
> create mask = 0700
> printable = Yes
> browsable = Yes
> public = Yes
> guest ok = Yes
> writeable = Yes
>
> [homes]
> comment = Home Directories
> read only = No
> create mask = 0700
> directory mask = 0700
> browseable = No
> csc policy = disable
>
> [NETLOGON]
> comment = NETLOGON auf LX2-RVMO-02
> path = /home/netlogon
> admin users = @smb-o-admin-it
> write list = @smb-o-admin-it
> force user = root
> force group = smb-o-admin-it
> guest ok = Yes
> csc policy = disable
>
>
>
> ########################################################################
> here comes an syslog extract from an example filetransfer (copying
> from \\server\public to local desktop. Transfer ends with windows
> message "File could not be copied. From Sourcefile or from Sourcedisk
> could not be read"
>
> ############################################################
> [2004/09/15 22:01:57, 5] auth/auth_util.c:debug_nt_user_token(491)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: NT user token of user
> S-1-5-21-29628934-819234659-1421906636-501
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: contains 6 SIDs
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: SID[ 0]:
> S-1-5-21-29628934-819234659-1421906636-501
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: SID[ 1]:
> S-1-5-21-29628934-819234659-1421906636-514
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: SID[ 2]: S-1-1-0
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: SID[ 3]: S-1-5-2
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: SID[ 4]: S-1-5-32-546
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: SID[ 5]:
> S-1-5-21-29628934-819234659-1421906636-132069
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 5]
> auth/auth_util.c:debug_unix_user_token(505)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: UNIX token of user 65534
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: Primary group is 65534 and
> contains 1 supplementary groups
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: Group[ 0]: 65534
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 5]
> smbd/uid.c:change_to_user(280)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: change_to_user
> uid=(65534,65534) gid=(0,65534)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 4]
> smbd/vfs.c:vfs_ChDir(654)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: vfs_ChDir to /tmp
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 4]
> smbd/nttrans.c:nt_open_pipe(496)
>
> ### here starts the interesting thing... ###
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: nt_open_pipe: Opening pipe
> \browser.
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 3]
> smbd/error.c:error_packet(129)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: error packet at
> smbd/nttrans.c(508) cmd=162 (SMBntcreateX)
> NT_STATUS_OBJECT_NAME_NOT_FOUND
> #### connection is crashed... -> Message on the win-box "File could
> not be copied. From Sourcefile or from Sourcedisk could not be read"
>
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 5]
> lib/util.c:show_msg(443)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 5]
> lib/util.c:show_msg(453)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: size=35
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_com=0xa2
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_rcls=52
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_reh=0
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_err=49152
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_flg=136
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_flg2=51201
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_tid=2
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_pid=1680
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_uid=102
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_mid=19267
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smt_wct=0
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: smb_bcc=0
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 6]
> lib/util_sock.c:write_socket(449)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: write_socket(23,39)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: [2004/09/15 22:01:57, 6]
> lib/util_sock.c:write_socket(452)
> Sep 15 22:01:57 lx2-rvmo-02 smbd[9780]: write_socket(23,39) wrote 39
> Sep 15 22:02:01 lx2-rvmo-02 PAM_unix[10454]: (cron) session opened for
> user root by (uid=0)
> Sep 15 22:02:01 lx2-rvmo-02 /USR/SBIN/CRON[10455]: (root) CMD (test -x
> /usr/sbin/logcheck && nice -n10 /usr/sbin/logcheck)
> Sep 15 22:02:01 lx2-rvmo-02 PAM_unix[10454]: (cron) session closed for
> user root
> Sep 15 22:02:07 lx2-rvmo-02 nmbd[32436]: [2004/09/15 22:02:07, 4]
> nmbd/nmbd_workgroupdb.c:find_workgroup_on_subnet(162)
> Sep 15 22:02:07 lx2-rvmo-02 nmbd[32436]: find_workgroup_on_subnet:
> workgroup search for RVMO.DE on subnet 192.168.1.2: found.
> Sep 15 22:02:07 lx2-rvmo-02 nmbd[32436]: [2004/09/15 22:02:07, 4]
> nmbd/nmbd_workgroupdb.c:find_workgroup_on_subnet(162)
> Sep 15 22:02:07 lx2-rvmo-02 nmbd[32436]: find_workgroup_on_subnet:
> workgroup search for RVMO.DE on subnet UNICAST_SUBNET: found.
> Sep 15 22:02:07 lx2-rvmo-02 nmbd[32436]: [2004/09/15 22:02:07, 4]
> nmbd/nmbd_workgroupdb.c:find_workgroup_on_subnet(162)
> Sep 15 22:02:07 lx2-rvmo-02 nmbd[32436]: find_workgroup_on_subnet:
> workgroup search for RVMO.DE on subnet UNICAST_SUBNET: found
>
>
>
> Attachments (can be delivered directly by mail, are too large
> #####################################################
> - log.nmdb from logon process (logging on from rvmo1018)
> - log.smdb from logon process (logging on from rvmo1018)
> - log.rvmo1018 from logon process (logging on from rvmo1018)
> - syslog from logon process (logging on from rvmo1018)
>
>
>
>
>
>
More information about the samba
mailing list