Merge pull request #249 from phil-opp/fix-println-deadlock

Update `print` macro to avoid deadlock; remove hacky `print_error` function

blog/post/04-printing-to-screen.md

@@ -253,10 +253,12 @@ pub fn print_something() {
     writer.write_byte(b'H');
 }
 ```
-It just creates a new Writer that points to the VGA buffer at `0xb8000`. Then it writes the byte `b'H'` to it. The `b` prefix creates a [byte character], which represents an ASCII code point. When we call `vga_buffer::print_something` in main, a `H` should be printed in the _lower_ left corner of the screen in light green.
+It just creates a new Writer that points to the VGA buffer at `0xb8000`. Then it writes the byte `b'H'` to it. The `b` prefix creates a [byte character], which represents an ASCII code point. When we call `vga_buffer::print_something` in main, a `H` should be printed in the _lower_ left corner of the screen in light green:
 
 [byte character]: https://doc.rust-lang.org/reference.html#characters-and-strings
 
+![QEMU output with a green `H` in the lower left corner](images/vga-H-lower-left.png)
+
 ### Volatile
 We just saw that our `H` was printed correctly. However, it might not work with future Rust compilers that optimize more aggressively.
 
@@ -353,11 +355,13 @@ When you print strings with some special characters like `ä` or `λ`, you'll no
 [UTF-8]: http://www.fileformat.info/info/unicode/utf8.htm
 
 ### Support Formatting Macros
-It would be nice to support Rust's formatting macros, too. That way, we can easily print different types like integers or floats. To support them, we need to implement the [core::fmt::Write] trait. The only required method of this trait is `write_str` that looks quite similar to our `write_str` method. To implement the trait, we just need to move it into an `impl ::core::fmt::Write for Writer` block and add a return type:
+It would be nice to support Rust's formatting macros, too. That way, we can easily print different types like integers or floats. To support them, we need to implement the [core::fmt::Write] trait. The only required method of this trait is `write_str` that looks quite similar to our `write_str` method. To implement the trait, we just need to move it into an `impl fmt::Write for Writer` block and add a return type:
 
 ```rust
-impl ::core::fmt::Write for Writer {
+use core::fmt;
-    fn write_str(&mut self, s: &str) -> ::core::fmt::Result {
+
+impl fmt::Write for Writer {
+    fn write_str(&mut self, s: &str) -> fmt::Result {
         for byte in s.bytes() {
           self.write_byte(byte)
         }
@@ -369,15 +373,16 @@ The `Ok(())` is just a `Ok` Result containing the `()` type. We can drop the `pu
 
 Now we can use Rust's built-in `write!`/`writeln!` formatting macros:
 
-```rust
+{{< highlight rust "hl_lines=2 4 5 6" >}}
 // in the `print_something` function
 use core::fmt::Write;
 let mut writer = Writer {...};
 writer.write_byte(b'H');
 writer.write_str("ello! ");
 write!(writer, "The numbers are {} and {}", 42, 1.0/3.0);
-```
+{{< / highlight >}}
-Now you should see a `Hello! The numbers are 42 and 0.3333333333333333` in strange colors at the bottom of the screen.
+
+Now you should see a `Hello! The numbers are 42 and 0.3333333333333333` at the bottom of the screen.
 
 [core::fmt::Write]: https://doc.rust-lang.org/nightly/core/fmt/trait.Write.html
 
@@ -506,7 +511,9 @@ macro_rules! println {
     ($fmt:expr, $($arg:tt)*) => (print!(concat!($fmt, "\n"), $($arg)*));
 }
 ```
-It just adds a `\n` and then invokes the [`print!` macro], which is defined as:
+Macros are defined through one or more rules, which are similar to `match` arms. The `println` macro has two rules: The first rule is for invocations with a single argument (e.g. `println!("Hello")`) and the second rule is for invocations with additional parameters (e.g. `println!("{}{}", 4, 2)`).
+
+Both rules simply append a newline character (`\n`) to the format string and then invoke the [`print!` macro], which is defined as:
 
 [`print!` macro]: https://doc.rust-lang.org/nightly/std/macro.print!.html
 
@@ -515,9 +522,14 @@ macro_rules! print {
     ($($arg:tt)*) => ($crate::io::_print(format_args!($($arg)*)));
 }
 ```
-It calls the `_print` method in the `io` module of the current crate (`$crate`), which is `std`. The [`_print` function] in libstd is rather complicated, as it supports different `Stdout` devices.
+The macro expands to a call of the [`_print` function] in the `io` module. The [`$crate` variable] ensures that the macro also works from outside the `std` crate. For example, it expands to `::std` when it's used in other crates.
 
-[`_print` function]: https://doc.rust-lang.org/nightly/src/std/io/stdio.rs.html#578
+The [`format_args` macro] builds a [fmt::Arguments] type from the passed arguments, which is passed to `_print`. The [`_print` function] of libstd is rather complicated, as it supports different `Stdout` devices. We don't need that complexity since we just want to print to the VGA buffer.
+
+[`_print` function]: https://github.com/rust-lang/rust/blob/46d39f3329487115e7d7dcd37bc64eea6ef9ba4e/src/libstd/io/stdio.rs#L631
+[`$crate` variable]: https://doc.rust-lang.org/book/macros.html#the-variable-crate
+[`format_args` macro]: https://doc.rust-lang.org/nightly/std/macro.format_args.html
+[fmt::Arguments]: https://doc.rust-lang.org/nightly/core/fmt/struct.Arguments.html
 
 To print to the VGA buffer, we just copy the `println!` macro and modify the `print!` macro to use our static `WRITER` instead of `_print`:
 
@@ -525,15 +537,15 @@ To print to the VGA buffer, we just copy the `println!` macro and modify the `pr
 // in src/vga_buffer.rs
 macro_rules! print {
     ($($arg:tt)*) => ({
-            use core::fmt::Write;
+        use core::fmt::Write;
-            let mut writer = $crate::vga_buffer::WRITER.lock();
+        let mut writer = $crate::vga_buffer::WRITER.lock();
-            writer.write_fmt(format_args!($($arg)*)).unwrap();
+        writer.write_fmt(format_args!($($arg)*)).unwrap();
     });
 }
 ```
 Instead of a `_print` function, we call the `write_fmt` method of our static `Writer`. Since we're using a method from the `Write` trait, we need to import it before. The additional `unwrap()` at the end panics if printing isn't successful. But since we always return `Ok` in `write_str`, that should not happen.
 
-Note the additional `{}` scope around the macro: I wrote `=> ({…})` instead of `=> (…)`. The additional `{}` avoids that the `Write` trait is silently imported when `print` is used.
+Note the additional `{}` scope around the macro: We write `=> ({…})` instead of `=> (…)`. The additional `{}` avoids that the `Write` trait is silently imported to the parent scope when `print` is used.
 
 ### Clearing the screen
 We can now use `println!` to add a rather trivial function to clear the screen:
@@ -549,7 +561,7 @@ pub fn clear_screen() {
 ### Hello World using `println`
 To use `println` in `lib.rs`, we need to import the macros of the VGA buffer module first. Therefore we add a `#[macro_use]` attribute to the module declaration:
 
-```rust
+{{< highlight rust "hl_lines=3 9 10" >}}
 // in src/lib.rs
 
 #[macro_use]
@@ -563,9 +575,66 @@ pub extern fn rust_main() {
 
     loop{}
 }
-```
+{{< / highlight >}}
+
 Since we imported the macros at crate level, they are available in all modules and thus provide an easy and safe interface to the VGA buffer.
 
+As expected, we now see a _“Hello World!”_ on a cleared screen:
+
+![QEMU printing “Hello World!” on a cleared screen](images/vga-hello-world.png)
+
+### Deadlocks
+Whenever we use locks, we must be careful to not accidentally introduce _deadlocks_. A [deadlock] occurs when a thread/program waits for a lock that will never be released. Normally, this happens when multiple threads access multiple locks. For example, when thread A holds lock 1 and tries to acquire lock 2 and -- at the same time -- thread B holds lock 2 and tries to acquire lock 1.
+
+[deadlock]: https://en.wikipedia.org/wiki/Deadlock
+
+However, a deadlock can also occur when a thread tries to acquire the same lock twice. This way we can trigger a deadlock in our VGA driver:
+
+```rust
+// in rust_main in src/lib.rs
+
+println!("{}", { println!("inner"); "outer" });
+```
+The argument passed to `println` is new block that resolves to the string _“outer”_ (a block always returns the result of the last expression). But before returning “outer”, the block tries to print the string _“inner”_.
+
+When we try this code in QEMU, we see that neither of the strings are printed. To understand what's happening, we take a look at our `print` macro again:
+
+```rust
+macro_rules! print {
+    ($($arg:tt)*) => ({
+        use core::fmt::Write;
+        let mut writer = $crate::vga_buffer::WRITER.lock();
+        writer.write_fmt(format_args!($($arg)*)).unwrap();
+    });
+}
+```
+So we _first_ lock the `WRITER` and then we evaluate the arguments using `format_args`. The problem is that the argument in our code example contains another `println`, which tries to lock the `WRITER` again. So now the inner `println` waits for the outer `println` and vice versa. Thus, a deadlock occurs and the CPU spins endlessly.
+
+### Fixing the Deadlock
+In order to fix the deadlock, we need to evaluate the arguments _before_ locking the `WRITER`. We can do so by moving the locking and printing logic into a new `print` function (like it's done in the standard library):
+
+```rust
+// in src/vga_buffer.rs
+
+macro_rules! print {
+    ($($arg:tt)*) => ({
+        $crate::vga_buffer::print(format_args!($($arg)*));
+    });
+}
+
+pub fn print(args: fmt::Arguments) {
+    use core::fmt::Write;
+    WRITER.lock().write_fmt(args).unwrap();
+}
+```
+Now the macro only evaluates the arguments (through `format_args!`) and passes them to the new `print` function. The `print` function then locks the `WRITER` and prints the formatting arguments using `write_fmt`. So now the arguments are evaluated before locking the `WRITER`.
+
+Thus, we fixed the deadlock:
+
+![QEMU printing “inner” and then “outer”](images/fixed-println-deadlock.png)
+
+We see that both “inner” and “outer” are printed.
+
 ## What's next?
 In the next posts we will map the kernel pages correctly so that accessing `0x0` or writing to `.rodata` is not possible anymore. To obtain the loaded kernel sections we will read the Multiboot information structure. Then we will create a paging module and use it to switch to a new page table where the kernel sections are mapped correctly.
 

blog/post/09-catching-exceptions.md

@@ -547,131 +547,7 @@ pub extern "C" fn rust_main(...) {
 
 It works! We see a `EXCEPTION: DIVIDE BY ZERO` message at the bottom of our screen:
 
-![QEMU screenshot with `EXCEPTION: PAGE BY ZERO` message](images/qemu-divide-error-println.png)
+![QEMU screenshot with `EXCEPTION: DIVIDE 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?
 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.

blog/post/10-better-exception-messages.md

@@ -58,8 +58,8 @@ extern "C" fn divide_by_zero_handler() -> ! {
     let stack_frame: *const ExceptionStackFrame;
     unsafe {
         asm!("mov $0, rsp" : "=r"(stack_frame) ::: "intel");
-        print_error(format_args!("EXCEPTION: DIVIDE BY ZERO\n{:#?}",
+        println!("\nEXCEPTION: DIVIDE BY ZERO\n{:#?}",
-            *stack_frame));
+            *stack_frame);
     };
     loop {}
 }
@@ -172,10 +172,8 @@ extern "C" fn divide_by_zero_wrapper() -> ! {
 extern "C" fn divide_by_zero_handler(stack_frame: *const ExceptionStackFrame)
     -> !
 {
-    unsafe {
+    println!("\nEXCEPTION: DIVIDE BY ZERO\n{:#?}",
-        print_error(format_args!("EXCEPTION: DIVIDE BY ZERO\n{:#?}",
+        unsafe { &*stack_frame });
-            *stack_frame));
-    }
     loop {}
 }
 
@@ -194,7 +192,7 @@ call divide_by_zero_handler
 ```
 It moves the exception stack frame pointer from `rsp` to `rdi`, where the first argument is expected, and then calls the main handler. Let's create the corresponding inline assembly to complete our wrapper function:
 
-```rust
+{{< highlight rust "hl_lines=4 5 6" >}}
 #[naked]
 extern "C" fn divide_by_zero_wrapper() -> ! {
     unsafe {
@@ -203,7 +201,8 @@ extern "C" fn divide_by_zero_wrapper() -> ! {
              : "rdi" : "intel");
     }
 }
-```
+{{< / highlight >}}<!--end_-->
+
 Instead of `call divide_by_zero_handler`, we use a placeholder again. The reason is Rust's name mangling, which changes the name of the `divide_by_zero_handler` function. To circumvent this, we pass a function pointer as input parameter (after the second colon). The `"i"` tells the compiler that it is an immediate value, which can be directly inserted for the placeholder. We also specify a clobber after the third colon, which tells the compiler that we change the value of the `rdi` register.
 
 ### Intrinsics::Unreachable
@@ -218,7 +217,7 @@ error: computation may converge in a function marked as diverging
 ```
 The reason is that we marked our `divide_by_zero_wrapper` function as diverging (the `!`). We call another diverging function in inline assembly, so it is clear that the function diverges. However, the Rust compiler doesn't understand inline assembly, so it doesn't know that. To fix this, we tell the compiler that all code after the `asm!` macro is unreachable:
 
-```rust
+{{< highlight rust "hl_lines=7" >}}
 #[naked]
 extern "C" fn divide_by_zero_wrapper() -> ! {
     unsafe {
@@ -228,7 +227,8 @@ extern "C" fn divide_by_zero_wrapper() -> ! {
         ::core::intrinsics::unreachable();
     }
 }
-```
+{{< / highlight >}}<!--end_-->
+
 The [intrinsics::unreachable] function is unstable, so we need to add `#![feature(core_intrinsics)]` to our `src/lib.rs`. It is just an annotation for the compiler and produces no real code. (Not to be confused with the [unreachable!] macro, which is completely different!)
 
 [intrinsics::unreachable]: https://doc.rust-lang.org/nightly/core/intrinsics/fn.unreachable.html
@@ -237,7 +237,7 @@ The [intrinsics::unreachable] function is unstable, so we need to add `#![featur
 ### It works!
 The last step is to update the interrupt descriptor table (IDT) to use our new wrapper function:
 
-```rust
+{{< highlight rust "hl_lines=6" >}}
 // in src/interrupts/mod.rs
 
 lazy_static! {
@@ -247,7 +247,7 @@ lazy_static! {
         idt
     };
 }
-```
+{{< / highlight >}}
 
 Now we see a correct exception stack frame when we execute `make run`:
 
@@ -276,7 +276,7 @@ extern "C" fn divide_by_zero_handler(...) {
     let y = Some(x);
     for i in (0..100).map(|z| (z, z - 1)) {}
 
-    unsafe { print_error(...)); }
+    println!(...);
     loop {}
 }
 {{< / highlight >}}
@@ -402,7 +402,7 @@ In order to fix this bug, we need to make sure that the stack pointer is correct
 
 The problem is that we're pushing an uneven number of 8 byte registers. Thus we need to align the stack pointer again before the `call` instruction:
 
-```rust
+{{< highlight rust "hl_lines=5" >}}
 #[naked]
 extern "C" fn divide_by_zero_wrapper() -> ! {
     unsafe {
@@ -414,7 +414,8 @@ extern "C" fn divide_by_zero_wrapper() -> ! {
         ::core::intrinsics::unreachable();
     }
 }
-```
+{{< / highlight >}}<!--end_-->
+
 The additional `sub rsp, 8` instruction aligns the stack pointer to a 16 byte boundary. Now it should work on real hardware (and in QEMU KVM mode) again.
 
 ## A Handler Macro
@@ -445,7 +446,7 @@ The macro takes a single Rust identifier (`ident`) as argument and expands to a
 
 Now we can remove the `divide_by_zero_wrapper` and use our new `handler!` macro instead:
 
-```rust
+{{< highlight rust "hl_lines=6" >}}
 // in src/interrupts/mod.rs
 
 lazy_static! {
@@ -455,7 +456,7 @@ lazy_static! {
         idt
     };
 }
-```
+{{< / highlight >}}
 
 Note that the `handler!` macro needs to be defined above the static `IDT`, because macros are only available after their definition.
 
@@ -477,10 +478,9 @@ lazy_static! {
 extern "C" fn invalid_opcode_handler(stack_frame: *const ExceptionStackFrame)
     -> !
 {
-    unsafe {
+    let stack_frame = unsafe { &*stack_frame };
-        print_error(format_args!("EXCEPTION: INVALID OPCODE at {:#x}\n{:#?}",
+    println!("\nEXCEPTION: INVALID OPCODE at {:#x}\n{:#?}",
-            (*stack_frame).instruction_pointer, *stack_frame));
+        stack_frame.instruction_pointer, stack_frame);
-    }
     loop {}
 }
 ```
@@ -547,18 +547,16 @@ Let's write a page fault handler which analyzes and prints the error code:
 extern "C" fn page_fault_handler(stack_frame: *const ExceptionStackFrame,
                                  error_code: u64) -> !
 {
-    unsafe {
+    println!(
-        print_error(format_args!(
+        "\nEXCEPTION: PAGE FAULT with error code {:?}\n{:#?}",
-            "EXCEPTION: PAGE FAULT with error code {:?}\n{:#?}",
+        error_code, unsafe { &*stack_frame });
-            error_code, *stack_frame));
-    }
     loop {}
 }
 ```
 
 We need to register our new handler function in the static interrupt descriptor table (IDT):
 
-```rust
+{{< highlight rust "hl_lines=10" >}}
 // in src/interrupts/mod.rs
 
 lazy_static! {
@@ -573,7 +571,8 @@ lazy_static! {
         idt
     };
 }
-```
+{{< / highlight >}}
+
 Page faults have the vector number 14, so we set the 14th IDT entry.
 
 #### Testing it
@@ -631,14 +630,12 @@ extern "C" fn page_fault_handler(stack_frame: *const ExceptionStackFrame,
                                  error_code: u64) -> !
 {
     use x86::controlregs;
-    unsafe {
+    println!(
-        print_error(format_args!(
+        "\nEXCEPTION: PAGE FAULT while accessing {:#x}\
-            "EXCEPTION: PAGE FAULT while accessing {:#x}\
+        \nerror code: {:?}\n{:#?}",
-            \nerror code: {:?}\n{:#?}",
+        unsafe { controlregs::cr2() },
-            controlregs::cr2(),
+        PageFaultErrorCode::from_bits(error_code).unwrap(),
-            PageFaultErrorCode::from_bits(error_code).unwrap(),
+        unsafe { &*stack_frame });
-            *stack_frame));
-    }
     loop {}
 }
 ```

blog/post/11-returning-from-exceptions.md

@@ -42,15 +42,13 @@ Let's start by defining a handler function for the breakpoint exception:
 
 extern "C" fn breakpoint_handler(stack_frame: *const ExceptionStackFrame) -> !
 {
-    unsafe {
+    let stack_frame = unsafe { &*stack_frame };
-        print_error(format_args!("EXCEPTION: BREAKPOINT at {:#x}\n{:#?}",
+    println!("\nEXCEPTION: BREAKPOINT at {:#x}\n{:#?}",
-                                 (*stack_frame).instruction_pointer,
+        stack_frame.instruction_pointer, stack_frame);
-                                 *stack_frame));
-    }
     loop {}
 }
 ```
-We print a red error message using `print_error` and also output the instruction pointer and the rest of the stack frame. Note that this function does _not_ return yet, since our `handler!` macro still requires a diverging function.
+We print an error message and also output the instruction pointer and the rest of the stack frame. Note that this function does _not_ return yet, since our `handler!` macro still requires a diverging function.
 
 We need to register our new handler function in the interrupt descriptor table (IDT):
 
@@ -98,7 +96,7 @@ pub extern "C" fn rust_main(...) {
 
 When we execute `make run`, we see the following:
 
-![QEMU showing `EXCEPTION: BREAKPOINT at 0x1100aa` and a dump of the exception stack frame](images/qemu-breakpoint-handler.png)
+![QEMU showing `EXCEPTION: BREAKPOINT at 0x110970` and a dump of the exception stack frame](images/qemu-breakpoint-handler.png)
 
 It works! Now we “just” need to return from the breakpoint handler somehow so that we see the `It did not crash` message again.
 
@@ -131,18 +129,18 @@ The situation is a bit different for the breakpoint exception, since it needs no
 Let's check this for our breakpoint handler. Remember, the handler printed the following message (see the image above):
 
 ```
-EXCEPTION: BREAKPOINT at 0x1100aa
+EXCEPTION: BREAKPOINT at 0x110970
 ```
 
-So let's disassemble the instruction at `0x1100aa` and its predecessor:
+So let's disassemble the instruction at `0x110970` and its predecessor:
 
 {{< highlight shell "hl_lines=3" >}}
-> objdump -d build/kernel-x86_64.bin | grep -B1 "1100aa:"
+> objdump -d build/kernel-x86_64.bin | grep -B1 "110970:"
-  1100a9:	cc                   	int3
+11096f:	cc                   	int3
-  1100aa:	48 89 c6             	mov    %rax,%rsi
+110970:	48 c7 01 2a 00 00 00 	movq   $0x2a,(%rcx)
 {{< / highlight >}}
 
-We see that `0x1100aa` indeed points to the next instruction after `int3`. So we can simply jump to the stored instruction pointer when we want to return from the breakpoint exception.
+We see that `0x110970` indeed points to the next instruction after `int3`. So we can simply jump to the stored instruction pointer when we want to return from the breakpoint exception.
 
 ### Implementation
 Let's update our `handler!` macro to support non-diverging exception handlers:
@@ -192,7 +190,7 @@ extern "C" fn invalid_opcode_handler(
 extern "C" fn breakpoint_handler(
 -   stack_frame: *const ExceptionStackFrame) -> ! {
 +   stack_frame: *const ExceptionStackFrame) {
-    unsafe { print_error(...) }
+    println!(...);
 -   loop {}
 }
 ```
@@ -201,9 +199,9 @@ Note that we also removed the `loop {}` at the end of our `breakpoint_handler` s
 ### Testing
 Let's try our new `iretq` logic:
 
-![QEMU output with `EXCEPTION BREAKPOINT` and `EXCEPTION PAG FAULT` but no `It did not crash`](images/qemu-breakpoint-return-page-fault.png)
+![QEMU output with `EXCEPTION BREAKPOINT` and `EXCEPTION PAGE FAULT` but no `It did not crash`](images/qemu-breakpoint-return-page-fault.png)
 
-Instead of the expected _“It did not crash”_ message after the breakpoint exception, we get a page fault. The strange thing is that our kernel tried to access address `0x0`, which should never happen. So it seems like we messed up something important.
+Instead of the expected _“It did not crash”_ message after the breakpoint exception, we get a page fault. The strange thing is that our kernel tried to access address `0x1`, which should never happen. So it seems like we messed up something important.
 
 ### Debugging
 Let's debug it using GDB. For that we execute `make debug` in one terminal (which starts QEMU with the `-s -S` flags) and then `make gdb` (which starts and connects GDB) in a second terminal. For more information about GDB debugging, check out our [Set Up GDB] guide.
@@ -230,7 +228,7 @@ Breakpoint 1, blog_os::rust_main (multiboot_information_address=1539136)
 ```
 It worked! So our kernel successfully returned from the `int3` instruction, which means that the `iretq` itself works.
 
-However, when we `continue` the execution again, we get the page fault. So the exception occurs somewhere in the `println` logic. This means that it occurs in code generated by the compiler (and not e.g. in inline assembly). But the compiler should never access `0x0`, so how is this happening?
+However, when we `continue` the execution again, we get the page fault. So the exception occurs somewhere in the `println` logic. This means that it occurs in code generated by the compiler (and not e.g. in inline assembly). But the compiler should never access `0x1`, so how is this happening?
 
 The answer is that we've used the wrong _calling convention_ for our exception handlers. Thus, we violate some compiler invariants so that the code that works fine without intermediate exceptions starts to violate memory safety when it's executed after a breakpoint exception.
 
@@ -280,7 +278,7 @@ So here is what happens:
 - Our `breakpoint_handler` prints to the screen and assumes that it can overwrite `rax` freely (since it's a scratch register). Somehow the value `0` ends up in `rax`.
 - We return from the breakpoint exception using `iretq`.
 - `rust_main` continues and accesses the memory address in `rax`.
-- The CPU tries to access address `0x0`, which causes a page fault.
+- The CPU tries to access address `0x1`, which causes a page fault.
 
 So our exception handler erroneously assumes that the scratch registers were saved by the caller. But the caller (`rust_main`) couldn't save any registers since it didn't know that an exception occurs. So nobody saves `rax` and the other scratch registers, which leads to the page fault.
 
@@ -878,7 +876,7 @@ extern "C" fn page_fault_handler(stack_frame: *const ExceptionStackFrame,
     error_code: u64)
 {
     use x86::controlregs;
-    unsafe {  print_error(...); }
+    println!(...);
 
     // new
     unsafe {

src/interrupts/mod.rs

@@ -113,29 +113,24 @@ struct ExceptionStackFrame {
     stack_segment: u64,
 }
 
-use vga_buffer::print_error;
-
 extern "C" fn divide_by_zero_handler(stack_frame: *const ExceptionStackFrame) {
-    unsafe {
+    let stack_frame = unsafe { &*stack_frame };
-        print_error(format_args!("EXCEPTION: DIVIDE BY ZERO\n{:#?}", *stack_frame));
+    println!("EXCEPTION: DIVIDE BY ZERO\n{:#?}", stack_frame);
-    }
     loop {}
 }
 
 extern "C" fn breakpoint_handler(stack_frame: *const ExceptionStackFrame) {
-    unsafe {
+    let stack_frame = unsafe { &*stack_frame };
-        print_error(format_args!("EXCEPTION: BREAKPOINT at {:#x}\n{:#?}",
+    println!("EXCEPTION: BREAKPOINT at {:#x}\n{:#?}",
-                                 (*stack_frame).instruction_pointer,
+             stack_frame.instruction_pointer,
-                                 *stack_frame));
+             stack_frame);
-    }
 }
 
 extern "C" fn invalid_opcode_handler(stack_frame: *const ExceptionStackFrame) {
-    unsafe {
+    let stack_frame = unsafe { &*stack_frame };
-        print_error(format_args!("EXCEPTION: INVALID OPCODE at {:#x}\n{:#?}",
+    println!("EXCEPTION: INVALID OPCODE at {:#x}\n{:#?}",
-                                 (*stack_frame).instruction_pointer,
+             stack_frame.instruction_pointer,
-                                 *stack_frame));
+             *stack_frame);
-    }
     loop {}
 }
 
@@ -150,13 +145,12 @@ bitflags! {
 }
 
 extern "C" fn page_fault_handler(stack_frame: *const ExceptionStackFrame, error_code: u64) {
+    let stack_frame = unsafe { &*stack_frame };
     use x86::controlregs;
-    unsafe {
+    println!("EXCEPTION: PAGE FAULT while accessing {:#x}\nerror code: \
-        print_error(format_args!("EXCEPTION: PAGE FAULT while accessing {:#x}\nerror code: \
                                   {:?}\n{:#?}",
-                                 controlregs::cr2(),
+             unsafe { controlregs::cr2() },
-                                 PageFaultErrorCode::from_bits(error_code).unwrap(),
+             PageFaultErrorCode::from_bits(error_code).unwrap(),
-                                 *stack_frame));
+             stack_frame);
-    }
     loop {}
 }

src/vga_buffer.rs

@@ -28,29 +28,21 @@ macro_rules! println {
 
 macro_rules! print {
     ($($arg:tt)*) => ({
-            use core::fmt::Write;
+            $crate::vga_buffer::print(format_args!($($arg)*));
-            $crate::vga_buffer::WRITER.lock().write_fmt(format_args!($($arg)*)).unwrap();
     });
 }
 
+pub fn print(args: fmt::Arguments) {
+    use core::fmt::Write;
+    WRITER.lock().write_fmt(args).unwrap();
+}
+
 pub fn clear_screen() {
     for _ in 0..BUFFER_HEIGHT {
         println!("");
     }
 }
 
-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);
-}
-
 #[allow(dead_code)]
 #[derive(Debug, Clone, Copy)]
 #[repr(u8)]