kernel.log Filling up...

mrunion · 2009-11-05 15:26:58

When I am rendering using the Lux Renderer (0.6 version -- the latest), the kernel log and message.log are filling up with repeated messages about the CPU temp being above the limit, then being OK. I have rendered for about 4 hours and the logs are 8.8GB and 2.6 GB respectively! These messages flood in at a rate of 10-20 or more per second.

Is this a bug with the kernel message logging? I found this, but do not know if it's related:
https://bugs.launchpad.net/ubuntu/karmi … bug/453444

ruffedgz · 2009-11-05 15:38:13

I'm kind of curious about the /etc/syslog-ng.conf file. Can you display that output just to make sure.

Thanks!

mrunion · 2009-11-05 18:55:29

Here is what the /etc/syslog-ng.conf file looks like:

@version: 3.0
#
# /etc/syslog-ng.conf
#

options {
  stats_freq (0);
  flush_lines (0);
  time_reopen (10);
  log_fifo_size (1000);
  long_hostnames(off); 
  use_dns (no);
  use_fqdn (no);
  create_dirs (no);
  keep_hostname (yes);
  perm(0640);
  group("log");
};

source src {
  unix-stream("/dev/log");
  internal();
  file("/proc/kmsg");
};

destination d_authlog { file("/var/log/auth.log"); };
destination d_syslog { file("/var/log/syslog.log"); };
destination d_cron { file("/var/log/crond.log"); };
destination d_daemon { file("/var/log/daemon.log"); };
destination d_kernel { file("/var/log/kernel.log"); };
destination d_lpr { file("/var/log/lpr.log"); };
destination d_user { file("/var/log/user.log"); };
destination d_uucp { file("/var/log/uucp.log"); };
destination d_mail { file("/var/log/mail.log"); };
destination d_news { file("/var/log/news.log"); };
destination d_ppp { file("/var/log/ppp.log"); };
destination d_debug { file("/var/log/debug.log"); };
destination d_messages { file("/var/log/messages.log"); };
destination d_errors { file("/var/log/errors.log"); };
destination d_everything { file("/var/log/everything.log"); };
destination d_iptables { file("/var/log/iptables.log"); };
destination d_acpid { file("/var/log/acpid.log"); };
destination d_console { usertty("root"); };

# Log everything to tty12
destination console_all { file("/dev/tty12"); };

filter f_auth { facility(auth); };
filter f_authpriv { facility(auth, authpriv); };
filter f_syslog { program(syslog-ng); };
filter f_cron { facility(cron); };
filter f_daemon { facility(daemon); };
filter f_kernel { facility(kern) and not filter(f_iptables); };
filter f_lpr { facility(lpr); };
filter f_mail { facility(mail); };
filter f_news { facility(news); };
filter f_user { facility(user); };
filter f_uucp { facility(cron); };
filter f_news { facility(news); };
filter f_ppp { facility(local2); };
filter f_debug { not facility(auth, authpriv, news, mail); };
filter f_messages { level(info..warn) and not facility(auth, authpriv, mail, news, cron) and not program(syslog-ng) and not filter(f_iptables); };
filter f_everything { level(debug..emerg) and not facility(auth, authpriv); };
filter f_emergency { level(emerg); };
filter f_info { level(info); };
filter f_notice { level(notice); };
filter f_warn { level(warn); };
filter f_crit { level(crit); };
filter f_err { level(err); };
filter f_iptables { match("IN=" value("MESSAGE")) and match("OUT=" value("MESSAGE")); };
filter f_acpid { program("acpid"); };

log { source(src); filter(f_acpid); destination(d_acpid); };
log { source(src); filter(f_authpriv); destination(d_authlog); };
log { source(src); filter(f_syslog); destination(d_syslog); };
log { source(src); filter(f_cron); destination(d_cron); };
log { source(src); filter(f_daemon); destination(d_daemon); };
log { source(src); filter(f_kernel); destination(d_kernel); };
log { source(src); filter(f_lpr); destination(d_lpr); };
log { source(src); filter(f_mail); destination(d_mail); };
log { source(src); filter(f_news); destination(d_news); };
log { source(src); filter(f_ppp); destination(d_ppp); };
log { source(src); filter(f_user); destination(d_user); };
log { source(src); filter(f_uucp); destination(d_uucp); };
#log { source(src); filter(f_debug); destination(d_debug); };
log { source(src); filter(f_messages); destination(d_messages); };
log { source(src); filter(f_err); destination(d_errors); };
log { source(src); filter(f_emergency); destination(d_console); };
log { source(src); filter(f_everything); destination(d_everything); };
log { source(src); filter(f_iptables); destination(d_iptables); };

# Log everything to tty12
#log { source(src); destination(console_all); };

The messages.log is full of this stuff (with the timestamp changed):

Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal
Nov  5 13:57:24 highvoltage kernel: CPU1: Temperature/speed normal

and kernel.log has:

Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature above threshold, cpu clock throttled (total events = 8026138)
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature above threshold, cpu clock throttled (total events = 8026139)
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature above threshold, cpu clock throttled (total events = 8026140)
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature/speed normal
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature above threshold, cpu clock throttled (total events = 8026141)
Nov  5 13:57:46 highvoltage kernel: CPU0: Temperature/speed normal

Last edited by mrunion (2009-11-05 19:00:00)

ruffedgz · 2009-11-05 22:34:54

So everything looks default on the /etc/syslog-ng file so lets look at the /etc/logrotate.conf file and see if you have /etc/cron.daily/logrotate

If you see a commented out section:

# restrict maximum size of log files
#size 20M

See if you can uncomment that and change it to a reasonable size like 500 MB or whatever you want to help with the rotating of the logs.

I see this as a real problem with the applications "Lux Renderer" and if you don't mind getting logs for it, you might want to change something within /etc/syslog-ng.conf file to do that (if you want to do that, I can see what I can come up to make those logs go away).

mrunion · 2009-11-06 03:18:30

Cool. This is on my laptop at work, so I will check in the AM. The LuxRender itself is not a "problem" -- but since it's a true light-modelling renderer, it's processor intensive, thus making my processor works it's "bits" off! That in turn is getting logged all over the place. Thus the problem. Again, I'll chec on this in the AM at work -- and many thanks for your assistance!

llcawthorne · 2009-11-09 20:30:09

I had this same problem. I couldn't find a solid solution, so started tinker. I originally thought it would be linked to coretemp, but that wasn't the case. Apparently, tsenshe 'thermal' module apparently spawns the messages. While I know that I should blow some dust out of my case and get my temps down, I found that 'rmmod thermal' would stop the messages until I get around to doing it.

While I understand that overheating can be a serious problem, I do think 16G of messages in a short day or two period that I didn't notice it filling my logs is a tad bit excessive. I suppose its better than a broken chip if I had been suffering severe overheating, but my BIOS settings should shut me down before it got too out of hand. The module seems a bit more restrictive than I am, but perhaps I should re-read materials on how hard I can press this processor (and blow the dust out of my case).

llcawthorne · 2009-11-10 17:01:30

I've looked into this a bit more. My research was cluttered a bit by the fact that they changed the way of doing things in 2007 and lots of what I found predated that. I really should look at how to use google to sort stuff out by date or what not, but that is not important to this issue.

The thermal module has modes that seem to influence its trippoints.

'act=C' sets the active trippoint (where C is a number of degrees Celsius)
'crt=C' sets the critical trip point
'psv=C' sets the passive trip point

There are some others too, and you can 'modinfo thermal' to see them with short descriptions.

I edited /etc/modprobe.d/modprobe.conf and put in the following:
'options thermal psv=85 act=90 crt=100'

I haven't seen any errors this morning in my log's while I was gone to school, so I believe it is working alright. I'll reboot and give it a try.
[I doubt I want to run at these temperatures 24 hours a day though, so I will probably cut down to one folding client, so that I only break 70 if I am doing something intensive and then only temporarily].

I am having trouble figuring out what lm_sensors refers to as my cpu_high and crit though. In /etc/sensors3.conf I have made an entry for the appropriate atk0110-acpi source and can change the label with temp1_label, but temp1_high and temp1_crit and temp1_max and temp1_over don't have any effect on the display. I would prefer my sensors reading when I type 'sensors' to recognize roughly the same values that my module does, but it isn't a priority, and I may get back to looking at it later.

Last edited by llcawthorne (2009-11-10 18:12:55)

llcawthorne · 2009-11-10 19:24:41

Started getting some errors again after reboot. Removed the thermal module, the coretemp module, the asus_ath0110 module, and stopped sensors and they went away. Of course, that also disabled me being able to get a sensor reading of what the chip was running at, and I don't particularly like knowing that I am near the edge of my hardwares capabilities but not knowing how close. I checked my logs and I was while I was doing all those calculations over the past day or two with thermal info turned off, I managed to generate a machine check exception. Only one, but that is one more than I would like to see.

Apparently, it looks like kernel devs are aware of the "message storm" and have a patch coming down the pipe that will make it log these events no more than once every five minutes.

http://osdir.com/ml/linux-kernel/2009-09/msg08569.html

This handles what I am after, so I don't think I'll be looking at this anymore. I am quite fine with the PC cutting back before I break it if I push it too hard, and would prefer it to log the event. I just don't want to fill up my var partition.

For now, I think I'll just fold with one client. I can't imagine how I would engage all 8 (4 hyperthreaded) cores at 100% for a significant amount of time in order to make my temp's redline withing folding twice, although I am sure I will find a way; hopefully after a patch is in place to stop me from having to clean out my var partition (which is really only a minor inconvenience; i do hate having to delete logs instead of rotate them though, but even with 4TB I definitely don't have a place to store 16G's of logs per day).

mrunion · 2009-11-11 00:47:28

Excellent! Thanks for the info!

Arch Linux

#1 2009-11-05 15:26:58

kernel.log Filling up...

#2 2009-11-05 15:38:13

Re: kernel.log Filling up...

#3 2009-11-05 18:55:29

Re: kernel.log Filling up...

#4 2009-11-05 22:34:54

Re: kernel.log Filling up...

#5 2009-11-06 03:18:30

Re: kernel.log Filling up...

#6 2009-11-09 20:30:09

Re: kernel.log Filling up...

#7 2009-11-10 17:01:30

Re: kernel.log Filling up...

#8 2009-11-10 19:24:41

Re: kernel.log Filling up...

#9 2009-11-11 00:47:28

Re: kernel.log Filling up...

Board footer