What are we measuring?
How can we tell whether a program is fast? And how can we tell whether a change actually helped?
We will write a few C programs, measure how long they take, and investigate two things that can affect their performance: compiler settings and memory access order. These programs use one application thread. We will get to parallel programs later.
You will need a Linux terminal, GCC, and a text editor. If you need help getting connected or working with files, start with Module 0.
Source files
Create the files as you work through the examples, or download them here:
Keep them together in a working directory. Run the commands below from that directory.
Source code becomes an executable
Write hello.c
Create hello.c in your editor. With Nano:
nano hello.cEnter this complete program:
#include <stdio.h>
int main(void) {
printf("Hello, world!\n");
return 0;
}In Nano, Ctrl+O, then Enter, saves; Ctrl+X exits. #include <stdio.h> gives C the declaration of printf. Execution starts at main. \n ends the output line, and returning zero indicates successful completion.
Let GCC choose the output name
gcc hello.c
ls -l
./a.outhello.c is a text file containing source code. For this command, GCC coordinates compilation, assembly, and linking, producing an executable named a.out by default. The name is historical; it does not mean this is a text output file. A successful compile often prints nothing.
Think about it: Did GCC run our program?
Give the executable a useful name
gcc -Wall -o hello hello.c
./hello
gcc -g -Wall -o hello hello.c
./hello| Piece | Say it this way |
|---|---|
gcc |
Run the compiler driver |
hello.c |
Read this source file |
-o hello |
Put the executable in the file hello |
-Wall |
Enable a useful collection of warnings about suspicious code |
-g |
Include information a debugger can use to connect machine code to source |
./hello |
Run the executable named hello in this directory |
-Wall does not enable every possible warning or prove correctness. -g does not launch a debugger, repair bugs, or turn on runtime checking. It can coexist with optimization, although optimized code can be harder to step through.
The shell normally searches directories in PATH for bare command names. The current directory is usually absent, so we supply ./.
If compilation fails, fix the first error and compile again before running. An older executable may still exist after a failed build. Never use -o hello.c: the output name should be different from the source filename.
Quick check: Change the greeting, save, rebuild, and run it. Check that the new greeting appears.
Give the machine some work
Create sum.c:
#include <stdio.h>
int main(void) {
const long long n = 100000000LL;
double sum = 0.0;
for (long long i = 1; i <= n; i++) {
sum += 1.0 / i;
}
printf("Sum: %.6f\n", sum);
return 0;
}gcc -g -Wall -O0 -o sum sum.c
./sumWe compute the harmonic sum, \(H_n = 1 + 1/2 + \cdots + 1/n\). -O0 uses a capital letter O, followed by zero; it disables most optimization passes. We will compare it with -O2 shortly.
long long is an integer type with at least 64 bits. The LL suffix makes the constant a long long. double holds floating-point values. sum += value means sum = sum + value.
1.0 / i performs floating-point division. With 1 / i, both operands would be integers and division would discard the fraction, producing zero for every i > 1. %.6f prints six digits after the decimal point. The result is an approximation.
Check the computation before timing it
Temporarily change n to 3, save, compile, and run. Expect Sum: 1.833333, since \(1 + 1/2 + 1/3 = 11/6\).
Then change n back to 100000000LL, save, and compile again before timing. Remember to rebuild whenever you change the source.
Think about it: What should happen to runtime if we double n?
Put a stopwatch around the whole program
time ./sumIn a typical Bash session, the timing report resembles the following. These are example times; yours will differ.
real 0m1.240s
user 0m1.190s
sys 0m0.010s
| Label | Meaning | In this illustrative run |
|---|---|---|
real |
Elapsed time from command start to completion | 1.240 seconds passed |
user |
CPU time spent executing the program’s user-space code, including libraries | 1.190 CPU seconds |
sys |
CPU time spent in the kernel on behalf of the program | 0.010 CPU seconds |
real includes waiting. user + sys measures consumed CPU time, not an additional elapsed phase. Do not add all three together. Shell formatting can differ. If necessary, time -p ./sum requests a simpler report with values in seconds.
Wall-clock time versus CPU time
Think about it: A program spends two seconds waiting. Did those seconds matter to the person waiting for an answer?
time sleep 2Expect real near two seconds, with very little user or sys time. Sleeping lets the CPU do other work. In later parallel programs, waiting for a message can likewise increase elapsed time without consuming equal CPU time.
For performance, we usually want elapsed time: how long we wait for the answer. C’s clock() measures CPU time, so it would leave out time spent sleeping or waiting.
“User time” does not mean time spent typing, and “system time” does not mean all elapsed time on the system. Library calculations generally contribute to user time; kernel work caused by system calls contributes to sys time.
For this single-threaded CPU-bound program, user + sys will often be close to real. Sharing a busy node can widen the gap. Later, multiple threads running concurrently can accumulate CPU time greater than elapsed time. CPU time remains useful for understanding resource use; our main question here is how long the answer takes.
Shell timing covers the executable’s overall run, including startup, computation, and output. It does not include the earlier compilation when the command is time ./sum. Remote shell timing also does not measure the entire laptop-to-server-to-screen experience.
Put the stopwatch inside C
We now want the time spent computing the sum. Save this complete version as sum_timed.c:
#include <stdio.h>
#include <time.h>
int main(void) {
const long long n = 100000000LL;
double sum = 0.0;
struct timespec start, finish;
clock_gettime(CLOCK_MONOTONIC, &start);
for (long long i = 1; i <= n; i++) {
sum += 1.0 / i;
}
clock_gettime(CLOCK_MONOTONIC, &finish);
double elapsed = (finish.tv_sec - start.tv_sec)
+ (finish.tv_nsec - start.tv_nsec) / 1e9;
printf("Sum: %.6f\n", sum);
printf("Time for the loop: %.4f seconds\n", elapsed);
return 0;
}gcc -g -Wall -O0 -o sum_O0 sum_timed.c
time ./sum_O0We now have two elapsed times: the internal computation interval and the shell’s whole-program interval. The shell’s interval also includes setup and output. For a large sum, the numbers may be close. Separate clocks and rounding mean the displayed difference is not an exact overhead measurement.
Explain the timer one piece at a time
| Piece | Explanation |
|---|---|
<time.h> |
Declares time-related types and functions |
struct timespec start, finish |
Two records, each storing seconds (tv_sec) and nanoseconds (tv_nsec) |
&start and &finish |
Pass the address of each record so the clock function can fill it |
CLOCK_MONOTONIC |
A clock suitable for measuring elapsed intervals, with an unspecified origin |
/ 1e9 |
Converts the difference in nanoseconds to seconds |
elapsed |
The seconds difference plus the nanoseconds difference converted to seconds |
CLOCK_MONOTONIC does not jump when the civil clock is reset. Its absolute reading is not a calendar date; use the difference. Nanosecond fields do not promise nanosecond accuracy or effective resolution. The timer calls themselves have overhead, so time substantial work.
Subtracting the clock readings
Each reading has a whole-second part and a nanosecond part. There are one billion nanoseconds in a second, so 1e9 converts the nanosecond difference to seconds.
The fractional difference can be negative. Going from 10.8 seconds to 12.3 seconds gives:
(12 - 10) + (0.3 - 0.8) = 2 - 0.5 = 1.5 seconds
Time did not go backward. We subtracted the whole and fractional parts separately, then added the differences.
Use the GCC commands shown here, without adding -std=c11. Strict C11 mode can hide the system timer declarations. Keep #include <time.h> at the top of the file.
This introductory example assumes the clock calls succeed. In a program intended for wider use, we would check their return values too. The book uses its own timer.h; this example uses the system timer directly.
Why exclude setup and printing?
The two measurements cover different parts of the program:
Whole program: [ setup | start | computational loop | finish | print ]
Internal time: [ computational loop ]
Think about it: If we printed every partial sum inside the loop, what would our time describe?
Change the compiler setting, then measure repeatedly
Build two versions of the same source
gcc -g -Wall -O0 -o sum_O0 sum_timed.c
gcc -g -Wall -O2 -o sum_O2 sum_timed.c
./sum_O0
./sum_O2Before looking at times, check that the printed sums agree. Both builds must use the same n. Keep both executables so there is no ambiguity about which version ran.
Think about it: The source and algorithm are the same. What can the compiler change?
-O2 requests GCC’s level-two collection of optimizations. GCC may simplify work, improve generated instruction sequences, and apply eligible transformations while respecting the language rules. It does not mean “twice as fast,” “use two cores,” or “optimize exactly twice.”
-O0 disables most optimization passes; -O2 enables many. The exact set depends on GCC version and target, and enabling a pass does not guarantee that it applies to this loop. This setting does not guarantee any particular transformation of our loop, and it does not make the program run on multiple cores. Optimization can increase compilation time and complicate debugging. Keeping -g is allowed.
We will normally use -O2 when measuring performance.
Our harmonic sum includes division and a running dependency: each addition uses the previous sum. It may show a modest improvement, a large one, or no clear benefit. A small difference is a useful result, especially if it is comparable to variation between trials.
Run a small experiment
Run each version once to get started. Then run this pair of commands five times, writing down the times after each pair:
./sum_O0
./sum_O2On every other pair, run sum_O2 first. Use the up-arrow key to recall commands. Record the number labeled Time for the loop; use the same kind of time in every comparison.
Node: ________ Compiler/version: ________ n: ________
| Trial | -O0 seconds |
-O2 seconds |
|---|---|---|
| 1 | ||
| 2 | ||
| 3 | ||
| 4 | ||
| 5 | ||
| Minimum |
Circle the smallest time in each column. If time permits, calculate how much faster one build was:
\[ \text{observed speedup} = \frac{\text{minimum time with }-O0}{\text{minimum time with }-O2}. \]
For example, hypothetical minima of 1.2 seconds and 0.8 seconds give a factor of 1.5, or about 33% less elapsed time. This is an optimization comparison, not parallel speedup.
Keep all five times. The minimum gives us the fastest run we observed, but also look at how much the values vary. If one unusually low time changes the conclusion, collect more trials. You can also compare medians—the middle values after sorting. Use the same statistic for both versions.
Compare and explain
Think about it: Why did the same executable take different amounts of time?
A defensible report: “On node , with GCC and ___ terms, the minimum of five measured trials changed from ___ s to ___ s. The other trials ranged from ___ to ___; the printed sums agreed.”
Does memory order matter?
Predict first: These two traversal orders visit every matrix element and perform the same number of additions. Should their runtimes match?
C’s two-dimensional arrays use row-major storage. The elements of a row are adjacent. Visiting columns of that same array does not change its storage layout; it changes the access order.
For a 3-by-3 array, increasing memory addresses look like this:
[a00 a01 a02] [a10 a11 a12] [a20 a21 a22]
Row traversal: a00 → a01 → a02 → a10 → a11 → ...
Column traversal: a00 → a10 → a20 → a01 → a11 → ...
Complete locality.c
We will add up the same array twice: first across rows, then down columns. Focus on the order of the two loops. Everything inside each pair of loops is the same.
#include <stdio.h>
#include <time.h>
#define N 4096
double a[N][N];
int main(void) {
/* Fill the array before starting either timer. */
for (int i = 0; i < N; i++) {
for (int j = 0; j < N; j++) {
a[i][j] = i + j;
}
}
double row_sum = 0.0;
double column_sum = 0.0;
struct timespec start, finish;
/* Across each row: j changes fastest. */
clock_gettime(CLOCK_MONOTONIC, &start);
for (int i = 0; i < N; i++) {
for (int j = 0; j < N; j++) {
row_sum += a[i][j];
}
}
clock_gettime(CLOCK_MONOTONIC, &finish);
double row_time = (finish.tv_sec - start.tv_sec)
+ (finish.tv_nsec - start.tv_nsec) / 1e9;
/* Down each column: i changes fastest. */
clock_gettime(CLOCK_MONOTONIC, &start);
for (int j = 0; j < N; j++) {
for (int i = 0; i < N; i++) {
column_sum += a[i][j];
}
}
clock_gettime(CLOCK_MONOTONIC, &finish);
double column_time = (finish.tv_sec - start.tv_sec)
+ (finish.tv_nsec - start.tv_nsec) / 1e9;
printf("Across rows: %.4f seconds\n", row_time);
printf("Down columns: %.4f seconds\n", column_time);
printf("Row sum: %.0f\n", row_sum);
printf("Column sum: %.0f\n", column_sum);
return 0;
}gcc -g -Wall -O2 -o locality locality.c
./localityRead the output
The output looks like this. The times below are made-up examples; your times will differ.
Across rows: 0.0400 seconds
Down columns: 0.2400 seconds
Row sum: 68702699520
Column sum: 68702699520
Start with the first two lines: smaller means faster. In this example, going down columns took six times as long. Then check the last two lines: both ways produced the same total.
The two sums are the answers to the calculation. Printing them lets us check that the two loops agree and gives the compiler a reason to keep the calculation. If we compute a value and never use it, an optimizing compiler may remove that work.
These particular entries and totals are whole numbers small enough to be represented exactly by the double type on our system. With arbitrary fractional values, changing addition order can introduce small rounding differences.
Why access order can matter
The processor keeps blocks of recently used data in a small, fast cache. Across a row, the next value is next door in memory and may already be in the block just fetched. Down a column, the next value is a whole row away. Using nearby data close together in time is called spatial locality.
Predict, run, explain
Run ./locality three times and record just the first two lines each time:
| Run | Across rows (seconds) | Down columns (seconds) |
|---|---|---|
| 1 | ||
| 2 | ||
| 3 |
Think about it: Which order was faster? Was that consistent across all three runs?
Both loops add the same numbers. Why might one take longer?
Why this array size?
#define N 4096 gives the array 4096 rows and 4096 columns. With eight bytes per double, that uses 128 MiB, or about 0.13 GB. That is a useful starting size for making memory access visible on a machine with several gigabytes of RAM. It is the fast cache, not all of RAM, that we want the array to exceed.
#define N 4096 names a fixed size. To try a different size, edit this one line and recompile. The array is declared outside main so it does not occupy the small stack normally used for local variables. This lets us use a large array without allocating it on the stack.
The array is initialized before either timer starts, and printing happens after both timers stop. The example always times rows first. For a follow-up check, move the entire column-timing block above the row-timing block and repeat; compare whether the conclusion holds. Initialization and earlier work affect cache state, so these are not controlled cold-cache measurements.
If the difference is small, record that honestly. Timing depends on the processor, compiler, and other activity as well as locality. If you share a machine with others, take turns running the experiment. If memory is busy, use N = 2048 by changing the definition to #define N 2048; that uses 32 MiB. The exact sums will change too.
Check your understanding
- Write a command that builds
sum_timed.cwith warnings, debugging information, and level-two optimization, naming the resultsum_fast. - Explain why
time sleep 2can report about two real seconds but almost no CPU time. - Identify exactly what the internal timer excludes, and name one reason repeated results vary.
- State one observation from your experiments and one limitation of your explanation.
Optional extensions
Try one of these next:
- Scale the workload: Change
ninsum_timed.cto200000000LLand rebuild both versions. Predict and measure how doubling the work changes elapsed time. Keep old executables under distinct names. - Make a warning useful: Add an unused local variable to
hello.c, rebuild with-Wall, and explain the message. Remove it and rebuild cleanly. - Look at compiler output: Use
gcc -O2 -S sum_timed.c -o sum_timed.s.-Sstops at assembly text. Inspect it withless; this does not make an executable. Notice how different this representation is from the C source. You do not need to understand each instruction yet. - Measure end-to-end work: Compare shell and internal timings for locality. Explain the initialization, both traversals, and printing included in the whole-program measurement.
- Think ahead: Which parts of summing could be divided among workers? What partial results would need to be combined?
Quick troubleshooting reference
| Symptom | First thing to check |
|---|---|
gcc: command not found |
Confirm you are on the assigned Linux node; ask me about the course compiler setup |
| Source file not found | pwd, ls, spelling, and whether the editor saved the file |
Bare hello is not found |
Use ./hello |
| Output still shows old greeting | Save, rebuild successfully, then run the correct executable |
| Timer symbol undeclared | Include <time.h> and use the shown GCC command in its default mode; ask me if it still fails |
| Undefined reference to clock function on old Linux | Try -lrt at the end of the compile command |
| Near-zero or erratic times | Increase useful work cautiously; verify the result and repeat |
| Run takes too long | Ctrl+C stops it; reduce the size and rebuild both versions consistently |
| Locality program is killed | Check free -h, reduce N to 2048, and stagger shared-node runs |