Bug 1744 - systemd consumes 100% of CPU.
: systemd consumes 100% of CPU.
Status: RESOLVED FIXED
Product: Desktop Bugs
Classification: ROSA Desktop
Component: Main Packages
: Fresh
: All Linux
: Normal normal
: ---
Assigned To: ROSA Linux Bugs
: ROSA Linux Bugs
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2013-03-03 17:52 MSK by fvill
Modified: 2013-07-29 10:53 MSD (History)
5 users (show)

See Also:
RPM Package: systemd-194-10-rosa2012.1.x86_64
ISO-related:
Bad POT generating:
Upstream:


Attachments
Part of the strace log for systemd (25.41 KB, text/plain)
2013-03-14 16:31 MSK, Eugene Shatokhin
Details
Part of the strace log for systemd-journald (16.55 KB, text/plain)
2013-03-14 16:40 MSK, Eugene Shatokhin
Details

Note You need to log in before you can comment on or make changes to this bug.
Description fvill 2013-03-03 17:52:31 MSK
systemd and systemd-journal use 100% of CPU.

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                       
    1 root      20   0 39788 4980 2228 R   99  0.1  24:19.72 systemd                                                                                                                                                        
 5647 root      20   0 20.8g 318m 317m R   97  4.0   4:54.67 systemd-journal                                                                                                                                               


Guilty : rsyslog.service and syslog.socket
Mar 03 14:50:32 grenouille.lamare systemd[1]: Failed to start System Logging Service.
Mar 03 14:50:32 grenouille.lamare systemd[1]: rsyslog.service start request repeated too quickly, refusing to start.
Mar 03 14:50:32 grenouille.lamare systemd[1]: Failed to start System Logging Service.
Mar 03 14:50:32 grenouille.lamare systemd[1]: rsyslog.service start request repeated too quickly, refusing to start.
Mar 03 14:50:32 grenouille.lamare systemd[1]: Failed to start System Logging Service.
Mar 03 14:50:32 grenouille.lamare systemd[1]: rsyslog.service start request repeated too quickly, refusing to start.
Mar 03 14:50:32 grenouille.lamare systemd[1]: Failed to start System Logging Service.
Mar 03 14:50:32 grenouille.lamare systemd[1]: Failed to start System Logging Service.
Mar 03 14:50:32 grenouille.lamare systemd[1]: Failed to start System Logging Service.

I had to shutdown syslog.socket to end the loop.
Comment 1 Alexander 2013-03-05 21:30:49 MSK
I have the same issue
Comment 2 Stanislav Fomin 2013-03-07 16:16:20 MSK
Frequently have same issue (different laptops, 64bit/32bit).
IMHO after hibernate/wakeup.
Comment 3 Denis Silakov 2013-03-11 14:58:49 MSK
Seems to be the same as http://bugs.rosalinux.ru/show_bug.cgi?id=1317 fixed not long ago.

Do you use the latest avahi package? And if yes, does it help to disable avahi service?
Comment 4 Alexander 2013-03-11 15:00:27 MSK
systemctl stop avahi-daemon.socket does not helps
Comment 5 Eugene Shatokhin 2013-03-14 16:31:51 MSK
Created attachment 1263 [details]
Part of the strace log for systemd

The problem seems indeed to be related to rsyslog service. Attached is a part of the strace log for systemd collected on one of the systems that is affected by this problem.

The log is full of records like 

sendmsg(12, {msg_name(0)=NULL, msg_iov(9)=[{"PRIORITY=3\nSYSLOG_FACILITY=3\nCOD"..., 170}, {"MESSSAGE_ID=be02cf6855d2428ba40d"..., 44}, {"\n", 1}, {"UNIT=rsyslog.service", 20
}, {"\n", 1}, {"RESULT=failed", 13}, {"\n", 1}, {"MESSAGE=Failed to start System L"..., 47}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 298
Comment 6 Eugene Shatokhin 2013-03-14 16:40:10 MSK
Created attachment 1264 [details]
Part of the strace log for systemd-journald

Attached a part of the strace log for systemd-journald collected when the problem showed up. The rest of the log is similar.
Comment 7 Alexander Burmashev 2013-04-03 16:10:30 MSD
Since our systemd provides it's own journalctl, maybe you could try removing rsyslog, possibly you will need rpm -e --nodeps
Comment 8 Eugene Shatokhin 2013-07-15 17:19:20 MSD
Hit this issue on another system again. Same symptoms.

By the way, Mageia seems to have it too:
https://bugs.mageia.org/show_bug.cgi?id=8028
Comment 9 Eugene Shatokhin 2013-07-15 17:24:14 MSD
(In reply to comment #7)
> Since our systemd provides it's own journalctl, maybe you could try removing
> rsyslog, possibly you will need rpm -e --nodeps

basesystem-minimal requires syslog-daemon which is provided by rsyslog. Not sure if it is safe to just remove it then.
Comment 10 Eugene Shatokhin 2013-07-15 19:22:13 MSD
Well, it looks like rsyslog service failed to start due to a pid file /var/run/rsyslogd.pid still present in the system. It is unclear, why rsyslog left that file behind before.

The daemon (launched as '/sbin/rsyslogd -n -c 4') exits with code 1 in that case.

As suggested in a discussion of a similar issue (https://bugs.freedesktop.org/show_bug.cgi?id=62958), I added "RestartPreventExitStatus=1" to "[Service]" section of /lib/systemd/system/rsyslog.service to prevent systemd from restarting the service if it exits with code 1. 

After a reboot, however, the problem still happens, systemd still tries to restart rsyslog despite it exits with that code. Don't know why yet, need to dig further.
Comment 11 Eugene Shatokhin 2013-07-16 19:36:27 MSD
Well, things are clearer now.

systemd-journald keeps writing to /run/systemd/journal/syslog socket and that makes systemd to try to activate rsyslog.service. Again and again. systemd has rate limiting facilities but they seem not to work until systemd 198.

1.
This is a bug in systemd, probably fixed by this commit:
http://cgit.freedesktop.org/systemd/systemd/commit/?id=464876c9c410b2f5bb997259510a13d0ee7d0af0

The patch looks simple, perhaps we could backport it to our systemd 194.

2.
Apart from that, we can remove that offending pid file (/var/run/rsyslogd.pid) each time before rsyslog.service starts (like we do to avahi-daemon). If that file is left behind by rsyslogd again due to an abnormal termination of the OS or whatever, this will handle it.

Will try to implement all that.
Comment 12 Eugene Shatokhin 2013-07-29 10:53:32 MSD
The updated packages fixing this problem are in our repositories now. Closing.