Friday, 25 January 2013

(Serial) console flooded with kernel messages?

(If you want to ignore the explanations and see how to stop the Linux kernel from flooding the console with low importance messages, go straight to the bottom of the article, is the small bit at end with larger font.)

After connecting to the serial console on my Linksys WRT160NL router I was faced with the problem that the console was flooded with all sorts of messages such as:
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.U DST=178.156.183.255 PROTO=UDP SPT=137 DPT=137 LEN=58
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
ACCEPT IN=br0 OUT=eth1 SRC=a.b.c.d DST=69.171.246.16 PROTO=TCP SPT=3651 DPT=443
DROP IN=eth1 OUT= SRC=X.Y.Z.U DST=178.156.183.255 PROTO=UDP SPT=137 DPT=137 LEN=58
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=178.156.183.146 DST=255.255.255.255 PROTO=UDP SPT=17500 DPT=17500 LEN=120
DROP IN=eth1 OUT= SRC=178.156.183.146 DST=178.156.183.255 PROTO=UDP SPT=17500 DPT=17500 LEN=120
DROP IN=eth1 OUT= SRC=178.156.183.146 DST=255.255.255.255 PROTO=UDP SPT=17500 DPT=17500 LEN=120
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=X.Y.Z.W DST=255.255.255.255 PROTO=UDP SPT=58488 DPT=2008 LEN=26
DROP IN=eth1 OUT= SRC=178.156.177.142 DST=255.255.255.255 PROTO=UDP SPT=17500 DPT=17500 LEN=153
DROP IN=eth1 OUT= SRC=178.156.177.142 DST=255.255.255.255 PROTO=UDP SPT=17500 DPT=17500 LEN=153

The serial console was working, but it was impossible to do anything practical in these conditions. I tried looking on the net for 'linux stop console flooding' and similar terms, but didn't get too far, except the fact the problem was the loglevel.

Here is the explanation of what this means (quote from Documentation/kernel-parameters.txt):

        loglevel=       All Kernel Messages with a loglevel smaller than the
                        console loglevel will be printed to the console. It can
                        also be changed with klogd or other programs. The
                        loglevels are defined as follows:

                        0 (KERN_EMERG)          system is unusable
                        1 (KERN_ALERT)          action must be taken immediately
                        2 (KERN_CRIT)           critical conditions
                        3 (KERN_ERR)            error conditions
                        4 (KERN_WARNING)        warning conditions
                        5 (KERN_NOTICE)         normal but significant condition
                        6 (KERN_INFO)           informational
                        7 (KERN_DEBUG)          debug-level messages


This was enough to go through my local git tree of the kernel in the Documentation directory and grep for loglevel. This brought me to this interesting bit from Documentation/sysctl/kernel.txt
==============================================================

printk:

The four values in printk denote: console_loglevel,
default_message_loglevel, minimum_console_loglevel and
default_console_loglevel respectively.

These values influence printk() behavior when printing or
logging error messages. See 'man 2 syslog' for more info on
the different loglevels.

- console_loglevel: messages with a higher priority than
  this will be printed to the console
- default_message_loglevel: messages without an explicit priority
  will be printed with this priority
- minimum_console_loglevel: minimum (highest) value to which
  console_loglevel can be set
- default_console_loglevel: default value for console_loglevel

==============================================================

So I ran 'cat /proc/sys/kernel/printk' and got (I managed to read it through the flood of messages from the firewall):

7       4       1       7
According to the explanations above, that meant that console_loglevel was too, so to fix it I ran:
echo '2 4 1 7' > /proc/sys/kernel/printk
And, behold, the serial console was usable.

3 comments:

Anonymous said...

I've been there too. There should be an easy to type command line utility that kills the console log temporarily, and has options to turn it back up to a usable value.

it'd fit nicely into util-linux

Bob Proulx said...

You can also change this using the dmesg command. I typically set log level five with: # dmesg -n5

eddyp said...

@joeyh: I agree, but such a tool isn't yet available. 'dmesg -D' is out of the question since I didn't have dmesg at all on that system.

@Bob: This was on a system that didn't even had the dmesg command, so your approach wouldn't have worked, although it would on most systems.