michaelkuc6/blog_os
1
0
Fork 0
mirror of https://github.com/phil-opp/blog_os.git synced 2025-12-16 22:37:49 +00:00
Code Issues Projects Releases Wiki Activity

Exceptions inside printlns are no longer a problem

Browse Source 
The recent update to the vga driver evaluates the arguments before locking the global stdout writer
This commit is contained in:
Philipp Oppermann
2016-10-30 17:32:04 +01:00
parent 41c87636e0
commit ca522db7bf
1 changed files with 0 additions and 124 deletions
Download Patch File Download Diff File Expand all files Collapse all files

124
blog/post/09-catching-exceptions.md
View File

@@ -549,129 +549,5 @@ It works! We see a `EXCEPTION: DIVIDE BY ZERO` message at the bottom of our scre
![QEMU screenshot with `EXCEPTION: PAGE BY ZERO` message](images/qemu-divide-error-println.png) ![QEMU screenshot with `EXCEPTION: PAGE BY ZERO` message](images/qemu-divide-error-println.png)
### Exceptions inside println
What happens when the exception occurs in the body of a `println`? Let's try:
```rust
pub extern "C" fn rust_main(...) {
...
interrupts::init();
// provoke a divide by zero fault inside println
println!("{:?}", divide_by_zero());
println!("It did not crash!");
loop {}
}
```
Now the output ends on the `guard page` line. No `EXCEPTION` message and no `It did not crash` message either. What's happening?
#### Debugging
Let's debug it using [GDB]. It is a console debugger and works with nearly everything, including QEMU. To make QEMU listen for a debugger connection, we start it with the `-s` flag:
[GDB]: https://www.gnu.org/software/gdb/
```Makefile
# in `Makefile`
run: $(iso)
@qemu-system-x86_64 -cdrom $(iso) -s
```
Then we can launch GDB in another console window:
```
> gdb build/kernel-x86_64.bin
[some version, copyright, and usage information]
Reading symbols from build/kernel-x86_64.bin...done.
(gdb)
```
Now we can connect to our running QEMU instance on port `1234`:
```
(gdb) target remote :1234
Remote debugging using :1234
0x00000000001031bd in spin::mutex::cpu_relax ()
at /home/.../spin-0.3.5/src/mutex.rs:102
102 unsafe { asm!("pause" :::: "volatile"); }
```
So we're locked in a function named `mutex::cpu_relax` inside the `spin` crate. Let's try a backtrace:
```
(gdb) backtrace
#0 0x00000000001031bd in spin::mutex::cpu_relax ()
at /home/.../spin-0.3.5/src/mutex.rs:102
#1 spin::mutex::{{impl}}::obtain_lock<blog_os::vga_buffer::Writer> (
self=0x111230 <blog_os::vga_buffer::WRITER::h702c3f466147ac3b>)
at /home/.../spin-0.3.5/src/mutex.rs:142
#2 0x0000000000103143 in spin::mutex::{{impl}}::lock<blog_os::vga_buffer::
Writer> (
self=0x111230 <blog_os::vga_buffer::WRITER::h702c3f466147ac3b>)
at /home/.../spin-0.3.5/src/mutex.rs:163
#3 0x000000000010da59 in blog_os::interrupts::divide_by_zero_handler ()
at src/vga_buffer.rs:31
...
```
Pretty verbose… and very useful. Let's clean it up a bit:
- `spin::mutex::cpu_relax`
- `spin::mutex::obtain_lock<vga_buffer::Writer>`
- `spin::mutex::lock<vga_buffer::Writer>`
- `blog_os::interrupts::divide_by_zero_handler`
- ...
It's a _back_-trace, so it goes from the innermost function to the outermost function. We see that our divide-by-zero handler was called successfully. It then tried to write its error message. Therefore, it tried to `lock` the static `WRITER`, which in turn called `obtain_lock` and `cpu_relax`.
So our kernel tries to lock the output `WRITER`, which is already locked by the interrupted `println`. Thus, our exception handler waits forever and we don't see what error occurred. Yay, that's our first deadlock! :)
(As you see, GDB can be very useful sometimes. For more information about GDB check out our [Set Up GDB] page.)
[Set Up GDB]: {{% relref "set-up-gdb.md" %}}
## Printing Errors Reliably
In order to guarantee that we always see error messages, we add a `print_error` function to our `vga_buffer` module:
```rust
// in src/vga_buffer.rs
pub unsafe fn print_error(fmt: fmt::Arguments) {
use core::fmt::Write;
let mut writer = Writer {
column_position: 0,
color_code: ColorCode::new(Color::Red, Color::Black),
buffer: Unique::new(0xb8000 as *mut _),
};
writer.new_line();
writer.write_fmt(fmt);
}
```
Instead of using the static `WRITER`, this function creates a new `Writer` on each invocation. Thereby it ignores the mutex and is always able to print to the screen without deadlocking. We print in red to highlight the error and add a newline to avoid overwriting unfinished lines.
### Safety
This function clearly violates the invariants of the `vga_buffer` module, as it creates another `Unique` pointing to `0xb8000`. Thus, we deliberately introduce a data race on the VGA buffer. For this reason, the function is marked as `unsafe` and should only be used if absolutely necessary.
However, the situation is not _that_ bad. The VGA buffer only stores characters (no pointers) and we never rely on the buffer's values. So the function might cause mangled output, but should never be able to violate memory safety. Nevertheless, we will implement a better solution in a future post.
### Using print_error
Let's use the new `print_error` function to print the divide-by-zero error:
```rust
// in src/interrupts/mod.rs
use vga_buffer::print_error;
extern "C" fn divide_by_zero_handler() -> ! {
unsafe { print_error(format_args!("EXCEPTION: DIVIDE BY ZERO")) };
loop {}
}
```
We use the built-in [format_args] macro to translate the error string to a `fmt::Arguments` type. Now we should always see the error message, even if the exception occurred inside `println`:
[format_args]: https://doc.rust-lang.org/nightly/std/macro.format_args!.html
![QEMU screenshot with new red `EXCEPTION: PAGE BY ZERO` message](images/qemu-divide-error-red.png)
## What's next? ## What's next?
We've successfully caught our first exception! However, our `EXCEPTION: DIVIDE BY ZERO` message doesn't contain much information about the cause of the exception. The next post improves the situation by printing i.a. the current stack pointer and address of the causing instruction. We will also explore other exceptions such as page faults, for which the CPU pushes an _error code_ on the stack. We've successfully caught our first exception! However, our `EXCEPTION: DIVIDE BY ZERO` message doesn't contain much information about the cause of the exception. The next post improves the situation by printing i.a. the current stack pointer and address of the causing instruction. We will also explore other exceptions such as page faults, for which the CPU pushes an _error code_ on the stack.