CSE 422S: Lab 1

Kernel Monitoring Framework


He then told them many remarkable stories, sometimes half as if speaking to himself, sometimes looking at them suddenly with a bright blue eye under his deep brows. Often his voice would turn to song, and he would get out of his chair and dance about. He told them tales of bees and flowers, the ways of trees, and the strange creatures of the Forest, about the evil things and good things, things friendly and things unfriendly, cruel things and kind things, and secrets hidden under brambles.

As they listened, they began to understand the lives of the Forest, apart from themselves, indeed to feel themselves as the strangers where all other things were at home.

The Fellowship of the Ring, Book I, Chapter 7

An important aspect of system development and management is to monitor (and possibly adapt) the operation of the system: real-world systems usually must conform to performance requirements beyond simply being free of bugs or producing correct output. For example, for high-performance systems it may be important to know computational throughput, for interactive systems it may be important to measure responsiveness to users, and safety-critical systems may need to track and maintain their ability to handle problematic events within bounded timeframes. In such situations, the system must be able to monitor itself and take actions as necessary to ensure the correct operation of the system. In this assignment we will explore some ways to perform such monitoring tasks, using kernel modules, kernel timers, kernel threads, and other features we've looked at in this course.

In this lab, you will:

  1. Use kernel timers to schedule recurring events (e.g., thread wakeups) in the future.
  2. Use kernel threads to perform deferrable work inside the kernel.
  3. Create a simple monitoring framework that periodically captures basic information from kernelspace, using kernel timers and kernel threads to manage the frequency and context of such information gathering.
  4. Verify and evaluate the operation of your monitoring framework through tracing techniques that we've explored previously in studio exercises.

Please complete the required exercises below.

As you work through these exercises, please record your answers, and when finished email your results to eng-cse422s@email.wustl.edu with the phrase Lab1 in the subject line.

Create a readme.txt file for your project. Make sure that the name of each person who worked on this lab assignment is listed at the beginning of it, and make sure that in addition to completing the code for this project, you also carefully document your work in that readme.txt file, as indicated in the Assignment section below.


Readings and other resources

The following sources of information are likely to be useful as you work on this project.

Assignment

  1. At the top of your readme.txt file, list the names of the people who worked together on this lab, and a working e-mail address for each of those people. You are encouraged to work in groups of 2 or 3 people on this lab assignment, though you may work individually instead if you prefer - groups larger than 3 are not allowed for this assignment.

  2. To get started, create a simple kernel module that uses the module_param macro to define two ulong module parameters, called log_sec and log_nsec, which will govern how frequently (in seconds and nanoseconds, respectively) your module will (re-)schedule a repeating timer. Declare and provide default values for two static unsigned long variables to store the values for these module parameters, so that in the event that your module is loaded without parameters, the timer defaults to expiring once every second.

    These module parameters should not be visible in the filesystem, so (in addition to setting up the module parameters so that is the case, when you use the module_param macro for each of them) your module implementation for this lab should not contain code for filesystem readable/writeable attributes, which you used in the studios that had those features - instead, please start with something like the simple module example shown on pages 338 and 339 of LKD, and then add features to it as the assignment specifies.

    Add a section titled "Module Design" to your readme.txt file, and in it describe briefly (in a paragraph or two) how you implemented these requirements.

  3. Now you will implement a recurring timer that is initialized and started at module load time and canceled when the module is unloaded, and that repeatedly reschedules itself a specific interval later (as defined by the module parameters) whenever it expires.

    Please review the hrtimers API web page for an overview of hrtimers and how they work. Since the API has changed somewhat since that page was posted, please then review the hrtimer.h and ktime.h header files that are found in the include/linux directory under the linux source directory that you downloaded and built in the second studio.

    Add static variables for the timer interval and the timer, of types ktime_t and struct hrtimer respectively, to your module.

    In your module, write a new static function for your timer's expiration with return type enum hrtimer_restart, which takes a pointer to struct hrtimer as its only parameter. In the body of that function, use the hrtimer_forward() function (or hrtimer_forward_now() if you prefer) and the module's static timer inverval variable, to reschedule the timer's next expiration one timer inverval forward into the future. The timer expiration function then should return HRTIMER_RESTART to indicate that the timer is being restarted.

    In your module's init() function, pass the static unsigned long variables for the module parameters into a call to ktime_set(), and assign that function's result to the module's static timer interval variable. Then, your module's init() function should: (1) call hrtimer_init() with the module's timer variable and the CLOCK_MONOTONIC and HRTIMER_MODE_REL flags, (2) set the function field of the module's timer variable (struct) to point to the timer expiration function you wrote, and (3) call hrtimer_start() with the module's timer and timer interval variables and the HRTIMER_MODE_REL flag, to schedule the first expiration of the timer (which then will forward the scheduling of its next expiration etc. until the module is unloaded - see next).

    In your module's exit() function, use hrtimer_cancel() to cancel the module's timer.

    Compile your module, and use insmod to load it (and rmmod to unload it) with different parameter values (including not passing any module parameters to insmod so that the defaults are used) on your Raspberry Pi. To pass parameters to your module via the insmod utility, you will need to give the name as well as the value of each parameter as in:

    sudo insmod monitor_mod.ko log_sec=0 log_nsec=100000000

    For each of those runs, monitor and verify the timing of when your timer wakes up, using the system log. In the studios so far, we have accessed the system log through the command dmesg. However, the system log is also accessible through the file /var/log/syslog. This makes it possible to view real-time updates to the system log with the command "tail -f /var/log/syslog".

    Hypothetically your timer should wake up and execute regularly (e.g., at each occurrence of whatever interval was specified in the module parameters, or every second if no parameters were passed via insmod). However, fluctuations in the actual timing of execution, called variations, may occur in practice. The dmesg command gives timestamps with six significant digits (i.e. microseconds resolution). Use this to estimate the timing variations in the intervals between expirations of your timer, for different module parameter values.

    Add a section titled "Timer Design and Evaluation" to your readme.txt file, and in it describe briefly (in a paragraph or two) how you implemented the requirements above. In that same section please also paste fragments of the system log that show your timer being rescheduled several times in each of a few runs with different parameter vales, and then comment briefly on how much the timing of your timer varies from the specified interval, based on the results you observed.

  4. Please review the kernel thread interface, which is found in include/linux/kthread.h, and is very similar to the POSIX threading interface.

    Add another static variable to your module, of type struct task_struct *, which will hold a pointer to the task struct for your module's (currently single) kernel thread.

    Add another static function to your module, which returns an integer and takes a single parameter of type void *. This function will run in one or more kernel threads when they are spawned by the module. In the body of that function, first use printk() to generate a message that contains the name you gave this function, to show that it ran, and the function then should return 0 to indicate it completed successfully.

    Then, modify your module's init() function so that when the module loads it calls kthread_run() to spawn a kernel thread (which in turn runs the static thread function you wrote) and stores the result of the kthread_run() call into the module's static task struct pointer variable.

    Also modify your module's exit function so that when the module is unloaded it uses kthread_stop() to alert the thread that it should cease execution.

    At this point it's a good idea to compile your module and load and unload it on your Raspberry Pi and make sure it loads and unloads correctly and that the thread function is run once per load/unload of the module, before going farther with this assignment.

    Modify your module's static thread function so that it repeatedly (in a loop) (1) uses printk() to generate a system log message indicating another iteration of the loop has started and giving the values of current->nvcsw and current->nivcsw (for debugging purposes, it also may be useful to track how many iterations have happened and add the iteration number to each of those system log messages), (2) passes TASK_INTERRUPTIBLE into a call to set_current_state() and then immediately calls schedule() to suspend its execution until another piece of code wakes it up, and (3) uses kthread_should_stop() to test whether or not it should cease execution (and if so the thread function should exit the loop, print another system log message indicating it's terminating, and return 0).

    Although it may look like a variable name, current is actually a macro for the task_struct of the currently executing process. Since this code is executing in a kernel thread, and kernel threads are effectively treated like any other process in the system, current points to the task_struct that describes the module's kernel thread. The data fields nvcsw and nivcsw stand for Number of Voluntary Context SWitches and Number of InVoluntary Context SWitches, respectively, and they record the number of occurences of these two events within the kernel thread.

    Modify your module's timer expiration function so that each time it is called (but before it forwards the timer's next expiration) it passes the module's static task struct pointer variable into a call to wake_up_process(), which will wake up the kernel thread so it can make another iteration of its loop (or end if the module is being unloaded).

    This may be another good point to compile your module and load and unload it on your Raspberry Pi and make sure that the measurements are occurring at the right intervals and are showing reasonable values, before going farther with this assignment.

    Add a section titled "Thread Design and Evaluation" to your readme.txt file, and in it describe briefly (in a paragraph or two) how you implemented the requirements above. In that same section please also paste fragments of the system log that show your kernel thread iterating several times in each of a few runs with different parameter values, and printing out the number of voluntary and involuntary preemptions it has experienced as of each of those iterations. Then comment briefly on (1) how much the timing of each loop's iteration varies from the specified intervals (especially in comparison to the variations you saw in the intervals between timer expirations), and (2) why you think your module's kernel thread may have been preempted voluntarily vs. involuntarily, based on the results you observed.

  5. At this point, you should have a simple functional, single-threaded monitoring framework. However, some operations only can be done (or done efficiently) on a per-CPU basis. (e.g., accesing per-CPU data structures.) If you look at a listing of other kernel threads in top or ps, you will notice that many of them end with "/0" or a similar string. This denotes that the kernel thread is pinned to (and thus only runs on) that core. For example, the thread ksoftirq/2 only executes on core 2, while migrate/1 only runs on core 1.

    Copy your existing module's .c file to another file with an appropriate name for a multi-threaded version (e.g., if your single-threaded module was implemented in monitor_mod.c you might name the new file mt_monitor_mod.c). You will turn in separate files for your single-threaded and multi-threaded monitoring modules.

    Modify the multi-threaded version of your module so that it has static task_struct pointer variables for four kernel threads, one for each core of your Raspberry Pi.

    Also modify your module's init() function so that instead of calling kthread_run() to spawn a single kernel thread, it instead:

    1. calls kthread_create() four times (passing the thread function into each call) and stores the result of each call in a separate static task_struct pointer variable of the module;

    2. calls kthread_bind() four times, to bind each of those threads to a separate core; and then

    3. calls wake_up_process() four times (passing the appropriate static task_struct pointer variable each time) so that each thread begins to execute.

    Modify your module's exit() function so that it calls kthread_stop() four times, using the appropriate static task_struct pointer variable of the module for each of the threads.

    Modify your module's timer expiration function so that each time it is called (again before it forwards its next expiration into the future) it calls wake_up_process() four times, using the appropriate static task_struct pointer variable of the module for each of the threads, so each one wakes up an runs another iteration each time the timer expires.

    Compile and load (and unload) your multi-threaded module with different module parameter values. Verify correct behavior of your multi-threaded monitoring framework through the messages that are printed in the system log. Each of the four threads should be executing on a different processor (you can also verify what CPU a kernel thread is currently executing on with the function smp_processor_id()) within a relatively short time of one another.

    When you are satisfied that your kernel threads are behaving properly, add a section titled "Multi-threading Design and Evaluation" to your readme.txt file, and in it describe briefly (in a paragraph or two) how you implemented the requirements for multi-threading, above. In that same section please also paste fragments of the system log that show each of your kernel threads iterating several times in each of a few runs with different parameter values, and printing out the number of voluntary and involuntary preemptions it has experienced as of each of those iterations. Then comment briefly on (1) how much the timing of each loop's iteration varies from the specified intervals (especially in comparison to the variations you saw in the intervals for the single-threaded case), and (2) the relative frequency of voluntary vs. involuntary preemptions each thread experienced (again especially in comparison to what you saw in the single-threaded case).

  6. Take a system trace with trace-cmd while your multi-threaded module is loaded. You can perform system tracing in free-running mode by simply omitting a program name. For example, the command trace-cmd record -e sched_switch will trace the system until you interrupt it with CTRL-C. Take at least ten seconds of trace.

    Graphically verify your system's behavior with Kernelshark. Take a screenshot and save it in a file named trace.png. You can take a screenshot of the whole screen by hitting the Print Screen button on your keyboard, or you can install a graphical screenshot utility with sudo apt-get install gnome-screenshot (which will then show up under Accessories in the system menu).

  7. Add a section titled "System Performance" to your readme.txt file. Zoom in on several of the thread wakeups, and in that section of your readme.txt file discuss briefly (1) whether (based on what you see) your threads run to completion every time, or they are sometimes preempted, and (2) given that the threads are executing in kernel mode, what might be able to preempt them.

    Estimate the total execution time of one of your thread wakeups (the time from the start of the first thread wakeup to the end of the last thread) using Kernelshark's graphical interface. You can do this easily by setting markers with left-click and shift plus left-click. Once you have set two markers, the time between those two markers will appear in the "Delta" box. Measure three groups and report their timings. Take a screenshot of one such measurement and save it in a file named total_exec.png.

    Again looking at the groups of thread wakeups, notice that each thread does not start at exactly the same time. This variability in thread release times is called jitter. Measure the difference between the first and the last thread starting times for three wakeups and report the minimum, maximum, and mean values of those measurements in the "System Performance" section of your readme.txt file. Take a screenshot of one such group and save it in a file named jitter.png.

    Rather than using the graphical interface, you can also examine kernel traces in text format. The command trace-cmd report generates this text, and you can search for relevant log entries with grep. For example, the command trace-cmd report | grep log_thread/3 would return all log entries related to the process log_thread/3. Use this technique to compute the actual running time over five wakeups of one particular thread running in your multi-threaded monitoring module, and in "System Performance" section of your readme.txt file report the minimum, maximum, and mean values you saw for that thread.

  8. At the bottom of your readme.txt file please add a section titled "Development Effort" and in it please provide an estimate of the amount of time (in total-person hours) that your team (or you if you didn't work with anyone else) spent completing this assignment. This will allow the instructor to calibrate and possibly refine the content of this course in future semesters.

What to turn in

Please attach the following files to an e-mail with the phrase Lab1 in the subject line.

In the body of that e-mail, again list the names of everyone who worked on the project. Please also cc the e-mail addresses of any other team members besides the person who is sending the e-mail, and send the e-mail to eng-cse422s@email.wustl.edu so that it arrives at the mail server by the deadline. Please make sure to send your e-mail enough ahead of the deadline that it arrives on time, according to the time stamp our e-mail server puts on the e-mail when it is received.


Posted 9:35pm on Monday September 25, 2017 and updated on Tuesday October 3, 2017 by Chris Gill.

Changes since original posting: