Cogs and Levers A blog full of technical stuff

Dissecting dmesg with awk

AWK is a programming language that deals with processing text in a sequence of pattern matching rules. It’s really handy for reducing massive amounts of text into just the information that you care about. The full user guide for AWK can be found here.

Rather than take you on a tour through the user guide, I thought today’s post might be better as a practical example. I’m going to present some useful functions with AWK using the Linux Kernel’s dmesg output as source data.

As a final note, a lot if not all of the information that I’ll present below can be transformed into a “one liner”. There’s quite a few instances of crafty AWK hackers putting these together. I just want to present some of the language.

Source data

The dmesg data is in an easy-enough format to work with. Taking the first few lines as an example:

[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct

We see that there is an elapsed time figure surrounded with square brackets, the rest of the line is the log text. Further on through the text, we start to see the log lines prefixed with a driver name also:

[    4.871693] vboxdrv: Found 8 processor cores.
[    4.872033] vboxdrv: fAsync=0 offMin=0x19e offMax=0xcb6

Basic usage

For the purposes of today’s post, the following usage is going to be most useful to us

dmesg | awk -f our-awk-script.awk

This supplies the dmesg output to our AWK script.

To accomplish this task, we’re going to use a regular expression to pick out each line with “fail” in it.

/ failed / {
	print $0
}

Immediately, you can see that AWK statements take the shape of:

condition { actions }

The action here print $0 prints the whole, captured line to the console. Other variables are available to be printed such as $1, $2, and so on. These numbered variables take chunks of the captured string, split by a space character as its delimiter.

Exploring the variables

Just to take a look at those variables a little closer, we can augment our initial rule slightly to see what’s contained in those variables:

/ failed / {
	print "$0: ", $0
	print "$1: ", $1
	print "$2: ", $2
	print "$3: ", $3
	print "$4: ", $4
}

Run for one line of text matching the “failed” rule:

$0:  [    1.804314] iwlwifi 0000:03:00.0: Direct firmware load failed with error -2
$1:  [
$2:  1.804314]
$3:  iwlwifi
$4:  0000:03:00.0:

Listing out which drivers mentioned the word “failed”

AWK has a very flexible associative array type as well. We can basically reference any variable with any index we choose. For the next progression of this script, we’ll build an array of driver names with an instance count so we can just give the user a report of the which drivers were mentioned how many times.

/ failed / { 
	drivers[$3] = drivers[$3] + 1
}

END {
	for (driver in drivers) {
		print driver ":", drivers[driver]
	}	
}

$3 is giving us the driver name, so we just increment a value in the array for that driver. END is something new. It’s executed, at the end. We enumerate the array that we’ve built, printing the name of the driver and the count.

Running this, I get the following result:

nouveau: 1
nouveau:: 1
iwlwifi: 2

That’s annoying. nouveau appears in the report twice because it’s mentioned with and without a colon : character in the source text.

[    1.687503] nouveau E[     DRM] failed to create 0x80000080, -22
[    1.687631] nouveau: probe of 0000:01:00.0 failed with error -22

Adding a call to gsub to perform a simple string replacement does the trick. gsub is a part of AWK’s string functions.

/ failed / { 
	gsub(/\:/, "", $3)
	drivers[$3] = drivers[$3] + 1
}

With an output like this

nouveau: 2
iwlwifi: 2

Much better.

Just as we have an ‘END’ section above, we are also given the ability to write code in a ‘BEGIN’ section that will kick off before any of our pattern rules are executed.

Using boolean logic in conditions

AWK conditions aren’t just regular expressions, they can incorporate boolean logic from the file also. You can test any variable like a normal boolean condition. In the following example, I don’t want to count failures that come out of the iwlwifi driver.

/ failed / && $3 != "iwlwifi" { 
	gsub(/\:/, "", $3)
	drivers[$3] = drivers[$3] + 1
}

Other functions to check out

If at any time, your rule wants to bug out of the script entirely - wire up the exit call. If you just want to stop processing this line of text and move on to the next, you can use next.

Sharing files easily over HTTP with Python

Getting a quick web server up and running is really simple (if you don’t need a fully blown application server). I find this technique really useful when prototyping web sites that I only need to serve static HTML, CSS & Javascript with.

In the folder that hosts your web application, issue the following Python command:

python -m SimpleHTTPServer

After you do this, you’ll get a confirmation message that your site is available:

Serving HTTP on 0.0.0.0 port 8000 ...

And that’s it. You can read up more on this really handy utility here.

An inline assembly primer with gcc

A really handy feature of GCC is that it allows you to inter-mix assembly code with your C code.

There are so many great references on this topic already. One of the best is from Lockless however there are many, many more.

Today’s article is more of a quick reference for inlining your assembly code.

Syntax

When preparing a block of assembly to be put inline in your C code, you use the asm keyword.

asm [volatile] ( 
	assembly code
	: outputs
	: inputs
	: clobbers
)

The first parameter that is passed is the assembly code itself. It’ll be in AT&T syntax, but will also have some extra rules apply to it which will allow for the compiler to make some decisions for you. The outputs, inputs and clobbers are optional lists consisting of directives instructing the compiler how to handle inputs, outputs and what’s expected to be trashed (clobbered) in your assembly block.

A simple example usage, to add two integers and return the result might look like this:

int add(int a, int b) {
	int c;

	asm (
		"xorl	%%eax, %%eax\n\t"
		"addl	%2, %1\n\t"
		"movl 	%1, %0"
		: "=m" (c)
		: "r" (a), "r" (b)
		: "%eax"
	);

	return c;
}

Once this code is compiled, you can see what the compiler has done with it:

	asm (
   a:	8b 55 ec             	mov    edx,DWORD PTR [rbp-0x14]
   d:	8b 4d e8             	mov    ecx,DWORD PTR [rbp-0x18]
  10:	31 c0                	xor    eax,eax
  12:	01 ca                	add    edx,ecx
  14:	89 55 fc             	mov    DWORD PTR [rbp-0x4],edx
		: "=m" (c)
		: "r" (a), "r" (b)
		: "%eax"
	);

edx and ecx were chosen as our general purpose registers for inputs, so they’re loaded first-up. The addition occurs and then the result (as requested) is placed in the memory location of our output. Back in the inline code, you can see that these registers have been symbolically referenced as %1, %2, etc.

Outputs are a mix of constraints and modifiers, inputs are just constraints and clobbers list out what was modified (register-wise or other).

What about volatile?

The volatile keyword allows you to tell the compiler to not optimise away our code if it deems that it isn’t required (i.e. is has no effect on anything).

Constraints

Constraint Description
m Any kind of a memory address
o Memory address if it’s offsettable
V Memory address if it’s not offsettable
< Memory with autodecrement addressing
> Memory with autoincrement addressing
r General purpose register
i Immediate integer value
n Immediate integer with a known value
I . . P Range based immediate integer values
E Immediate format-dependent floating point number
F Immediate floating point number
G, H Range based immediate float values
s Immediate integer that is not an explicit integer
g Any register, memory or immediate value; not a general purpose register though
X Any operand is allowed
p Any operand that is a valid memory address

A full description of all of these constraints can be found here.

Modifiers

Modifier Description
= Operand is written to
+ Operand is read from and written to
& Operand is written to (clobbered) before input operands are used
% Instruction is cumulative for this operand

A full description of all of these modifiers can be found here.

Clobbers

Clobber Description
cc Flags are modified
memory Memory outside of what is in the constraints is modified

A full description of clobbers can be found here.

A simple example with gcc and objdump

In today’s post, I want to present a dead-simple C program that we’ll compile into an object file and then use objdump to give us some assembly code. I’ll then take you through the generated assembly.

Using objdump

According to its manpage, objdump is used to dsplay information from object files. It has a whole host of different switches that you can supply to interrogate object files, but we’ll only have a very simple usage for it in this post.

I prefer Intel assembly syntax, so I’ll specify -M intel. We want to disassemble the object file, so we’ll use -d. It’s really helpful to also have the original source code intermixed with the assembly code, so we’ll turn that on with -S.

Your command should look something like this

objdump -d -M intel -S yourobjectfile.o

Simple example

The most basic program to look at is one that does nothing but return 0 back to the operating system.

int main(int argc, char *argv[]) {
return 0;
}

Compiling this unit (ensuring to specify -g to gcc for debug symbols) and then disassembling with objdump, we’re given back the following:

$ objdump -d -M intel -S inline.o

inline.o:     file format elf64-x86-64


Disassembly of section .text:

0000000000000000 <main>:

#include <stdio.h>

int main(int argc, char *argv[]) {
   0:	55                   push   rbp
   1:	48 89 e5             mov    rbp,rsp
   4:	89 7d fc             mov    DWORD PTR [rbp-0x4],edi
   7:	48 89 75 f0          mov    QWORD PTR [rbp-0x10],rsi
return 0;
   b:	b8 00 00 00 00       mov    eax,0x0
  10:	5d                   pop    rbp
  11:	c3                   ret    

Whilst the whole block that gets dumped out is important, we’re really only worried about the inner implementation of the main function call. The translation of this code is equally pretty simple.

push   rbp
mov    rbp,rsp
mov    DWORD PTR [rbp-0x4],edi
mov    QWORD PTR [rbp-0x10],rsi

mov    eax,0x0
pop    rbp
ret    

Dissecting this code, we can see that the program first sets up the stack frame for the two parameters passed into main, argc and argv.

So, we save the previous rbp to preserve its state.

push   rbp
mov    rbp,rsp

And in accordance with the calling conventions for System V AMD64

The first six integer or pointer arguments are passed in registers RDI, RSI, RDX, RCX, R8, and R9, while XMM0, XMM1, XMM2, XMM3, XMM4, XMM5, XMM6 and XMM7 are used for floating point arguments.

Therefore, argc being of type int is therefore a DWORD and is passed via edi. argv is a pointer and is a QWORD; therefore it is passed using the 64 bit register rsi.

mov    DWORD PTR [rbp-0x4],edi
mov    QWORD PTR [rbp-0x10],rsi

Upon entry, we’re just filling up those spots in the stack.

Exiting we’re just setting our return value (which is always in the accumulator), restoring the pre-entry value that was in rbp and returning to the caller.

mov    eax,0x0
pop    rbp
ret    

Write another, more complex C program; disassemble it and see if you can follow along with the results.

Fixed point numbers

In today’s post, I’m going to go over a very old technique for working with fractional numbers. Fixed point numbers are defined by dividing an integral data type (8, 16, 32 or 64 bit) word into a whole part and fractional part.

The idea

So, what you do is you need to split your number into a whole part and fractional part. This means you dedicate some bit-space of your word to both. For a simple example, let’s work with an byte (traditioanlly 8 bits) and split the number evenly giving the whole part 4 bits as well as the fractional part.

0 0 0 0 0 0 0 0 
------- -------
   |       |
 Whole   Frac

Above, we see our number represented in binary with all 8 bits laid out. The upper 4 bits are dedicated to the whole part, the lower 4 bits to the fractional.

The whole part

In this scenario (of a 4:4) split, you’ve probably already worked out that the maximum whole value we can hold is 15. Some example numbers as they appear might be:

0 0 0 1 0 0 0 0 = 1.0
0 1 0 1 0 0 0 0 = 5.0
1 1 1 1 0 0 0 0 = 15.0

First thing you’ll notice is, every number is effectivly shifted 4 bits to the left. This is how you load a fixed point number into memory. You shift the original integer to the left by the number of bits you have allocated for the fractional part.

Nothing overly special here. The fractional part is a little different to think about, but still makes sense.

The fractional part

As above, we’ve dedicated 4 bits to our fractional part as well. With binary numbers, the value of the bit slots go up in powers of two; going in the opposite direction they also go down in powers of two. With normal numbers, bit slot 0 actually corresponds to 2^0. By sliding this bit slot up by four, we effectivly start counting negative powers into the fractional part:

0 0 0 0 1 0 0 0 = 2^(-1) = 0.5
0 0 0 0 0 1 0 0 = 2^(-2) = 0.25
0 0 0 0 0 0 1 0 = 2^(-3) = 0.125
0 0 0 0 0 0 0 1 = 2^(-4) = 0.0625

Using this knowledge, we can start to treat the lower 4 bits as the fractional part of the number. Even bit shifting (multiplication by 2) works as you’d expect:

0 0 0 0 1 0 0 0 = 2^(-1) = 0.5

0 0 0 1 0 0 0 0 = 2^(0)  = 1

0.5 * 2 = 1

All we did was shift the first number by 1 slot to the left. This has the overall effect of multiplying the number by 2 - makes sense, we’re in binary after all.

Ok, let’s take a look at how some simple operations work in code.

Show your working

Working with a 4:4 fixed point number is fine for pen-and-paper type stuff, but we’ll want to scale that up once we start to work with code. We’ll target a 16 bit number now, using the lower 6 bits for fractionals so the number is now a 10:6.

First off, we’ll want to be able to load our numbers. As above, this is as simple as shifting the numbers left by the number of bits we have dedicated to the fractional portion of our number. In this case, 6.

mov		ah, 5		
shl		ah, 6

Of course, to get our whole number back again; all we do is shift a fixed point number to the right by the same number of bits again. Getting the fractional part of the number back out, again, depends on how many bits you have dedicated to the number’s precision (or fractional part). Because we’ve dedicated 6, this means the smallest number (and therefore the most accurate precision) we can use is actually 0.015625. We only have 6 bits precision, which gives us a range of 0-63.

This formula is what you’d use to get the fractional part of our number:

2^(-(number-of-bits)) * (lower-number-of-bits)

So, if we had the number 0.25 which would be represented by 0000000000010000, we can extract 0.25 from this using the formula above:

lower 6 bits = 010000 = 16
2^(-6) * 16 = 0.25

Addition and subtraction are handled just like normal. Nothing special needs to happen here. Multiplication and Division both require a little more effort.

Once you’ve performed your multiplication, you need to adjust the product by the number of fractional bits to the right.

mov     ax, 10      ; 10 * 10
shl     ax, 6
mov     bx, 10      
shl     bx, 6

imul    bx          ; perform the multiplication
                    ; result will now be in dx:ax

add     ax, 32      ; add the bit boundary
adc     dx, 0       ; adjust for any carry

shrd    ax, dx, 6   ; shift the top 6 bits of dx into ax

Division requires a little more care as well. We pre-prepare the numbers by shifting them by the whole part prior to operation.

mov     dx, 10      ; 10 / 4
shl     dx, 6
mov     bx, 4
shl     bx, 6

xor     ax, ax		  ; ax = 0      
shrd    ax, dx, 10  ; shift the top 10 bits of dx into ax
sar     dx, 10      ; shift and rotate 10 

idiv    bx			  ; perform the division

Whilst these operations are more complex than their natural analogues, you can see that there’s not that much too them.

Conclusion

All of this information is old, and that’s the point. Make sure you check out the fixed point writeup hosted by textfiles.com.