dmesg – Unix/Linux Command, Beginners Introduction With Examples

‘dmesg’ (display message) is not a popular Unix/Linux command. However, it provides vital information that can be used for troubleshooting production performance problems.

Kernel is the core part of the operating system responsible for the effective functioning of the device. ‘dmesg’ command prints all the kernel-related log messages in the console. It includes messages related to the device driver, OS patching, memory, disk drives, network, etc… Thus, if your application suffers from performance problems, you may use this command to determine whether it’s caused due to any kernel-related problems. Here is how you can invoke this command:

dmesg

When the above command is issued, all the kernel messages which are present in the ring buffer will be printed in the console as shown below:

[    0.000000] Linux version 4.14.203-116.332.amzn1.x86_64 (mockbuild@koji-pdx-corp-builder-60004) (gcc 
version 7.2.1 20170915 (Red Hat 7.2.1-2) (GCC)) #1 SMP Fri Oct 30 18:56:11 UTC 2020
 [    0.000000] Command line: root=LABEL=/ console=tty1 console=ttyS0 selinux=0 
nvme_core.io_timeout=4294967295 [    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' 
[    0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' 
[    0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' 
[    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256 
[    0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. 
[    3.347261] dracut: Mounted root filesystem /dev/nvme0n1p1 [    3.406870] dracut: Switching root 
[    3.638379] random: init: uninitialized urandom read (12 bytes read) 
[    4.182350] udevd[1060]: starting version 173 
[    4.319515] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input4 
[    4.326887] ACPI: Power Button [PWRF] 
[    4.326960] ena 0000:00:05.0: Elastic Network Adapter (ENA) v2.2.10g 
[    4.330604] input: Sleep Button as /devices/LNXSYSTM:00/LNXSLPBN:00/input/input5 
[    4.343523] ACPI: Sleep Button [SLPF] 
[    4.344053] ena: ena device version: 0.10 
[    4.351112] ena: ena controller version: 0.0.1 implementation version 1 
[    4.362656] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input3 
[    4.407341] mousedev: PS/2 mouse device common for all mice 
[    4.428044] ena 0000:00:05.0: LLQ is not supported Fallback to host mode policy. 
[    4.453975] ena 0000:00:05.0: Elastic Network Adapter (ENA) found at mem febf4000, mac addr 02:78:f8:5b:74:0b 
[    5.606395] random: lvm: uninitialized urandom read (4 bytes read) 
[    5.678583] EXT4-fs (nvme0n1p1): re-mounted. Opts: (null) 
[    5.719095] random: dd: uninitialized urandom read (4096 bytes read)
[    5.899359] random: vgs: uninitialized urandom read (4 bytes read) 
[    6.025098] NET: Registered protocol family 10 
[    6.032437] Segment Routing with IPv6 
[    6.249958] netlink: 12 bytes leftover after parsing attributes in process `ip'. 
[    8.597134] urandom_read: 1 callbacks suppressed 
[    8.597135] random: rngd: uninitialized urandom read (16 bytes read) 
[    8.611898] random: crng init done 
[   10.268851] EXT4-fs (nvme0n1p1): resizing filesystem from 2096635 to 15728123 blocks 
[   10.437611] EXT4-fs (nvme0n1p1): resized filesystem to 15728123 
[   49.718881] serial8250: too much work for irq4 
[5206410.490353] nr_pdflush_threads exported in /proc is scheduled for removal 
[7652896.972423] TCP: request_sock_TCP: Possible SYN flooding on port 9010. Sending cookies.  Check SNMP 
counters. 
[11359275.928638] TCP: request_sock_TCP: Possible SYN flooding on port 9010. Sending cookies.  Check SNMP 
counters.

Note: Several of the log messages generated by the dmesg command output may not be clear/understandable for first-time users. You can either take help from experienced System administrators in your organization or post your questions in SRE-focused forums like yCrash answers, Unix Stack Exchange or StackOverflow.

Handling Verbosity: ‘dmesg — — level’

‘dmesg’ command output is quite verbose. It categorizes its log messages into the following levels:

1. LOG_EMERG: system is unusable

2. LOG_ALERT: action must be taken immediately

3. LOG_CRIT: critical conditions

4. LOG_ERR: error conditions

5. LOG_WARNING: warning conditions

6. LOG_NOTICE: normal, but significant, condition

7. LOG_INFO: informational message

8. LOG_DEBUG: debug-level message

Due to the verbosity of the log, it might be impossible to read all the log statements printed by the ‘dmesg’ command. For troubleshooting purposes, it might be enough if you focus only on EMERG, ALERT, CRIT, ERR, WARN level messages. This filtering can be achieved by issuing the following command:

dmesg --level=emerg,alert,crit,err,warn

When above command is issued you can see the output in the console to be minimized to great extent:

[    0.192328] Decoding supported only on Scalable MCA processors. 
[    1.426378] i8042: Warning: Keylock active 
[    1.592193] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11 
[    1.830299] GPT:Primary header thinks Alt. header is not at the end of the disk. 
[    1.837085] GPT:16777215 != 125829119 
[    1.840436] GPT:Alternate GPT header not at the end of the disk. 
[    1.844945] GPT:16777215 != 125829119 
[    1.848325] GPT: Use GNU Parted to correct GPT errors. 
[    4.428044] ena 0000:00:05.0: LLQ is not supported Fallback to host mode policy. 
[    6.249958] netlink: 12 bytes leftover after parsing attributes in process `ip'. 
[    8.597134] urandom_read: 1 callbacks suppressed 
[   49.718881] serial8250: too much work for irq4 
[5206410.490353] nr_pdflush_threads exported in /proc is scheduled for removal

Human Readable Timestamp: ‘dmesg -T’

By default ‘dmesg’ command prints the log message with the relative timestamp format i.e.

[    1.042738] Freeing initrd memory: 15916K

The above log statement from ‘dmesg’ command tells that the above event happened ‘1.042738’ minutes after the device was started. But we don’t know when the device was started. Thus the above type of log statement might not be quite helpful. 

If we pass the ‘-T’ option to the ‘dmesg’ command then the timestamp will be printed in a human-readable format, as shown below.

dmesg -T

[Thu Jan 14 12:26:42 2021] Freeing initrd memory: 15916K

In the above log statement, the timestamp is printed as Jan’ 14, 2021 at 12:26:42 i.e. in absolute format. This kind of timestamp is more human-readable and easy to understand, especially when you want to correlate your application problem with the device problem.

Slicing and Dicing: dmesg With More, Less, Head, Tail

 You can use ‘more’, ‘less’, ‘head’, ‘tail’, ‘grep’ commands along with ‘dmesg’ commands to get the information more quickly. 

 To read the most recent kernel messages, you can issue the following command:

dmesg | tail -20

To read initial kernel messages that were printed during device boot up, you can issue the following command:

dmesg | head -20

To read memory-related kernel logs only, you can issue the following command:

dmesg | grep -i memory

Color-Coded Message: ‘dmesg -L’

To see the dmesg output in color, you can issue the following command:

dmesg -L 

Then the output will start to look like this:

Categories: ‘dmesg -x’

To see the dmesg output with appropriate categories (info, notice, Warning,….) and facility(kernel, user, system, daemon,..), you can issue the following command:

dmesg -x 

Then output will start to look like this:

kern  :info  : [    3.337738] EXT4-fs (nvme0n1p1): mounted filesystem with ordered data mode. Opts: 
(null) 
user  :info  : [    3.347261] dracut: Mounted root filesystem /dev/nvme0n1p1 
user  :info  : [    3.406870] dracut: Switching root 
daemon:info  : [    4.182350] udevd[1060]: starting version 173 
kern  :info  : [    4.319515] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input4 
kern  :info  : [    4.407341] mousedev: PS/2 mouse device common for all mice 
kern  :err   : [    4.428044] ena 0000:00:05.0: LLQ is not supported Fallback to host mode policy. 
kern  :notice: [    8.611898] random: crng init done 
kern  :info  : [   10.268851] EXT4-fs (nvme0n1p1): resizing filesystem from 2096635 to 15728123 blocks

dmesg – Combining Options

You can also combine multiple dmesg options and issue them together. Say if you want to see output in human readable timestamp format with proper categorization then you can issue: 

dmesg -Tx

Then output will start to look like this:

kern  :debug : [Thu Jan 14 12:26:41 2021] pci 0000:00:05.0: reg 0x10: [mem 0xfebf4000-0xfebf7fff] 
kern  :info  : [Thu Jan 14 12:26:41 2021] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11) 
kern  :info  : [Thu Jan 14 12:26:41 2021] EDAC MC: Ver: 3.0.0 
kern  :info  : [Thu Jan 14 12:26:41 2021] PCI: Using ACPI for IRQ routing 
kern  :debug : [Thu Jan 14 12:26:41 2021] PCI: pci_cache_line_size set to 64 bytes 
kern  :notice: [Thu Jan 14 12:26:42 2021] Key type blacklist registered 
kern  :info  : [Thu Jan 14 12:26:42 2021] workingset: timestamp_bits=36 max_order=20 bucket_order=0 
kern  :info  : [Thu Jan 14 12:26:42 2021] zbud: loaded 
kern  :notice: [Thu Jan 14 12:26:42 2021] Key type asymmetric registered 
kern  :notice: [Thu Jan 14 12:26:42 2021] Asymmetric key parser 'x509' registered 
kern  :info  : [Thu Jan 14 12:26:42 2021] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 
253)

dmesg Command Options

 If you want to know all the arguments/options passed to the ‘dmesg’ command, please refer here.