[Samba] Re: Samba 2.0.6-3 (productive env.) slow down dramticaly

Heiko Boeringer heiko.boeringer at epost.de
Wed Sep 15 20:47:06 GMT 2004


Hello community,

here is an extract from the syslog during the logon process. Any ideas 
what this means?? Is there my problem?

######################
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   000130 smb_io_rpc_auth_netsec_chk
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 5] 
rpc_parse/parse_prs.c:prs_uint8s(722)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:       0130 sig  : 77 00 7a 00 ff 
ff 00 00
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 5] 
rpc_parse/parse_prs.c:prs_uint8s(722)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:       0138 seq_num: c3 34 3d a2 
e8 98 8f 64
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 5] 
rpc_parse/parse_prs.c:prs_uint8s(722)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:       0140 packet_digest: 5e 9d 
de f0 4e fc e2 89
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 5] 
rpc_parse/parse_prs.c:prs_uint8s(722)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:       0148 confounder: 67 2e 41 
e1 94 ad d1 c1
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 2] 
rpc_parse/parse_prs.c:netsec_decode(1578)
 >>>>> Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   netsec_decode: FAILED: 
packet sequence number:
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 2] 
lib/util.c:dump_data(1839)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   [000] D8 1C 86 DB 9C 1D 65 
40                           ......e@
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 2] 
rpc_parse/parse_prs.c:netsec_decode(1580)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   should be:
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 2] 
lib/util.c:dump_data(1839)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   [000] 00 00 00 00 80 00 00 
00                           ........
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 3] 
rpc_server/srv_pipe.c:api_pipe_netsec_process(1403)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   failed to decode PDU
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 3] 
rpc_server/srv_pipe_hnd.c:process_request_pdu(605)
 >>>>>> Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   process_request_pdu: 
failed to do schannel processing.
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 3] 
rpc_server/srv_pipe_hnd.c:process_complete_pdu(752)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   process_complete_pdu: DCE/RPC 
fault sent on pipe lsass
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:37, 5] 
rpc_parse/parse_prs.c:prs_debug(82)
Sep 15 20:49:37 lx2-rvmo-02 smbd[8410]:   000000 smb_io_rpc_hdr


#########################
Whats this - the secrets.tdb is definitvely the right one and all access 
is running fine, only very, very slow....

Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:42, 5] 
libsmb/trustdom_cache.c:trustdom_cache_fetch(184)
 >>>>> Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]:   no entry for trusted 
domain RVMO.DE found.
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:42, 5] 
auth/auth_util.c:make_user_info(133)
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]:   attempting to make a user_info 
for  ()
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:42, 5] 
auth/auth_util.c:make_user_info(143)
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]:   making strings for 's 
user_info struct
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:42, 5] 
auth/auth_util.c:make_user_info(185)
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]:   making blobs for 's user_info 
struct
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:42, 3] 
auth/auth.c:check_ntlm_password(219)
 >>>>> Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]:   check_ntlm_password:  
Checking password for unmapped user []\[]@[RVMO1018] with the new 
password interface
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:42, 3] 
auth/auth.c:check_ntlm_password(222)
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]:   check_ntlm_password:  mapped 
user is: [RVMO.DE]\[]@[RVMO1018]
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:42, 5] 
lib/util.c:dump_data(1839)
Sep 15 20:49:42 lx2-rvmo-02 smbd[8410]:   [000] 64 CF D6 A6 83 08 99 
EC                           d.......

###########################
Sep 15 20:49:53 lx2-rvmo-02 smbd[4125]: [2004/09/15 20:49:53, 3] 
smbd/connection.c:yield_connection(76)
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   se_access_check: also 
S-1-5-21-29628934-819234659-1421906636-2046
 >>>> Sep 15 20:49:53 lx2-rvmo-02 smbd[4125]:   yield_connection: 
tdb_delete for name  failed with error Record does not exist.
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   se_access_check: also 
S-1-5-21-29628934-819234659-1421906636-2073
Sep 15 20:49:53 lx2-rvmo-02 smbd[4125]: [2004/09/15 20:49:53, 5] 
smbd/oplock.c:receive_local_message(107)
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   se_access_check: also 
S-1-5-21-29628934-819234659-1421906636-512
Sep 15 20:49:53 lx2-rvmo-02 smbd[4125]:   receive_local_message: doing 
select with timeout of 1 ms
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   se_access_check: also 
S-1-5-21-29628934-819234659-1421906636-11137
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   se_access_check: also 
S-1-5-21-29628934-819234659-1421906636-2083
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   se_access_check: also 
S-1-5-21-29628934-819234659-1421906636-5075
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:53, 5] 
lib/util_seaccess.c:se_access_check(309)
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   se_access_check: access (1) 
granted.
Sep 15 20:49:53 lx2-rvmo-02 smbd[4125]: [2004/09/15 20:49:53, 3] 
smbd/server.c:exit_server(614)
Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]: [2004/09/15 20:49:53, 5] 
lib/username.c:user_in_netgroup_list(315)
Sep 15 20:49:53 lx2-rvmo-02 smbd[4125]:   Server exit (normal exit)
 >>>>>> Sep 15 20:49:53 lx2-rvmo-02 smbd[8410]:   Unable to get default 
yp domain



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 to look!
>
> 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