Scheduling – an experiment

Problem 4.4 is about a program containing two user processes, plus the serial driver.

#include "microbian.h"
#include "hardware.h"
#include "lib.h"

static volatile int r = 0;

void proc1(int n) {
    for (int i = 0; i < 10; i++)
        printf("r = %d\n", r);
}

void proc2(int n) {
    while (r < 100000) r++;
}

void init(void) {
    serial_init();
    start("Proc1", proc1, 0, STACK);
    start("Proc2", proc2, 0, STACK);
}

Running this program with Process 2 scheduled first gives an easily understood result: the process increments r till it reaches 100,000 before Process 1 gets to run at all, and all the values that are printed are equal to 100,000.

If (as in the program shown) Process 1 gets to run first, the results are more interesting:

r = 0                                                                        
r = 1390                                                                     
r = 2617                                                                     
r = 3831                                                                     
r = 5045                                                                     
r = 6259                                                                     
r = 7472                                                                     
r = 8686                                                                     
r = 9900                                                                     
r = 11114                                                                   

Various questions arise: why do the printed values go up in fairly regular jumps? And why are the increments not exactly the same? It's obvious that Process 2 gets to run and increase the value of r, but once it starts, why doesn't it run to completion?

To answer these questions with confidence, I set up an experiment where I instrumented the operating system itself to flash different LEDs as it selected different processes to run, and then I connected an oscilloscope to monitor scheduling decisions as they were taken. A different approach might have been to have the scheduler record its decisions in a memory buffer for printing at the end of the program. It would certainly not have worked to have the operating system print its decisions as it went along, since (as we'll see) the printing mechanism is very much part of the phenomenon we're observing. Although an oscilloscope may be dispensable, it is a satisfyingly phyisical way of visualising what is happening.

An initial scope trace of the program running shows that the run has three phases. The horizontal scale here is 20ms per division.

Overview of a run

In this screenshot, the top trace (yellow) shows the serial driver process, the middle two traces show process 1 (green) that is capturing and printing values of r and process 2 (blue) that is incrementing r. The bottom trace (red) shows activity of the UART interrupt. Each trace is high when idle, and low when the corresponding process is running; the trace for the interrupt has a brief negatve-going pulse when the interrupt is triggered. The three phases are as follows:

• Initially, all three processes and the interrupt are all active.
• After about 10ms, process 1 has succeeded in taking its 10 snapshots of the value of r, and it exits.
• About 75ms from the start, process 2 finishes incrementing r to 100,000, and it also exits.
• After that, the serial driver process continues to respond to interrupts by sending characters from its buffer to the UART for a further 30ms or so.

Let's concentrate in on the first phase, which is where the counting happens. From the initial scope trace, it's plain that there are closer to 10 than 100,000 events in this phase. Here's the start of the run, showing four bursts of activity in the program, with a horizontal scale of 500μs per division.

Initial activity

Each trace is low when the corresponding process is active; the interrupt trace is high when nothing is happening, and briefly low each time an interrupt is received. Interrupts arrive at intervals of slightly more than 1ms, and that is right for a serial line running at 9600 baud. As you can see, in the interval between interrupts, process 2 runs constantly; it gets to run about 90% of the time. If it is constantly incrementing r in a loop that takes about 10 cycles per iteration, we expect that to take about a million cycles or 63ms to reach 10,000, and that is consistent with an elapsed time of 75ms to complete the process. It also means that between interrupts, process 2 has time to increase r by about 1,500.

The running of process 2 is suspended when an interrupt arrives. Let's zoom in further on the activity that then results, involving the device driver (yellow) and process 1 (green). The horizontal scale is 50μs per division.

A burst of activity

Here we see that the interrupt causes the connected process, the serial driver, to run. It was blocked at a call of receive, and it now runs, handles the interrupt by starting to transmit the next character, and blocks as receive again. The operating system now chooses another process to run. As it happens, process 1 was ready before the interrupt arrived (why this is so will be explained in a moment), and process 2 has joined the queue behind it – so process 1 is chosen. It captures a value of r and uses printf to format it as a string, which printf then passes to the serial driver all at once using a PUTBUF message. The serial driver then runs again, copies the characters into its own buffer, and sends a REPLY message that makes the process 1 ready to run again. However, process 1 now joins the queue behind process 2, and it is process 2 that gets to run when the serial driver reaches receive again. Process 2 now continues to increment r until the next interrupt, with process 1 sitting ready in the queue, thus establishing the conditions for the same behaviour to occur at the next interrupt.

Before long, process 1 has captured its 10 observations of r and converted them to output text, which the serial driver is now storing in its buffer, which has plenty of space for the entire output of the program. In the next phase, process 2 runs constantly, except for brief spells when the serial driver is responding to an interrupt by sending a character from its buffer to the UART. This scope trace shows the transition from the previous phase, with process 1 capturing its last value, then briefly running again just to tidy up and exit, with a horizontal scale of 500μs per divisions.

Phase 2 of the run

In the last phase, process 2 has finished incrementing r and exited, and the processor is idle between interrupts while the serial buffer drains. This scope trace shows the transition from phase 2 to phase 3, with process 2 exiting midway between one UART interrupt and the next. Horizontal scale of 500μs per division again

Phase 3 of the run

When phase 3 is over, UART becomes idle, the serial driver blocks waiting for a message that will never arrive, processes 1 and 2 have both exited, and the machine goes to sleep, never to wake up until we push reset to start another run.