systemd en systemd-journal gebruiken elk 95% CPU

Nederlands (Dutch) Installatie - Opstarten - Login
#1

Heeft iemend een oplossing voor de volgende situatie?
In onderstaande situatie heeft proces 24822 al een "kill -HUP’ gekregen

# top
top - 10:16:37 up 3 days, 18:58,  3 users,  load average: 2.71, 2.83, 2.79
Tasks: 269 total,   3 running, 265 sleeping,   0 stopped,   1 zombie
%Cpu(s): 13.5 us, 11.5 sy,  0.0 ni, 74.1 id,  1.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:  12199972 total, 10566660 used,  1633312 free,  1302292 buffers
KiB Swap:  2104316 total,   162824 used,  1941492 free,  6895316 cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM     TIME+ COMMAND
24822 root      20   0 1458m  14m  13m R 94.4  0.1  30:17.48 systemd-journal
    1 root      20   0 77320 7852 2852 R 93.1  0.1   5257:24 systemd

$ journalctl
-- Logs begin at Thu, 2013-09-26 04:40:06 CEST, end at Thu, 2013-09-26 10:17:33 CEST. --
Sep 26 04:40:06 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:06 tux systemd-journal[580]: Missed 18721 kernel messages
Sep 26 04:40:06 tux systemd[1]: syslogd.service start request repeated too quickly, refusing to start.
Sep 26 04:40:06 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:06 tux systemd[1]: syslogd.service start request repeated too quickly, refusing to start.
Sep 26 04:40:06 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
:
:
Sep 26 04:40:06 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:06 tux systemd[1]: syslogd.service start request repeated too quickly, refusing to start.
Sep 26 04:40:06 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:06 tux systemd[1]: syslogd.service start request repeated too quickly, refusing to start.
Sep 26 04:40:06 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:07 tux systemd-journal[580]: Suppressed 160266 messages from /system
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
:
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:07 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 04:40:07 tux systemd[1]: Failed to start System Logging Service.
Sep 26 04:40:10 tux systemd-journal[580]: Missed 13664 kernel messages
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd-journal[580]: Missed 2477 kernel messages
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
:
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd-journal[580]: Suppressed 125424 messages from /system
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Starting System Logging Service...
Sep 26 04:40:10 tux systemd[1]: Job klogd.service/start failed with result 'dependency'.
Sep 26 04:40:10 tux systemd[1]: Starting System Logging Service...
Sep 26 04:40:10 tux systemd[1]: Starting System Logging Service...
Sep 26 04:40:10 tux systemd[1]: Starting System Logging Service...
Sep 26 04:40:10 tux systemd[1]: Starting System Logging Service...
Sep 26 04:40:10 tux systemd[1]: Starting System Logging Service...
Sep 26 04:40:10 tux systemd[1]: Starting System Logging Service...

Linux 3.7.10-1.16-desktop [openSUSE 12.3 (Dartmouth)] x86_64 Xeon(R) CPU E3-1245 V2 @ 3.40GHz/1600(8) x86_64 11914 Mb

# rpm -qa | grep -i -e kernel -e systemd | sort
kernel-default-3.7.10-1.16.1.x86_64
kernel-default-devel-3.7.10-1.16.1.x86_64
kernel-desktop-3.7.10-1.1.1.x86_64
kernel-desktop-3.7.10-1.16.1.x86_64
kernel-desktop-devel-3.7.10-1.16.1.x86_64
kernel-devel-3.7.10-1.16.1.noarch
kernel-docs-3.7.10-1.16.1.noarch
kernel-firmware-20130714git-1.5.1.noarch
kernel-source-3.7.10-1.16.1.noarch
nfs-kernel-server-1.2.7-2.14.1.x86_64
systemd-195-13.40.1.x86_64
systemd-32bit-195-13.40.1.x86_64
systemd-presets-branding-openSUSE-0.2.0-2.5.1.noarch
systemd-sysvinit-195-13.40.1.x86_64
texlive-l3kernel-2012.67.svn_3570svn26111-4.5.2.noarch
# zypper lp
Loading repository data...
Reading installed packages...
No updates found.
#2

Hallo,

Ik zie zo op het eerste oog dat je zowel kernel-default als kernel-desktop geïnstalleerd hebt. Heeft dat een reden?
Installeer ook 's het pakket systemd-analyze, en doe daarna eens

systemd-analyze blame

en post de output hier

EDIT:
PS bij mij draait die klogd.service helemaal niet:


@laptop:~> systemctl status klogd.service
klogd.service - System Kernel Logging Service
          Loaded: loaded (/usr/lib/systemd/system/klogd.service; disabled)
          Active: inactive (dead)
          CGroup: name=systemd:/system/klogd.service
#3 

# systemctl status klogd.service
klogd.service - System Kernel Logging Service
          Loaded: loaded (/usr/lib/systemd/system/klogd.service; disabled)
          Active: inactive (dead)
          CGroup: name=systemd:/system/klogd.service

Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
Sep 26 14:30:51 tux systemd[1]: Dependency failed for System Kernel Logging Service.
# systemd-analyze blame
  7690ms NetworkManager-dispatcher.service
  7575ms avahi-daemon.service
  7542ms systemd-logind.service
  6778ms network.service
  3876ms ossec.service
  3466ms postgresql.service
  3442ms apparmor.service
  1515ms systemd-vconsole-setup.service
  1442ms cycle.service
  1426ms systemd-udev-root-symlink.service
  1356ms systemd-modules-load.service
  1292ms systemd-remount-fs.service
  1118ms apache2.service
  1054ms dev-hugepages.mount
  1049ms dev-mqueue.mount
   896ms postfix.service
   560ms vmtoolsd.service
   560ms xfs.service
   357ms console-kit-daemon.service
   352ms systemd-sysctl.service
   264ms systemd-user-sessions.service
   262ms rtkit-daemon.service
   258ms console-kit-log-system-start.service
   220ms polkit.service
   219ms scpm.service
   214ms udisks2.service
   198ms systemd-tmpfiles-setup.service
   176ms bluetooth.service
   154ms openct.service
   124ms upower.service
   101ms xdm.service
    93ms fbset.service
    87ms identd.service
    86ms systemd-readahead-replay.service
    75ms boot-efi.mount
    40ms ntp.service
    38ms systemd-udevd.service
    30ms atd.service
    22ms systemd-readahead-collect.service
    17ms sshd.service
    13ms isapnp.service
    13ms systemd-udev-trigger.service
    13ms proc-sys-fs-binfmt_misc.mount
    13ms sys-fs-fuse-connections.mount
    10ms var-lock.mount
     4ms rc-local.service
     2ms sys-kernel-debug.mount
     1ms var-run.mount
#

Beide kernels is waarschijnlijk een gevolg van het installeren van alle packages die op mijn vorige systeem ook waren geïnstalleerd (OpenSUSE 11.4)
Ik heb er geen probleem mee om kernel-default te verwijderen, maar als ik me goed herinner heeft VMWare daar iets van nodig

#4

Workstation:


# uname -a
Linux tux 3.7.10-1.16-desktop #1 SMP PREEMPT Fri May 31 20:21:23 UTC 2013 (97c14ba) x86_64 x86_64 x86_64 GNU/Linux
# ps -fl 1
F S UID        PID  PPID  C PRI  NI ADDR SZ WCHAN  STIME TTY        TIME CMD
4 R root         1     0 96  80   0 - 19330 -      Sep22 ?        5556:12 /sbin/init showopts
# ps -efl | grep system
4 S root       363     1  0  80   0 - 17063 -      Sep22 ?        00:00:00 /usr/lib/systemd/systemd-udevd
4 S root       775     1  0  80   0 -  6595 -      Sep22 ?        00:00:28 /usr/lib/systemd/systemd-logind
4 S message+  2625     1  0  80   0 -  5779 -      Sep22 ?        00:01:27 /bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation
4 R root     24822     1 94  80   0 - 208325 -     09:45 ?        05:25:26 /usr/lib/systemd/systemd-journald

Laptop:


# uname -a
Linux lx09 3.7.10-1.16-desktop #1 SMP PREEMPT Fri May 31 20:21:23 UTC 2013 (97c14ba) i686 i686 i386 GNU/Linux
# ps -fl 1
F S UID        PID  PPID  C PRI  NI ADDR SZ WCHAN  STIME TTY        TIME CMD
4 S root         1     0  0  80   0 -  1447 ?      Sep24 ?          0:06 /sbin/init
# ps -efl | grep system
4 S root       247     1  0  80   0 - 65306 ?      Sep24 ?        00:00:15 /usr/lib/systemd/systemd-journald
4 S root       282     1  0  80   0 -  1481 ?      Sep24 ?        00:00:00 /usr/lib/systemd/systemd-udevd
4 S message+   595     1  0  80   0 -   989 ?      Sep24 ?        00:01:04 /bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-ac
4 S root       645     1  0  80   0 -   859 ?      Sep24 ?        00:00:07 /usr/lib/systemd/systemd-logind
#5

Eehh, is dit systeem geupgrade van 11.4 naar 12.3? Begrijp ik dat goed? Dat zou nl. veel verklaren.

#6

Nee, het is een nieuwe doos. 100% nieuwe hardware.
Ik heb een lijst gemaakt van de geïnstalleerde packages op de oude machine en die op de nieuwe machine geïnstalleerd (met uitzondering van de -32bit versies)

#7

En wat geeft deze bij jou?

systemctl status syslogd.service

? Bij mij komen “dependency” fouten niet voor in journalctl. Dat betekent dat systemd een service wil starten, en die service wil dat er eerst andere services draaien, waaraan blijkbaar niet voldaan wordt. Wat mij betreft moet dat eerst opgelost worden, voordat de output van “blame” goed op waarde geschat kan worden. Die tijden lijden onder de zware belasting van het systeem. Ook niks te vinden in /var/log/messages?

#8 
# systemctl status syslogd.service
syslogd.service - System Logging Service
          Loaded: loaded (/usr/lib/systemd/system/syslogd.service; enabled)
          Active: failed (Result: start-limit) since Fri, 2013-09-27 07:49:46 CEST; 7s ago
         Process: 11197 ExecStart=/usr/sbin/syslogd $ADDITIONAL_SOCKET (code=exited, status=1/FAILURE)
         Process: 11193 ExecStartPre=/usr/sbin/syslogd-service-prepare (code=exited, status=0/SUCCESS)
          CGroup: name=systemd:/system/syslogd.service

Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
Sep 27 07:49:53 tux systemd[1]: Starting System Logging Service...
# locate syslogd.service
/etc/systemd/system/multi-user.target.wants/syslogd.service
/usr/lib/systemd/system/syslogd.service
# rpm -qf /usr/lib/systemd/system/syslogd.service
syslogd-1.4.1-768.2.1.x86_64
#

Op mijn laptop (OpenSUSE 12.3) en mijn werk-PC (OpenSUSE 12.2):

# systemctl status syslogd.service
syslogd.service
          Loaded: error (Reason: No such file or directory)
          Active: inactive (dead)
# locate syslogd.service
#

Op /var/log zie ik iets nog veel verontrustenders:

# ls -lrt
:
:
drwxr-xr-x 2 root      root         4096 Sep 11 10:07 ConsoleKit
drwxrwxr-x 3 root      lp           4096 Sep 12 16:59 hp
drwx------ 2 root      root         4096 Sep 13 11:57 krb5
-rw-rw-rw- 1 root      root          643 Sep 15 16:46 rc.dhcpd.log
drwxr-x--- 3 root      root         4096 Sep 17 15:45 apache2
drwx------ 2 root      root         4096 Sep 21 11:39 YaST2
-rw-r--r-- 1 root      root        48467 Sep 21 11:40 alternatives.log
-rw-r--r-- 1 root      root          192 Sep 22 09:17 fs-errors
-rw-r--r-- 1 root      root        42099 Sep 22 09:17 boot.log
-rw-r--r-- 1 root      root         2001 Sep 22 15:17 ntp
-rw-r--r-- 1 root      root            0 Sep 22 15:18 pm-powersave.log
-rw-r--r-- 1 root      root        41262 Sep 22 15:18 Xorg.0.log
drwxrwxrwx 3 root      root         4096 Sep 22 20:21 journal
-rw-r----- 1 root      root       350972 Sep 22 20:40 zypper.log-20130923.xz
-rw-r--r-- 1 root      root       292876 Sep 23 22:09 lastlog
-rw-r--r-- 1 root      root        36832 Sep 24 00:09 kdm.log
-rw-rw-r-- 1 root      utmp        52608 Sep 24 00:14 wtmp
-rw------- 1 root      root         6956 Sep 24 14:49 btmp-20130924.xz
-rw-r----- 1 root      root     10817956 Sep 26 12:13 pk_backend_zypp
-rw-r----- 1 root      root      4869392 Sep 26 14:30 zypper.log
-rw------- 1 root      root       452736 Sep 27 06:34 btmp
#

Daar missen heel wat “actuele” bestanden :frowning:
Op mijn laptop gaat dat wel goed:

# ls -lrt
:
:
-rw-r----- 1 root     root      186924 Sep 19 21:14 messages-20130919.xz
-rw-r--r-- 1 root     root       48775 Sep 23 22:37 Xorg.0.log.old
-rw-rw-rw- 1 root     root         237 Sep 24 00:11 iked.log
-rw-r--r-- 1 root     root       11818 Sep 24 00:11 boot.log
-rw-r--r-- 1 root     root      617965 Sep 24 00:12 kdm.log
-rw-r----- 1 root     root     2226661 Sep 24 00:14 localmessages
-rw-r--r-- 1 root     root           0 Sep 24 00:14 pm-powersave.log
-rw-r----- 1 root     root       26401 Sep 24 10:50 acpid
-rw-r--r-- 1 root     root       12662 Sep 24 19:26 pm-suspend.log
-rw-r--r-- 1 root     root       48030 Sep 24 19:26 Xorg.0.log
-rw-r--r-- 1 root     root      616448 Sep 24 19:28 ntp
-rw-r----- 1 root     root      232284 Sep 24 21:13 messages-20130924.xz
-rw-r----- 1 root     root      530852 Sep 25 09:01 snapper.log
-rw-r----- 1 root     root     9308899 Sep 25 09:09 zypper.log
-rw-r----- 1 root     root      267283 Sep 27 02:28 warn
-rw-r----- 1 root     root      213890 Sep 27 04:10 mail.info
-rw-r----- 1 root     root      216243 Sep 27 04:10 mail
-rw-r----- 1 root     root     2422962 Sep 27 07:36 NetworkManager
-rw-r----- 1 root     root      102073 Sep 27 07:51 messages
-rw-rw-r-- 1 root     utmp      279552 Sep 27 07:51 wtmp
-rw-r--r-- 1 root     root      293168 Sep 27 07:51 lastlog
#

Het syslogd package is op geen van mijn andere machines geïnstalleerd. Die ga ik nu verwijderen …

# zypper rm syslogd
Loading repository data...
Reading installed packages...
Resolving package dependencies...

The following NEW package is going to be installed:
  syslog-ng

The following package is going to be REMOVED:
  syslogd

1 new package to install, 1 to remove.
Overall download size: 628.5 KiB. After the operation, additional 2.4 MiB will be used.
Continue? [y/n/p/?] (y):
Retrieving package syslog-ng-3.4.2-1.5.1.x86_64                                                                                                                    (1/1), 628.5 KiB (  2.4 MiB unpacked)
Retrieving: syslog-ng-3.4.2-1.5.1.x86_64.rpm .......................................................................................................................................[done (895.7 KiB/s)]
(1/2) Removing syslogd-1.4.1-768.2.1 .............................................................................................................................................................[done]
(2/2) Installing: syslog-ng-3.4.2-1.5.1 ..........................................................................................................................................................[done]
Additional rpm output:
Updating /etc/sysconfig/syslog...
#

Beide entries in top zijn nu weg en de load valt weer terug naar acceptabele niveaus.
Ga maar even rebooten denk ik :):shame:
Dank voor de hints

#9

Ik denk ook dat dat 'm is. Heb nu even geen tijd voor uitgebreide zoekacties, maar ik denk dat je daarbij wel ergens iets zou tegenkomen over een switch van syslogd naar syslog-ng . Mooi dat 't allemaal “back to normal” lijkt / is.