[opensuse] systemd causing CPU to heat up
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 TOP output:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 1 root 20 0 49096 6412 2060 R 99,3 0,1 30:33.40 systemd 309 root 20 0 332m 26m 24m S 31,9 0,3 11:18.56 systemd-journal
Telcontar:/etc/postfix # sensors coretemp-isa-0000 Adapter: ISA adapter Core 0: +68.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC) Core 1: +58.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC) Core 2: +67.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC) Core 3: +64.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC) And the fans speed up to compensate, for the last hour or so. - -- Cheers / Saludos, Carlos E. R. (from 12.3 x86_64 "Dartmouth" at Telcontar) -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.19 (GNU/Linux) Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ iEYEARECAAYFAlG1AMQACgkQIvFNjefEBxrHXQCdHfe8+C9GVTam/TwrR0CIkTnT y78AoJFa05hEOyWyogupkq2lUdrzhFub =AO45 -----END PGP SIGNATURE----- -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
El 09/06/13 18:25, Carlos E. R. escribió:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
TOP output:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 1 root 20 0 49096 6412 2060 R 99,3 0,1 30:33.40 systemd 309 root 20 0 332m 26m 24m S 31,9 0,3 11:18.56 systemd-journal
Telcontar:/etc/postfix # sensors coretemp-isa-0000 Adapter: ISA adapter Core 0: +68.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC) Core 1: +58.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC) Core 2: +67.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC) Core 3: +64.0ᄚC (high = +74.0ᄚC, crit = +100.0ᄚC)
And the fans speed up to compensate, for the last hour or so.
Let's see.. your post is not helpful, let's make it useful. 1. what exact systemd version are you using in which distribution and arch ? 2. attach strace to PID1 as root and post the details on what exactly systemd is burning CPU cycles. -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
On 2013-06-10 00:29, Cristian Rodríguez wrote:
El 09/06/13 18:25, Carlos E. R. escribió:
1. what exact systemd version are you using in which distribution and arch ?
Distribution is on the signature, and systemd is whatever the distribution has, ie, 12.3 and systemd-195-13.25.1.x86_64 Systemd was restarting continuously rsyslog, and logging it somewhere. Where? No idea (yet). This activity caused cpu to go 100% on one core. I had to halt, wait, boot, to let the engine cool down. Apparently, rsyslog does not like this line in rsyslog config:
if (syslogfacility isequal 10) and ($msg contains 'changing to') and ($msg contains 'hat: Operation not permitted' ) then ~
There is no complain: Telcontar:~ # systemctl restart rsyslog.service # with line active Telcontar:~ # systemctl restart rsyslog.service # with line com.out. Telcontar:~ # but later it fails - it is in the syslog:
<5.6> 2013-06-10 00:46:04 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="1448" x-info="http://www.rsyslog.com"] exiting on signal 15. <5.6> 2013-06-10 00:46:54 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="8282" x-info="http://www.rsyslog.com"] start <3.6> 2013-06-10 00:46:54 Telcontar systemd 1 - - Stopping System Logging Service... <3.6> 2013-06-10 00:46:54 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 00:46:54 Telcontar systemd 1 - - Started System Logging Service. <3.5> 2013-06-10 00:46:54 Telcontar systemd 1 - - rsyslog.service: main process exited, code=exited, status=1/FAILURE <3.5> 2013-06-10 00:46:54 Telcontar systemd 1 - - Unit rsyslog.service entered failed state <3.6> 2013-06-10 00:46:54 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 00:46:54 Telcontar systemd 1 - - Started System Logging Service. <3.5> 2013-06-10 00:46:54 Telcontar systemd 1 - - rsyslog.service: main process exited, code=exited, status=1/FAILURE <3.5> 2013-06-10 00:46:54 Telcontar systemd 1 - - Unit rsyslog.service entered failed state <3.6> 2013-06-10 00:46:54 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 00:46:54 Telcontar systemd 1 - - Started System Logging Service. <5.6> 2013-06-10 00:46:57 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="8282" x-info="http://www.rsyslog.com"] exiting on signal 15. <5.6> 2013-06-10 00:46:57 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="8295" x-info="http://www.rsyslog.com"] start <3.6> 2013-06-10 00:46:57 Telcontar systemd 1 - - Stopping System Logging Service... <3.6> 2013-06-10 00:46:57 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 00:46:57 Telcontar systemd 1 - - Started System Logging Service. <3.6> 2013-06-10 00:47:39 Telcontar systemd 1 - - Starting Cleanup of Temporary Directories... <3.3> 2013-06-10 00:47:40 Telcontar systemd-tmpfiles 8313 - - stat(/run/user/1000/gvfs) failed: Permission denied <3.6> 2013-06-10 00:47:40 Telcontar systemd 1 - - Started Cleanup of Temporary Directories. <10.3> 2013-06-10 00:48:01 Telcontar 8320 - - pam_apparmor(crond:session): Unknown error occurred changing to news hat: Operation not permitted <0.5> 2013-06-10 00:48:01 Telcontar kernel - - - [ 921.273824] type=1400 audit(1370818081.268:51): apparmor="DENIED" operation="change_hat" info="unconfined" error=-1 pid=8320 comm="cron"
I commented out that line and restarted the service. CPU is cool again. This is caused by restarting (respawining?) too fast a process that insists in failing, instead of throttling. I have been out of commision quarter of an hour longer than needed because network is not started automatically on boot. I had to restart the service manually (!), and this caused XFCE to burp on session start, too. -- Cheers / Saludos, Carlos E. R. (from 12.3 x86_64 "Dartmouth" at Telcontar) -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
El 09/06/13 18:58, Carlos E. R. escribió:
This is caused by restarting (respawining?) too fast a process that insists in failing, instead of throttling.
Tried to reproduce your problem in Factory Copy and pasted the relevant rsyslog configuration that fails, issued service restart Jun 09 19:21:50 linux-cufi systemd[1]: Starting System Logging Service... Jun 09 19:21:50 linux-cufi systemd[1]: Started System Logging Service. Jun 09 19:21:50 linux-cufi systemd[1]: rsyslog.service: main process exited, code=exited, status=1/FAILURE Jun 09 19:21:50 linux-cufi systemd[1]: Unit rsyslog.service entered failed state. Jun 09 19:21:50 linux-cufi systemd[1]: Starting System Logging Service... Jun 09 19:21:50 linux-cufi systemd[1]: rsyslog.service start request repeated too quickly, refusing to start. Jun 09 19:21:50 linux-cufi systemd[1]: Failed to start System Logging Service. Relevant line: "Jun 09 19:21:50 linux-cufi systemd[1]: rsyslog.service start request repeated too quickly, refusing to start." No CPU running wild, no process using 99% of CPU, no accessory heater for this particularly cold autumn ;-) Whatever your problem is, it is already fixed. -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On 2013-06-10 01:28, Cristian Rodríguez wrote:
El 09/06/13 18:58, Carlos E. R. escribió:
Relevant line:
"Jun 09 19:21:50 linux-cufi systemd[1]: rsyslog.service start request repeated too quickly, refusing to start."
That's what happened earlier, but it is not happening now. Mine is not looping fast enough for systemd to think it is looping.
No CPU running wild, no process using 99% of CPU, no accessory heater for this particularly cold autumn ;-)
Whatever your problem is, it is already fixed.
No, it is not, it is reproducible here.
Telcontar:~ # systemctl restart rsyslog.service Telcontar:~ #
Telcontar:~ # systemctl status rsyslog.service rsyslog.service - System Logging Service Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled) Active: failed (Result: start-limit) since Mon, 2013-06-10 02:07:29 CEST; 11ms ago Process: 9102 ExecStart=/usr/sbin/rsyslogd -n $RSYSLOGD_PARAMS (code=exited, status=1/FAILURE) Process: 9098 ExecStartPre=/usr/sbin/rsyslog-service-prepare (code=exited, status=0/SUCCESS) CGroup: name=systemd:/system/rsyslog.service
Jun 10 02:07:29 Telcontar.valinor systemd[1]: Failed to start System Logging Service. Jun 10 02:07:29 Telcontar.valinor systemd[1]: Starting System Logging Service... Jun 10 02:07:29 Telcontar.valinor systemd[1]: Failed to start System Logging Service. Jun 10 02:07:29 Telcontar.valinor systemd[1]: Starting System Logging Service... Jun 10 02:07:29 Telcontar.valinor systemd[1]: Failed to start System Logging Service. Jun 10 02:07:29 Telcontar.valinor systemd[1]: Starting System Logging Service... Jun 10 02:07:29 Telcontar.valinor systemd[1]: Failed to start System Logging Service. Jun 10 02:07:29 Telcontar.valinor systemd[1]: Starting System Logging Service... Jun 10 02:07:29 Telcontar.valinor systemd[1]: Starting System Logging Service... Jun 10 02:07:29 Telcontar.valinor systemd[1]: Starting System Logging Service... Jun 10 02:07:29 Telcontar.valinor systemd[1]: Starting System Logging Service... Telcontar:~ #
top - 02:07:52 up 18 min, 17 users, load average: 1,02, 0,82, 0,57 Tasks: 274 total, 3 running, 271 sleeping, 0 stopped, 0 zombie %Cpu(s): 28,5 us, 9,9 sy, 0,0 ni, 61,6 id, 0,0 wa, 0,0 hi, 0,0 si, 0,0 st KiB Mem: 8193808 total, 4126528 used, 4067280 free, 35464 buffers KiB Swap: 22017008 total, 0 used, 22017008 free, 1374696 cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 1 root 20 0 48808 6332 2156 R 99,4 0,1 0:43.67 systemd 312 root 20 0 310m 12m 12m S 33,6 0,2 0:16.31 systemd-journal 8074 root 20 0 179m 58m 12m S 6,6 0,7 0:16.60 Xorg 8214 cer 20 0 2140m 1,3g 45m S 4,7 17,2 0:49.52 thunderbird-bin
Edit out the line in another terminal.
Telcontar:~ # systemctl restart rsyslog.service Telcontar:~ # systemctl status rsyslog.service rsyslog.service - System Logging Service Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled) Active: active (running) since Mon, 2013-06-10 02:08:21 CEST; 11s ago Process: 9283 ExecStartPre=/usr/sbin/rsyslog-service-prepare (code=exited, status=0/SUCCESS) Main PID: 9287 (rsyslogd) CGroup: name=systemd:/system/rsyslog.service └ 9287 /usr/sbin/rsyslogd -n
Jun 10 02:08:21 Telcontar.valinor systemd[1]: Started System Logging Service. Telcontar:~ #
top - 02:08:55 up 19 min, 17 users, load average: 0,84, 0,82, 0,59 Tasks: 274 total, 2 running, 272 sleeping, 0 stopped, 0 zombie %Cpu(s): 3,1 us, 1,3 sy, 0,0 ni, 95,6 id, 0,0 wa, 0,0 hi, 0,0 si, 0,0 st KiB Mem: 8193808 total, 4167664 used, 4026144 free, 36068 buffers KiB Swap: 22017008 total, 0 used, 22017008 free, 1387096 cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 8074 root 20 0 179m 58m 12m S 5,7 0,7 0:18.48 Xorg 8214 cer 20 0 2140m 1,4g 45m S 4,7 17,6 0:52.59 thunderbird-bin 8591 cer 20 0 395m 14m 6152 S 3,0 0,2 0:08.98 tracker-store 8212 cer 20 0 482m 20m 14m S 1,0 0,3 0:00.69 xfce4-terminal 8213 cer 20 0 1180m 417m 49m S 1,0 5,2 0:25.91 firefox 8974 cer 20 0 9956 1608 1060 R 0,7 0,0 0:00.31 top <10.3> 2013-06-10 02:06:24 Telcontar su - - - pam_apparmor(su-l:session): Unknown error occurred changing to root hat: Operation not permitted <5.6> 2013-06-10 02:07:09 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="1408" x-info="http://www.rsyslog.com"] exiting on signal 15. <5.6> 2013-06-10 02:08:19 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="9274" x-info="http://www.rsyslog.com"] start <3.6> 2013-06-10 02:08:19 Telcontar systemd 1 - - Stopping System Logging Service... <3.6> 2013-06-10 02:08:19 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 02:08:19 Telcontar systemd 1 - - Started System Logging Service. <3.5> 2013-06-10 02:08:19 Telcontar systemd 1 - - rsyslog.service: main process exited, code=exited, status=1/FAILURE <3.5> 2013-06-10 02:08:19 Telcontar systemd 1 - - Unit rsyslog.service entered failed state <3.6> 2013-06-10 02:08:19 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 02:08:19 Telcontar systemd 1 - - Started System Logging Service. <3.5> 2013-06-10 02:08:19 Telcontar systemd 1 - - rsyslog.service: main process exited, code=exited, status=1/FAILURE <3.5> 2013-06-10 02:08:19 Telcontar systemd 1 - - Unit rsyslog.service entered failed state <3.6> 2013-06-10 02:08:19 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 02:08:19 Telcontar systemd 1 - - Started System Logging Service. <0.5> 2013-06-10 02:08:19 Telcontar kernel - - - [ 1094.111486] type=1400 audit(1370822881.103:55): apparmor="DENIED" operation="change_hat" info="unconfined" error=-1 pid=9223 comm="cron" <3.6> 2013-06-10 02:08:21 Telcontar systemd 1 - - Stopping System Logging Service... <5.6> 2013-06-10 02:08:21 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="9274" x-info="http://www.rsyslog.com"] exiting on signal 15. <5.6> 2013-06-10 02:08:21 Telcontar rsyslogd - - - [origin software="rsyslogd" swVersion="7.2.7" x-pid="9287" x-info="http://www.rsyslog.com"] start <3.6> 2013-06-10 02:08:21 Telcontar systemd 1 - - Starting System Logging Service... <3.6> 2013-06-10 02:08:21 Telcontar systemd 1 - - Started System Logging Service.
I have many more problems... I can not switch to the text terminals, neither by keyboard or chvt 1 which hangs. I had to remove plymouth to solve that. Network is not starting on boot; a service restart and it runs happily, but for that I have to wait 3 minutes before I can get to a terminal. This wait causes the prompt for encrypted partition pass to fail, does not appear. Terminal 1 does not work. Login and pass lines are in one line. First pass char and it asks for login again. Terminal 2, once it starts, works fine. Graphics go to VT8, not 7 (started via init 5) - -- Cheers / Saludos, Carlos E. R. (from 12.3 x86_64 "Dartmouth" at Telcontar) -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.19 (GNU/Linux) Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ iEYEARECAAYFAlG1G2gACgkQIvFNjefEBxoZCwCfcvX3l1WnOuRzZFdH6jnrDygd Z9sAnAv3j3WHkABKaKa+CW1kqyAEOBxz =rcr2 -----END PGP SIGNATURE----- -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
El 09/06/13 20:18, Carlos E. R. escribió:
That's what happened earlier, but it is not happening now. Mine is not looping fast enough for systemd to think it is looping.
Ok, how exactly did you proceed ? I did exactly what you mentioned in your email and get the expected result.
No CPU running wild, no process using 99% of CPU, no accessory heater for this particularly cold autumn ;-)
Whatever your problem is, it is already fixed.
No, it is not, it is reproducible here.
Telcontar:~ # systemctl restart rsyslog.service Telcontar:~ #
Telcontar:~ # systemctl status rsyslog.service rsyslog.service -
show your unit file ;) it should read: cat /usr/lib/systemd/system/rsyslog.service [Unit] Description=System Logging Service Requires=var-run.mount Requires=syslog.socket After=var-run.mount [Service] Environment=RSYSLOGD_PARAMS= ExecStartPre=/usr/sbin/rsyslog-service-prepare EnvironmentFile=-/etc/sysconfig/syslog ExecStart=/usr/sbin/rsyslogd -n $RSYSLOGD_PARAMS ExecReload=/bin/kill -HUP $MAINPID StandardOutput=null [Install] WantedBy=multi-user.target Alias=syslog.service If it doesnt read this way, save it as /etc/systemd/system/rsyslog.service and issue # systemctl daemon-reload # systemctl reenable rsyslog.service -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
On 2013-06-10 02:23, Cristian Rodríguez wrote:
El 09/06/13 20:18, Carlos E. R. escribió:
That's what happened earlier, but it is not happening now. Mine is not looping fast enough for systemd to think it is looping.
Ok, how exactly did you proceed ? I did exactly what you mentioned in your email and get the expected result.
I edited in that line, restarted service, bang. Just like that. The file has more entries, of course, but that's the one that causes the problem.
Telcontar:~ # systemctl restart rsyslog.service Telcontar:~ #
Telcontar:~ # systemctl status rsyslog.service rsyslog.service -
show your unit file ;)
it should read:
cat /usr/lib/systemd/system/rsyslog.service
[Unit] Description=System Logging Service Requires=var-run.mount Requires=syslog.socket After=var-run.mount
[Service] Environment=RSYSLOGD_PARAMS= ExecStartPre=/usr/sbin/rsyslog-service-prepare EnvironmentFile=-/etc/sysconfig/syslog ExecStart=/usr/sbin/rsyslogd -n $RSYSLOGD_PARAMS ExecReload=/bin/kill -HUP $MAINPID StandardOutput=null
[Install] WantedBy=multi-user.target Alias=syslog.service
If it doesnt read this way, save it as /etc/systemd/system/rsyslog.service and issue
# systemctl daemon-reload # systemctl reenable rsyslog.service
I have not touched it. i see differences, but I swear I have not touched it myself.
cer@Telcontar:~> l /usr/lib/systemd/system/rsyslog.service -rw-r--r-- 1 root root 475 Apr 29 17:37 /usr/lib/systemd/system/rsyslog.service cer@Telcontar:~> cat /usr/lib/systemd/system/rsyslog.service [Unit] Description=System Logging Service Requires=var-run.mount syslog.target After=var-run.mount Before=syslog.target Conflicts=syslog-ng.service syslogd.service
[Service] Environment=RSYSLOGD_PARAMS= ExecStartPre=/usr/sbin/rsyslog-service-prepare EnvironmentFile=-/etc/sysconfig/syslog ExecStart=/usr/sbin/rsyslogd -n $RSYSLOGD_PARAMS ExecReload=/bin/kill -HUP $MAINPID Sockets=syslog.socket StandardOutput=null
[Install] WantedBy=multi-user.target Alias=syslog.service cer@Telcontar:~>
I can provoke the failure and get output from some log or command showing whatever is the problem, or hook a trace to it. -- Cheers / Saludos, Carlos E. R. (from 12.3 x86_64 "Dartmouth" at Telcontar) -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
On 06/09/2013 08:42 PM, Carlos E. R. wrote:
I have not touched it. i see differences, but I swear I have not touched it myself.
Yes, that no surprise since I provided to you a new version of the relevant unit file, one that is correct ;) -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On 2013-06-10 06:30, Cristian Rodríguez wrote:
On 06/09/2013 08:42 PM, Carlos E. R. wrote:
I have not touched it. i see differences, but I swear I have not touched it myself.
Yes, that no surprise since I provided to you a new version of the relevant unit file, one that is correct ;)
Then, the version I have, which is supplied by openSUSE, is bad? Is there a bugzilla for that? Telcontar:~ # rpm -qf /usr/lib/systemd/system/rsyslog.service rsyslog-7.2.7-2.5.1.x86_64 Telcontar:~ # rpm -V rsyslog S.5....T. c /etc/rsyslog.conf Telcontar:~ # rpm -qi rsyslog Name : rsyslog ... Packager : http://bugs.opensuse.org Vendor : openSUSE <<==== - -- Cheers / Saludos, Carlos E. R. (from 12.3 x86_64 "Dartmouth" at Telcontar) -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.19 (GNU/Linux) Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ iEYEARECAAYFAlG1zBQACgkQIvFNjefEBxpdGQCdGYDBoAA+Kny2o+U15U8xqwBK VDwAn2RyIqKmJ6O3S3RpFS8RabnFaoyE =YMph -----END PGP SIGNATURE----- -- To unsubscribe, e-mail: opensuse+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse+owner@opensuse.org
participants (2)
-
Carlos E. R.
-
Cristian Rodríguez