Debugging Linux scheduler

Question

I am trying to implement a new kernel scheduler as my academic project. I know this may slow down the system but for debugging purpose I am writing a printk statement in context switch and schedule function so that I can see the event in dmesg output. But I am not getting any output in dmesg file. I tried to insert printk statement in various places but didn't get any output. am I doing something process ? is there any better tool or technique is there for debugging this kind of task ?

Answer 1

How about learning ftrace for linux kernel? The way to use it is slightly kernel version dependent. Just read the file /sys/kernel/debug/tracing/README for details.

If the above directory is not present then you may have to mount it:

mount -t debugfs nodev /sys/kernel/debug

And then write a bash shell script to generate the userspace tracing:

#!/bin/bash
echo 0 >/sys/kernel/debug/tracing/tracing_enabled
echo 'sched_*' 'irq_*' > /sys/kernel/debug/tracing/set_ftrace_filter
echo function >/sys/kernel/debug/tracing/current_tracer
echo 1 >/sys/kernel/debug/tracing/tracing_enabled

ls -al /tmp/ 1>/dev/null &
ls -al /tmp/ 1>/dev/null &
ls -al /tmp/ 1>/dev/null &
ls -al /tmp/ 1>/dev/null &
ls -al /tmp/ 1>/dev/null &
ls -al /tmp/ 1>/dev/null &

sleep 3

echo 0 >/sys/kernel/debug/tracing/tracing_enabled

cat /sys/kernel/debug/tracing/trace

Things to note:

a. Linux kernel scheduling is implemented in the directory kernel/sched from the kernel source code. An example is CFQ in fair.c.

b. Reading the files and looking for the API, we know that relevant API involved in scheduling are starting with "irq_" and "sched_", and so which is why we code it into the shell script above.

c. The output of the above shell script on my system is located below (it is gzipped, about 21K lines, after massive truncation of "open" related functions):

https://drive.google.com/file/d/0B1hg6_FvnEa8dDBMcl9tcEs2VEU/edit?usp=sharing

Basically you can see which kernel function is involved in what process context. From the names of the kernel function, you can continue tracing via reading the source codes.

More details you can google further, for example:

http://tthtlc.wordpress.com/2013/11/19/using-ftrace-to-understanding-linux-kernel-api/

Answer 2

You might need to raise the kernel log level. Read what level is set currently by:

cat /proc/sys/kernel/printk

This entry should be greater than DEFAULT_MESSAGE_LOGLEVEL defined in kernel/printk.c
You can change it to some other value, say 2 by:

echo 2 > /proc/sys/kernel/printk

If you don't want to change the DEFAULT_MESSAGE_LOGLEVEL then you can give a higher priority flag while calling printk something like:

printk(KERN_ERR "Hello world"); //or any higher priority flag 

For more information, read on.