From d0b946f327f0f464818a1c759c1099cab0612c9c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Thomas=20Lov=C3=A9n?= Date: Mon, 4 Dec 2017 12:27:45 +0100 Subject: [PATCH] Chapter 6: Debug Output - COMPLETE --- doc/6_Debug_Output.md | 288 ++++++++++++++++++++++++++++++++++++++++++ doc/README.md | 1 + 2 files changed, 289 insertions(+) create mode 100644 doc/6_Debug_Output.md diff --git a/doc/6_Debug_Output.md b/doc/6_Debug_Output.md new file mode 100644 index 0000000..c24b978 --- /dev/null +++ b/doc/6_Debug_Output.md @@ -0,0 +1,288 @@ +# Debug Output + +In this chapter we'll be looking at some ways of getting status information out +of the kernel. + +## The printf function and TDD + +I really like having access to a printf-like function when developing. It just +makes debugging so much easier. + +For further convenience, I want the debug printer to print both to screen and +to a serial port. + +Now, I'm doing this as a learning experience, and one thing I've been meaning +to practice is Test-Driven Development. So let's write the debug printing that +way. + +Let's start very simple. A function that outputs a character to VGA and to +serial. Assuming (slightly prematurely) that we'll have two functions `void +vga_write(char c)` and `void serial_write(uint16_t port, uint8_t c)` The test +could look like this: + +`src/kernel/boot/debug.tt` +```c +char vga_recv; +char serial_recv; + +void vga_write(char c) +{ + vga_recv = c; +} +void serial_write(uint16_t port, uint8_t c) +{ + serial_recv = (char)c; +} + +TEST(putch_sends_character_to_vga) +{ + debug_putch('a'); + ASSERT_EQ_CHR(vga_recv, 'a'); +} +TEST(putch_sends_character_to_serial) +{ + debug_putch('a'); + ASSERT_EQ_CHR(serial_recv, 'a'); +} +``` + +... which can be made to pass with a simple function like: + +`src/kernel/boot/debug.c` +```c +void debug_putch(char c) +{ + vga_write(c); + serial_write(PORT_COM1, c); +} +``` + +... with some `#define`s and `#include`s and such, of course. + +As I understand it, in efficient TDD, you should write one test at a time, and +then make that pass - so that's what I tried to do, but I'm presenting more +than one test at a time for brevity. + +Next is writing strings, which requires an update to the mock functions: + +`src/kernel/boot/debug.tt` +```c +char vga_recv[BUFFER_SIZE]; +char serial_recv[BUFFER_SIZE]; + +BEFORE() +{ + for(int i= 0; i < BUFFER_SIZE; i++) + { + vga_recv[i] = '\0'; + serial_recv[i] = '\0'; + } +} + +void vga_write(char c) +{ + static int i = 0; + vga_recv[i++] = c; +} +void serial_write(uint16_t port, uint8_t c) +{ + static int i = 0; + serial_recv[i++] = (char)c; +} + +TEST(putsn_writes_string) +{ + char *str = "hello"; + debug_putsn(str, 5); + ASSERT_EQ_STR(vga_recv, str, BUFFER_SIZE); +} +TEST(putsn_writes_correct_number_of_characters) +{ + char *str = "1234567890"; + debug_putsn(str, 5); + ASSERT_EQ_STR(vga_recv, "12345", BUFFER_SIZE); +} +``` + + +`src/kernel/boot/debug.c` +```c +debug_putsn(char *s, size_t n) +{ + while(n--) + debug_putch(*s++); +} +``` + +Then there's `debug_printf`, which is left as an exercise for the reader - or +you could just look through my code. + +> You'll probably find that my implementation, among many other things, is +> influenced by [musl libc](https://www.musl-libc.org/) which is a very clean +> standard library implementation. We'll take a much closer look at musl later... + +The names of the tests are: +- `printf_prints_string` +- `printf_does_not_print_percent` +- `printf_prints_binary_number` +- `printf_prints_octal_number` +- `printf_prints_decimal_number` +- `printf_prints_hexadecimal_number` +- `printf_prints_char` +- `printf_prints_passed_string` +- `printf_keeps_printing_after_number` +- `printf_prints_text_around_number` +- `printf_keeps_going_for_unknown_format_specifier` +- `printf_pads_value` +- `printf_pads_more_than_9` +- `printf_zero_pads` + +## Printing to screen + +Next, let's look at `vga_write()`. + +I tried to use TDD for this as well, and that had an unexpected outcome. + +In order to test VGA printing, I had to mock up VGA hardware somehow - or at +least the VGA memory mapping. + +This brought me two realizations. + +First of all, each character on screen is described by a 16 bit value - one +byte for the character and one for the color attribute. + +This can be implemented as a structure: + +`src/kernel/drivers/vga.c` +```c +struct vga_cell { + uint8_t c; + uint8_t f; +}__attribute__((packed)); + +struct vga_cell buffer[24*80] = (void *)0xB8000; +... +``` + +The second realization was that each screen line comes right after the previous +one in memory. + +This seems obvious, of course - but stay with me. + +You've probably gone through some kernel development tutorial at +some point (I'd assume [Brandon Friesen's](http://www.osdever.net/bkerndev/Docs/title.htm), +[James Molloy's](http://www.jamesmolloy.co.uk/tutorial_html/) or +[The osdev.org Bare Bones ](http://wiki.osdev.org/Bare_Bones)). +If so, you may have a `putch()`, `monitor_put()` or +`terminal_putchar()` function which writes a character to screen, +increases a counter, and if it has reached the end of a line, goes +to the next. + +See where I'm going with this? There's no point in keeping track on the line +and column separately. All you need is a single counter. + +That makes my corresponding function very short and simple: + +`src/kernel/drivers/vga.c` +```c +... +uint64_t cursor = 0; + +void vga_write(char c) +{ + switch(c) + { + case '\n': + cursor += 80 - (cursor%80); + break; + default: + buffer[cursor++] = (struct vga_cell){.c = c, .f=7}; + } + scroll(); +} +``` + +`scroll()` scrolls the screen if we pass beyond the last line, and is also very simple: + +```c +... +void scroll() +{ + memmove(buffer, &buffer[80], 80*(24-1)*sizeof(struct vga_cell)); + memset(&buffer[80*(24-1)], 0, 80*sizeof(struct vga_cell)); + cursor -= 80; +} +... +``` + +As a final note, the line `struct vga_cell buffer[24*80] = (void *)0xB8000;` is +a really bad one. You should make sure to use double buffering when dealing +with VGA memory. The reason for this is that *reading* from VGA memory (such as +when scrolling the screen) is really really slow. + +## Bonus: PANIC + +Sometimes, things go wrong. + +When they do, you probably want to know, and perhaps get a chance to find out +why, or even to put things right. + +For this reason, I made a `PANIC()` macro. The definition looks like this: + +`src/kernel/include/debug.h` +```c +... +#define S(x) #x +#define S_(x) S(x) +#define S__LINE__ S_(__LINE__) + +#define PANIC(...) \ + do{ \ + debug_printf("\n\nKernel panic!\n%s:%d\n", __FILE__, __LINE__); \ + debug_printf(__VA_ARGS__); \ + volatile int _override = 0; \ + while(1){ \ + asm("panic_breakpoint_" S__LINE__ ":"); \ + if(_override) break; \ + } \ + }while(0) +... +``` + +It's pretty simple actually. It just prints an error message, and then loops +infinitely. + +However, the loop can be broken out of by changing the value of `_override` by +e.g. breaking in gdb and running + +```gdb +(gdb) set _override=1 +``` + +The `asm` line creates a label in the code, which you can add as a breakpoint +in gdb. The `S__LINE__` stuff and related macros is so that the labels will be +unique if you call `PANIC()` twice in the same source file (gdb will happily +break at any of several labels with the same name, but gcc doesn't like two +equal labels in the same file). + +Gdb has a neat command called `rbreak` which sets breakpoints based on a +regular expression. Unfortunately that only works for functions - not labels. +Therefore, I put the following function in gdbinit, to automatically find all +`panic_breakpoint`s and add them to gdb. + +`toolchain/gdbinit` +```gdb +... +python +import subprocess +import os +dump = subprocess.Popen(("objdump", "-t", os.environ['BUILDROOT'] + "sysroot/kernel"), stdout=subprocess.PIPE) +lines = subprocess.check_output(('grep', 'panic_breakpoint'), stdin=dump.stdout) +dump.wait() +for line in lines.split('\n'): + name = line.split(' ')[-1] + if name: + gdb.execute('b ' + name, to_string=True) +end +... +``` diff --git a/doc/README.md b/doc/README.md index 1270d38..4398193 100644 --- a/doc/README.md +++ b/doc/README.md @@ -8,4 +8,5 @@ [Chapter 3: Activate Long Mode](3_Activate_Long_Mode.md)
[Chapter 4: "Higher Half" Kernel](4_Higher_Half_Kernel.md)
[Chapter 5: Unit Testing Framework](5_Unit_Testing.md)
+[Chapter 6: Debug output](6_Debug_Output.md)