opensuse 12.2: yast "System Services (Runlevel): Services" very slow: how to investigate

jpluimers · June 20, 2013, 9:55am

I’ve a two server installations (so no X and other graphics stuff) of opensuse 12.2 to which I have SSH access and can sudo.

Network stuff is fast (SSH login, traceroute to the outside world, inbound and outbound smtp, inbound apache).
The machines are VMs on two different ESXi hosts behind two different NAT routers.
Both machines have 1024 megabyte memory and a single core XEON 2.5 Ghz CPU core.
Both machines are frequently updated (at least a couple of times a month but not on a regular schedule).

Two things are very slow on both machines:

1- yast “Network Services: HTTP Server”
2- yast “System Services (Runlevel): Services”

The first takes multiple minutes to start.
The second takes more than a minute per service to show the status.

When performing either of these 2 yast tasks on the machines, the whole affected machine feels slow (i.e. rpm -qa or starting another yast session takes forever, starting joe, top or less are slow, ssh login times out)
free -m -h indicates there is about 90 megabyte of free memory, and 690 megabyte of free buffers (I guess opensuse reserves most of the memory for buffers and little for processes).
top does not indicate high CPU usage.
/var/log/messages does not contain really strange stuff

As soon as the 2 slow yast tasks are done, the machines feel snappy again.

How can I start finding a cause?


snip:/home/jeroenp # free -m -h
             total       used       free     shared    buffers     cached
Mem:          997M       912M        84M         0B        36K       605M
-/+ buffers/cache:       306M       690M
Swap:         1.5G        24M       1.4G

top lines of top:


top - 09:44:44 up 8 days, 12:15,  4 users,  load average: 30.37, 28.61, 23.47
Tasks: 182 total,   1 running, 181 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.3 us,  1.0 sy,  0.0 ni,  0.0 id, 98.7 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:   1021008 total,   941552 used,    79456 free,       36 buffers
KiB Swap:  1532924 total,    25420 used,  1507504 free,   602836 cached


  PID USER      PR  NI  VIRT  RES  SHR S  %CPU %MEM    TIME+  COMMAND                                                                                           
 3260 vscan     20   0  222m  96m 1060 S   0.0  9.7   0:09.14 /usr/sbin/amavi                                                                                   
 3270 vscan     20   0  223m  95m  612 S   0.0  9.6   0:00.01 /usr/sbin/amavi                                                                                   
 3271 vscan     20   0  223m  95m  612 S   0.0  9.6   0:00.01 /usr/sbin/amavi                                                                                   
27344 root      20   0 57536  20m 2072 D   0.0  2.0   0:00.50 rpm                                                                                               
26889 root      20   0  159m  19m 7468 S   0.3  1.9   0:11.66 y2base                                                                                            
27436 root      20   0  140m  11m 5424 S   0.0  1.2   0:00.40 y2base                                                                                            
26853 root      20   0  140m  11m 5424 S   0.0  1.2   0:00.42 y2base

/var/log/messages


Jun 20 08:20:23 snip sshd[26228]: Accepted keyboard-interactive/pam for jeroenp from 92.66.117.174 port 53992 ssh2
Jun 20 08:20:23 snip systemd-logind[488]: New session 914 of user jeroenp.
Jun 20 08:20:26 snip sudo:  jeroenp : TTY=pts/0 ; PWD=/home/jeroenp ; USER=root ; COMMAND=/bin/bash
Jun 20 08:30:50 snip master[26676]: about to exec /usr/lib/cyrus/bin/ctl_cyrusdb
Jun 20 08:31:14 snip ctl_cyrusdb[26676]: checkpointing cyrus databases
Jun 20 08:31:14 snip ctl_cyrusdb[26676]: archiving log file: /var/lib/imap/db/log.0000000001
Jun 20 08:31:14 snip ctl_cyrusdb[26676]: last message repeated 2 times
Jun 20 08:31:14 snip ctl_cyrusdb[26676]: archiving database file: /var/lib/imap/annotations.db
Jun 20 08:31:14 snip ctl_cyrusdb[26676]: archiving database file: /var/lib/imap/mailboxes.db
Jun 20 08:31:14 snip ctl_cyrusdb[26676]: archiving log file: /var/lib/imap/db/log.0000000001
Jun 20 08:31:14 snip ctl_cyrusdb[26676]: done checkpointing cyrus databases
Jun 20 08:31:15 snip master[2656]: process 26676 exited, status 0
Jun 20 08:38:53 snip sshd[26772]: Accepted keyboard-interactive/pam for jeroenp from 92.66.117.174 port 56572 ssh2
Jun 20 08:38:53 snip sudo:  jeroenp : TTY=pts/1 ; PWD=/home/jeroenp ; USER=root ; COMMAND=/bin/bash
Jun 20 08:38:54 snip systemd-logind[488]: New session 916 of user jeroenp.
Jun 20 08:41:40 snip sshd[27023]: Accepted keyboard-interactive/pam for jeroenp from 92.66.117.174 port 56665 ssh2
Jun 20 08:41:42 snip sudo:  jeroenp : TTY=pts/2 ; PWD=/home/jeroenp ; USER=root ; COMMAND=/bin/bash
Jun 20 08:41:42 snip systemd-logind[488]: New session 917 of user jeroenp.
Jun 20 08:57:16 snip /USR/SBIN/CRON[27230]: (root) CMD (/usr/lib/AntiVir/guard/avupdate-guard --product=Scanner > /dev/null)
Jun 20 09:03:14 snip master[27304]: about to exec /usr/lib/cyrus/bin/ctl_cyrusdb
Jun 20 09:03:14 snip ctl_cyrusdb[27304]: checkpointing cyrus databases
Jun 20 09:03:14 snip ctl_cyrusdb[27304]: archiving log file: /var/lib/imap/db/log.0000000001
Jun 20 09:03:15 snip ctl_cyrusdb[27304]: last message repeated 2 times
Jun 20 09:03:15 snip ctl_cyrusdb[27304]: archiving database file: /var/lib/imap/annotations.db
Jun 20 09:03:15 snip ctl_cyrusdb[27304]: archiving database file: /var/lib/imap/mailboxes.db
Jun 20 09:03:15 snip ctl_cyrusdb[27304]: archiving log file: /var/lib/imap/db/log.0000000001
Jun 20 09:03:15 snip ctl_cyrusdb[27304]: done checkpointing cyrus databases
Jun 20 09:03:15 snip master[2656]: process 27304 exited, status 0
Jun 20 09:03:15 snip systemd[1]: Cannot add dependency job for unit ldap.service, ignoring: Unit ldap.service failed to load: No such file or directory. See system logs and 'systemctl status ldap.service' for details.
Jun 20 09:03:15 snip systemd[1]: Cannot add dependency job for unit ldap.service, ignoring: Unit ldap.service failed to load: No such file or directory. See system logs and 'systemctl status ldap.service' for details.
Jun 20 09:08:16 snip sshd[27347]: reverse mapping checking getaddrinfo for static.kpn.net [92.66.117.174] failed - POSSIBLE BREAK-IN ATTEMPT!
Jun 20 09:11:24 snip sudo:  jeroenp : TTY=pts/3 ; PWD=/home/jeroenp ; USER=root ; COMMAND=/bin/bash
Jun 20 09:11:25 snip systemd-logind[488]: New session 921 of user jeroenp.

–jeroen

knurpht · June 20, 2013, 10:08am

Ha Jeroen, welkom !!

As far as I can see, this is not Yast related, but rather LDAP. See that last bits of your output, it complains about a dep. not being available. This means something is missing somewhere, which probably causes the “slowdown”. Also I see a message about a possible break-in attempt.
A good practice is to look at “top” in another virtual tty, i.e. perform one of the tasks you know is slowing down stuff, then hit Ctrl-Alt-F2, login and run “top”.

jpluimers · June 20, 2013, 10:12am

Thanks for the welcome (:

I ran top from a second ssh session (that’s why I had so many sessions open).
The break in attempt is because the site I login from does not have a good reverse DNS.

When the yast software install does not complain about the ldap dependency, how can I find out what is missing for ldap?

–jeroen

knurpht · June 20, 2013, 10:19am

Sorry, missed the output from top

knurpht · June 20, 2013, 10:28am

The hint is already there: what does


systemctl status ldap.service

say?
Point with networked services is that they try and try and try. Is LDAP being used? If it is, users should experiene difficulties at least. If LDAP is not being used, stop it, run the Yast modules known to slow down things, and see if things have improved:


systemctl stop ldap.service

If it does, and there’s no user complaints, LDAP is probably not being used at all ( it’s not working now, and you don’t report users complaining ), then disable the service:


systemctl disable ldap.service

jpluimers · June 20, 2013, 11:14am

(I probably should first have indicated why I want this solved:
Of the two systems, the primary one handles my incoming mail and performs mail forwarding to the final mailboxes, provides DNS, and does some web-redirection.
The secondary one is on a separate ISP and is backup DNS. Other backup DNS and backup MX is shared amongst a group of friends.
The secondary machine is also my “experimental” box. I want to install tiny tiny RSS on it as Google Reader stops. Initially I thought Feedly supported the full history import (as it was visible when using Feedly), but found out the hard way that Feedly does not import the history when moving to the Feedly cloud: Is there a Google Reader replacement that keeps ALL Google Reader history?
Part of my Google Reader history are blogs that are now defunct (one of them from a deceased friend): I want to keep their content for archival purposes.
It looks like tiny tiny RSS can do that, but it requires mysql (which I didn’t have running and maybe not even want to run: I wish tiny tiny RSS would support mariadb by default).
)


snip:/home/jeroenp # systemctl status ldap.service
ldap.service
      Loaded: error (Reason: No such file or directory)
      Active: inactive (dead)

Knurpht:

Point with networked services is that they try and try and try. Is LDAP being used? If it is, users should experiene difficulties at least. If LDAP is not being used, stop it, run the Yast modules known to slow down things, and see if things have improved:
systemctl stop ldap.service
If it does, and there’s no user complaints, LDAP is probably not being used at all ( it’s not working now, and you don’t report users complaining ), then disable the service:

I know about networking services (many of my past gigs involved systems programming on the PC side talking to various obscure network systems on the other side), that’s why I wrote about the network stuff in the first message: most of it looks fast. To elaborate on that:

hostname seems OK
DNS is accessible
default route is OK
traceroute to the outside world is OK.


snip:/home/jeroenp # systemctl stop ldap.service

It does not give output, and it does not improve the yast speed for “HTTP Server Configuration”. It hangs for a very long time (minutes) at the 25% mark:


Initializing HTTP Server Configuration                                                
 
   -   Check the environment
   -   Read Apache2 configuration
   -   Read network configuration

It also does not improve the yast “System Services (Runlevel): Services”: still takes very long.

It fails, but doesn’t tell me which file or directory is missing (the log does not tell me either):


snip:/home/jeroenp # systemctl disable ldap.service
Failed to issue method call: No such file or directory

I tried finding out which package is providing the ldap server, but the result of the installed rpms is confusing:


snip:/home/jeroenp # rpm -qa | sort | grep ldap
libldap-2_4-2-2.4.31-2.1.3.x86_64
libldap-2_4-2-32bit-2.4.31-2.1.3.x86_64
libldapcpp1-0.3.0-8.1.2.x86_64
openldap2-client-2.4.31-2.1.3.x86_64
perl-ldap-0.44-2.1.1.x86_64
yast2-ldap-2.22.2-2.1.3.x86_64
yast2-ldap-client-2.22.10-2.4.1.noarch

I don’t see any ldap server package in this list.

I’m feeling I miss something important here (next to the fact that yast drives me crazy, but I don’t know the proper shell commands to perform install/deinstall/investigation well enough to perform these tasks swiftly without yast).

–jeroen

jpluimers · June 20, 2013, 11:45am

I found out about a bug I thought was related: Access Denied
But the workaround systemctl daemon-reload does not solve the issue.

–jeroen

wolfi323 · June 20, 2013, 11:55am

Your problem is that something wants to start ldap.service but it doesn’t exist.
My guess would be that you have a symlink somewhere in /etc/systemd/system/ that points to a missing file.

What does “find /etc/systemd/ -name ldap.service” give you?

jpluimers · June 20, 2013, 12:06pm

Found out about zypper (see output below), and it proves my point: no ldap server installed.

So some more questions:

why does opensuse think it should start the ldap service?
where does opensuse put the configuration information for loading ldap.service?
is it safe to manually change that configuration information?


snip:/home/jeroenp # zypper search --installed-only ldap
Loading repository data...
Reading installed packages...


S | Name                | Summary                               | Type   
--+---------------------+---------------------------------------+--------
i | libldap-2_4-2       | OpenLDAP Client Libraries             | package
i | libldap-2_4-2-32bit | OpenLDAP Client Libraries             | package
i | libldapcpp1         | C++ API for LDAPv3                    | package
i | openldap2-client    | The OpenLDAP commandline client tools | package
i | perl-ldap           | Client Interface for LDAP Servers     | package
i | yast2-ldap          | YaST2 - LDAP Agent                    | package
i | yast2-ldap-client   | YaST2 - LDAP Client Configuration     | package

wolfi323 · June 20, 2013, 12:07pm

And since openldap2 still contains an sysvinit init script, also:

find /etc/init.d -name ldap

You could also try to install the openldap2 package, so that the service does exist.

jpluimers · June 20, 2013, 12:14pm

Good: we came to the same conclusion (:

The bad thing: no mention of ldap.service or ldap in /etc/system.d:


snip:/home/jeroenp # find /etc/systemd/ -name ldap.service
snip:/home/jeroenp # find /etc/systemd/ -name ldap        
snip:/home/jeroenp # grep -inrw ldap /etc/systemd/
snip:/home/jeroenp #

The ldap.service is the only service that fails at boot:


snip:/home/jeroenp # dmesg | grep dependency
   13.052361] systemd[1]: Cannot add dependency job for unit ldap.service, ignoring: Unit ldap.service failed to load: No such file or directory. See system logs and 'systemctl status ldap.service' for details.

–jeroen

jpluimers · June 20, 2013, 12:21pm

Empty as well.
What’s the difference between sysvinit and non-sysvinit?

I’d rather do not do that yet, as I want to find out the root cause (I’m a bit pedantic, but I’d rather know the cause first before performing circumventing measures).

–jeroen

wolfi323 · June 20, 2013, 1:20pm

sysvinit is the older init system having runlevels 1-5 with scripts in /etc/init.d/.
systemd is a new replacement used by default in openSUSE since 12.1. It has more flexible “targets” instead of runlevels and doesn’t use scripts but so called “service files” (but it can run the old sysvinit scripts as well for compatibility).
Those service files are located in /usr/lib/systemd, and /etc/systemd contains for each “target” a directory with symlinks to those service files that should be started in that target (a bit similar to how it’s done with sysvinit).

I’d rather do not do that yet, as I want to find out the root cause (I’m a bit pedantic, but I’d rather know the cause first before performing circumventing measures).

Maybe “journalctl” contains a clue? (could be called “systemd-journalctl” on 12.2, I’m not sure right now)

As I said, something wants to start ldap.service, maybe as dependency.
So try to do a “grep -R ldap /etc/init.d” and “grep -R ldap /etc/systemd”…

Or maybe even “find /usr/lib/systemd -name ldap.service” and “grep -R ldap /usr/lib/systemd”.

jpluimers · June 20, 2013, 2:35pm

Maybe “journalctl” contains a clue? (could be called “systemd-journalctl” on 12.2, I’m not sure right now)

Yes, it is the latter. It is slow to get all entries, so I will send the output to a text file and then browse it.

Later: browsed it.
The first occurrence is at januari 1st (which means today is the first day I have tried to enable new system services since then).
I took screenshots during the initial install. This is right after I installed sendmail.


Jan 01 22:25:32 snip systemd[1]: Cannot add dependency job for unit ldap.service, ignoring: Unit ldap.service failed to load: No such file or direc...r details.

As I said, something wants to start ldap.service, maybe as dependency.
So try to do a “grep -R ldap /etc/init.d” and “grep -R ldap /etc/systemd”…

Or maybe even “find /usr/lib/systemd -name ldap.service” and “grep -R ldap /usr/lib/systemd”.

Bingo lots of results. Now I probably need some guidance on how to interpret them (:

What I think the below says is that sendmail needs ldap.service, but that yast does not understand this dependency.
Which means that I should install openldap2 like suggested by wolfi323: https://forums.opensuse.org/english/get-technical-help-here/install-boot-login/488019-opensuse-12-2-yast-system-services-runlevel-services-very-slow-how-investigate.html#post2566097

Can someone please confirm/deny my reasoning?


snip:/etc/systemd/system # find /usr/lib/systemd -name ldap.service

snip:/etc/systemd/system # grep -R ldap /usr/lib/systemd

snip:/etc/systemd/system # grep -R ldap /etc/systemd
/etc/systemd/system/multi-user.target.wants/sendmail.service:Wants=amavis.service cyrus.service ldap.service nscd.service ypbind.service sendmail-client.service
/etc/systemd/system/multi-user.target.wants/sendmail.service:After=amavis.service cyrus.service ldap.service nscd.service ypbind.service


snip:/etc/systemd/system # grep -R ldap /etc/init.d
/etc/init.d/rc3.d/S08smb:# Should-Start:   cupsd winbind nmb ldap
/etc/init.d/rc3.d/S08smb:# Should-Stop:    cupsd winbind nmb ldap
/etc/init.d/rc3.d/K01smb:# Should-Start:   cupsd winbind nmb ldap
/etc/init.d/rc3.d/K01smb:# Should-Stop:    cupsd winbind nmb ldap
/etc/init.d/rc3.d/S11sendmail:# Should-Start:      amavis cyrus ldap nscd ypbind
/etc/init.d/rc3.d/S11sendmail:# Should-Stop:       amavis cyrus ldap nscd ypbind
/etc/init.d/rc3.d/K03sendmail:# Should-Start:      amavis cyrus ldap nscd ypbind
/etc/init.d/rc3.d/K03sendmail:# Should-Stop:       amavis cyrus ldap nscd ypbind
/etc/init.d/rc3.d/S08named:# Should-Start:      ldap
/etc/init.d/rc3.d/S08named:# Should-Stop:       ldap
/etc/init.d/rc3.d/K05named:# Should-Start:      ldap
/etc/init.d/rc3.d/K05named:# Should-Stop:       ldap
/etc/init.d/rc5.d/S08smb:# Should-Start:   cupsd winbind nmb ldap
/etc/init.d/rc5.d/S08smb:# Should-Stop:    cupsd winbind nmb ldap
/etc/init.d/rc5.d/K01smb:# Should-Start:   cupsd winbind nmb ldap
/etc/init.d/rc5.d/K01smb:# Should-Stop:    cupsd winbind nmb ldap
/etc/init.d/rc5.d/S11sendmail:# Should-Start:      amavis cyrus ldap nscd ypbind
/etc/init.d/rc5.d/S11sendmail:# Should-Stop:       amavis cyrus ldap nscd ypbind
/etc/init.d/rc5.d/K03sendmail:# Should-Start:      amavis cyrus ldap nscd ypbind
/etc/init.d/rc5.d/K03sendmail:# Should-Stop:       amavis cyrus ldap nscd ypbind
/etc/init.d/rc5.d/S08named:# Should-Start:      ldap
/etc/init.d/rc5.d/S08named:# Should-Stop:       ldap
/etc/init.d/rc5.d/K05named:# Should-Start:      ldap
/etc/init.d/rc5.d/K05named:# Should-Stop:       ldap
/etc/init.d/autofs:# Should-Start:   $portmap ypbind keyserv ldap nfsserver network-remotefs
/etc/init.d/autofs:# Should-Stop:    $portmap ypbind keyserv ldap nfsserver network-remotefs
/etc/init.d/sendmail:# Should-Start:      amavis cyrus ldap nscd ypbind
/etc/init.d/sendmail:# Should-Stop:       amavis cyrus ldap nscd ypbind
/etc/init.d/smb:# Should-Start:   cupsd winbind nmb ldap
/etc/init.d/smb:# Should-Stop:    cupsd winbind nmb ldap
/etc/init.d/named:# Should-Start:      ldap
/etc/init.d/named:# Should-Stop:       ldap
/etc/init.d/dhcpd:# Should-Start:            network-remotefs $named $syslog $time ldap ndsd
/etc/init.d/dhcpd:# Should-Stop:            network-remotefs $named $syslog ldap ndsd
/etc/init.d/dhcpd:LDAP_CONF=/etc/openldap/ldap.conf
/etc/init.d/dhcpd6:# Should-Start:            network-remotefs $named $syslog $time ldap ndsd
/etc/init.d/dhcpd6:# Should-Stop:            network-remotefs $named $syslog ldap ndsd


snip:/etc/systemd/system #

Thanks for all the help so far. Learned a lot of new things today: good thing (:

Some notes on what I learned:

zypper search openldap2
zypper verify
zypper what-provides ldap
zypper update
zypper ps

/bin/systemd-journalctl

–jeroen

jpluimers · June 21, 2013, 12:37pm

Anyone? Please? (:

wolfi323 · June 21, 2013, 1:08pm

jpluimers:


snip:/etc/systemd/system # grep -R ldap /etc/systemd
/etc/systemd/system/multi-user.target.wants/sendmail.service:Wants=amavis.service cyrus.service ldap.service nscd.service ypbind.service sendmail-client.service
/etc/systemd/system/multi-user.target.wants/sendmail.service:After=amavis.service cyrus.service ldap.service nscd.service ypbind.service

I guess that one is causing that error message.
In this case your only options are to disable/uninstall sendmail (maybe use postfix instead?) or install openldap2 to get rid of that error message.

But I’m not sure that this causes your slow yast.
You could try to disable sendmail.service by calling “sudo systemctl disable sendmail.service” temporarily and run yast to see if that helps.
You can enable it then again with “sudo systemctl enable sendmail.service”.

What I think the below says is that sendmail needs ldap.service, but that yast does not understand this dependency.

You mean yast software management?
That only knows about dependencies that are specified in the RPM files. If one needed dependency is missing there, this should be reported as bug.
But it seems sendmail works without ldap, doesn’t it?
Maybe only that service dependency is wrong? (although: Wants != Requires; that only means it will be started if it’s available)

jpluimers · June 21, 2013, 11:59pm

I did
sudo systemctl disable sendmail.service
followed by
sudo rcsendmail stop

Tried yast -> Network Services -> HTTP Server.
It is still slow (takes about 2 minutes to load).

Same for yast -> System -> System services.
Takes 30+ seconds per service to show the current enabled state.

The only good thing I thought: no more ldap messages in /var/log/messages when doing things in yast, only after reboot.

Then it occurred to me: what if some dependencies did still not resolve them selves automatically?

So I rebooted. And it works! Thanks guys for your knowledge and your patience!

Tried yast -> Network Services -> HTTP Server.
Much faster (about 20 seconds to load).

Same for yast -> System -> System services.
Takes less than 1 second per service to show the current enabled state.

Still no new ldap warnings in the /var/log/messages

Conclusion: somehow the ldap services is needed and speeds a lot of things up.
Not sure why, so if anyone knows, please share your knowledge about it.

You mean yast software management?
That only knows about dependencies that are specified in the RPM files. If one needed dependency is missing there, this should be reported as bug.
But it seems sendmail works without ldap, doesn’t it?
Maybe only that service dependency is wrong? (although: Wants != Requires; that only means it will be started if it’s available)

Somewhere later this summer I’ll try this with the most recent opensuse version. If it still reproduces, I’ll log a bug.

–jeroen

robin_listas · June 25, 2013, 2:53am

Re-posting, as it did not make to the web-side.

On Sat, 22 Jun 2013 09:33:15 +0000, Carlos E. R. wrote:

> On 2013-06-22 00:06, jpluimers wrote:
>
>> Tried yast → Network Services → HTTP Server.
>> It is still slow (takes about 2 minutes to load).
>>
>> Same for yast → System → System services.
>> Takes 30+ seconds per service to show the current enabled state.
>>
>> The only good thing I thought: no more ldap messages in
>> /var/log/messages when doing things in yast, only after reboot.
>
> I have no access to this thread except this single message, yet…
>
> The 2 minutes wait is the delay while waiting for an LDAP server to
> respond. I think it might 30" per query.
>
> Somehow you configured for LDAP usage, and it is not working.