Race condition when printing in interrupt handlers

[xermicus]

First of all this blog post series is pure joy. Thank you very much for creating and maintaining this!

During the paging introduction chapter I noticed a race condition. It can occur when printing (or panicking for that matter) inside an interrupt handler (for example page or double fault handlers do exactly that). The race is triggered for example when a double fault occurs during printing, but the WRITER instance is already locked:

// main.rs (branch post-08)
pub extern "C" fn _start() -> ! {
    [...]
    blog_os::init();

    // trigger
    unsafe {           // page fault handler tries to lock but WRITER is already locked
        println!("{}", *(0xDEAD_BEEF as *mut u32));
    }
    [...]
}

I fixed it for myself by creating a print_panic function that does directly write to the vga buffer, not respecting the WRITER (which is then used inside the panic handler instead of the normal println macro and as a consequence only panic! or print_panic! is allowed inside interrupt handlers by "convention"). This fixes the problem for me, but it does not seem ideal and maybe introduces new problems? Is there a better solution?

Is it even worth fixing? I'm not sure. It is a detail. But then again it is a bug and more than that readers could learn something if this case is explicitly handled in the blog post (I'm willing to create a pull request).

[phil-opp]

Thanks for reporting and sorry for the late reply! I think we used to get this right, but probably something changed in our writer implementation or in the formatting code generated by the compiler. The best approach to fix this would probably be to implement the fmt::Write trait directly for the Mutex-wrapped writer and only lock it in the write_str method. This way, it would be unlocked while the arguments are evaluated.

I'm planning some larger updates to the printing code soon to switch from the text-based buffer to a pixel-based framebuffer soon. I will keep this issue in mind and ensure that the new code won't have this problem.

[nicolae536]

Hi I tried to implement the write on Mutex-wrapped but I'm not sure what's the problem a bit of help would be relly helpfull . For this code

    crate::vga_buffer::WRITER.write_fmt(args).unwrap();

I get the following error

error[E0055]: reached the recursion limit while auto-dereferencing `vga_buffer::writer::WrappedWriter`
  --> src\lib.rs:19:31
   |
19 |     crate::vga_buffer::WRITER.write_fmt(args).unwrap();
   |                               ^^^^^^^^^ deref recursion limit reached
   |
   = help: consider adding a `#![recursion_limit="256"]` attribute to your crate (`rust_os`)

error: aborting due to previous error; 1 warning emitted

Here is the implementation

use core::fmt;

use lazy_static::lazy_static;
use volatile::Volatile;

use super::color::*;
use super::screen_character;
use core::ops::{DerefMut, Deref};

// #[allow(dead_code)]
// use crate::serial_print;
// use crate::serial_println;

pub const BUFFER_HEIGHT: usize = 25;
pub const BUFFER_WIDTH: usize = 80;

#[repr(transparent)]
struct Buffer {
    chars: [[Volatile<screen_character::ScreenCharacter>; BUFFER_WIDTH]; BUFFER_HEIGHT],
}

pub struct Writer {
    column_position: usize,
    color_code: ColorCode,
    buffer: &'static mut Buffer,
}

impl Writer {
    pub fn new(column_position: usize,
               color_code: ColorCode) -> Writer {
        return Writer {
            column_position,
            color_code,
            buffer: unsafe { &mut *(0xb8000 as *mut Buffer) },
        };
    }
}

impl Writer {
    pub fn write_byte(&mut self, byte: u8) {
        match byte {
            b'\n' => self.new_line(),
            byte => {
                if self.column_position >= BUFFER_WIDTH {
                    self.new_line();
                }

                let row = BUFFER_HEIGHT - 1;
                let col = self.column_position;

                let color_code = self.color_code;
                self.buffer.chars[row][col].write(screen_character::ScreenCharacter::new(byte, color_code));
                self.column_position += 1;
            }
        }
    }

    pub fn write_string(&mut self, s: &str) {
        for byte in s.bytes() {
            match byte {
                // printable ASCII byte or newline
                0x20..=0x7e | b'\n' => self.write_byte(byte),
                // not part of printable ASCII range
                _ => self.write_byte(0xfe),
            }
        }
    }

    fn new_line(&mut self) {
        for row in 1..BUFFER_HEIGHT {
            for col in 0..BUFFER_WIDTH {
                let current_character = self.buffer.chars[row][col].read();
                self.buffer.chars[row - 1][col].write(current_character);
            }
        }
        self.clear_row(BUFFER_HEIGHT - 1);
        self.column_position = 0;
    }

    fn clear_row(&mut self, row_index: usize) {
        let blank = screen_character::ScreenCharacter::new(b' ', self.color_code);
        for col in 0..BUFFER_WIDTH {
            self.buffer.chars[row_index][col].write(blank);
        }
    }
}

// impl fmt::Write for Writer {
//     fn write_str(&mut self, s: &str) -> fmt::Result {
//         self.write_string(s);
//         Ok(())
//     }
// }

struct WrappedWriter {
    value: spin::Mutex<Writer>
}

impl fmt::Write for WrappedWriter {
    fn write_str(&mut self, s: &str) -> fmt::Result {
        self.value.lock().write_string(s);
        Ok(())
    }
}

impl Deref for WrappedWriter {
    type Target = WrappedWriter;

    fn deref(&self) -> &Self::Target {
        return self;
    }
}

impl DerefMut for WrappedWriter {
    fn deref_mut(&mut self) -> &mut Self::Target {
        return self;
    }
}

lazy_static! {
    pub static ref WRITER: WrappedWriter = {
        let writerInstance = WrappedWriter {
            value: spin::Mutex::new(
                Writer::new(0, ColorCode::new(Color::Yellow, Color::Black))
            )
        };
        writerInstance
    };
}

#[test_case]
fn test_println_output() {
    let test_str = "Some test string that fits on a single line";
    println!("{}", test_str);
    for (char_index, char) in test_str.chars().enumerate() {
        let screen_char = WRITER.value.lock().buffer.chars[BUFFER_HEIGHT - 2][char_index].read();
        assert_eq!(char::from(screen_char.ascii_character), char);
    }
}

Deref + DerefMut Were implemented because I get the following error without them but then again I didn't knew on what should I deref cause I don't actually need to deref from my point of view this are needed because write_fmt gets a mut of self.

error[E0596]: cannot borrow data in a dereference of `vga_buffer::writer::WRITER` as mutable
  --> src\lib.rs:19:5
   |
19 |     crate::vga_buffer::WRITER.write_fmt(args).unwrap();
   |     ^^^^^^^^^^^^^^^^^^^^^^^^^ cannot borrow as mutable
   |
   = help: trait `DerefMut` is required to modify through a dereference, but it is not implemented for `vga_buffer::writer::WRITER`

[bjorn3]

@nicolae536 What is your Deref implementation for vga_buffer::writer::WrappedWriter?

[nicolae536]

@bjorn3 I updated the post. I posted the wrong file first time.

[bjorn3]

impl Deref for WrappedWriter {
    type Target = WrappedWriter;

    fn deref(&self) -> &Self::Target {
        return self;
    }
}

It is not valid for a type to deref to itself. Target should be something like spin::Mutex<Writer>.

[xermicus]

Thanks for reporting and sorry for the late reply! I think we used to get this right, but probably something changed in our writer implementation or in the formatting code generated by the compiler. The best approach to fix this would probably be to implement the fmt::Write trait directly for the Mutex-wrapped writer and only lock it in the write_str method. This way, it would be unlocked while the arguments are evaluated.

I'm planning some larger updates to the printing code soon to switch from the text-based buffer to a pixel-based framebuffer soon. I will keep this issue in mind and ensure that the new code won't have this problem.

No worries! This sounds good, thank you 👍

[nicolae536]

@bjorn3 I also tried to change it like you mention but if I change to deref to sping::Mutex<Writer> than I don't have the correct type anymore. I get the same error for the following. Because the same problem implementing fmt::Write requires a &mut self he tries to deref to a &mut self but he cannot cause derefMut changes the type to spin::Mutex<Writer> and that one doe not implement the traint fmt::Write maybe I'm getting it wrong but there is no proper way of wrapping this only by implementing Send + Sync on the Writer itself so that he is not wrapped into a sping::Mutex<Writer> and I can call write fmt directly on him.

use core::fmt;

use lazy_static::lazy_static;
use volatile::Volatile;

use super::color::*;
use super::screen_character;
use core::ops::{Deref, DerefMut};

// #[allow(dead_code)]
// use crate::serial_print;
// use crate::serial_println;

pub const BUFFER_HEIGHT: usize = 25;
pub const BUFFER_WIDTH: usize = 80;

#[repr(transparent)]
struct Buffer {
    chars: [[Volatile<screen_character::ScreenCharacter>; BUFFER_WIDTH]; BUFFER_HEIGHT],
}

pub struct Writer {

    column_position: usize,
    color_code: ColorCode,
    buffer: &'static mut Buffer,
}

impl Writer {
    pub fn new(column_position: usize,
               color_code: ColorCode) -> Writer {
        return Writer {
            column_position,
            color_code,
            buffer: unsafe { &mut *(0xb8000 as *mut Buffer) },
        };
    }
}

impl Writer {
    pub fn write_byte(&mut self, byte: u8) {
        match byte {
            b'\n' => self.new_line(),
            byte => {
                if self.column_position >= BUFFER_WIDTH {
                    self.new_line();
                }

                let row = BUFFER_HEIGHT - 1;
                let col = self.column_position;

                let color_code = self.color_code;
                self.buffer.chars[row][col].write(screen_character::ScreenCharacter::new(byte, color_code));
                self.column_position += 1;
            }
        }
    }

    pub fn write_string(&mut self, s: &str) {
        for byte in s.bytes() {
            match byte {
                // printable ASCII byte or newline
                0x20..=0x7e | b'\n' => self.write_byte(byte),
                // not part of printable ASCII range
                _ => self.write_byte(0xfe),
            }
        }
    }

    fn new_line(&mut self) {
        for row in 1..BUFFER_HEIGHT {
            for col in 0..BUFFER_WIDTH {
                let current_character = self.buffer.chars[row][col].read();
                self.buffer.chars[row - 1][col].write(current_character);
            }
        }
        self.clear_row(BUFFER_HEIGHT - 1);
        self.column_position = 0;
    }

    fn clear_row(&mut self, row_index: usize) {
        let blank = screen_character::ScreenCharacter::new(b' ', self.color_code);
        for col in 0..BUFFER_WIDTH {
            self.buffer.chars[row_index][col].write(blank);
        }
    }
}

impl fmt::Write for Writer {
    fn write_str(&mut self, s: &str) -> fmt::Result {
        self.write_string(s);
        Ok(())
    }
}

// impl fmt::Write for  spin::Mutex<Writer> {}

struct WrappedWriter {
    value: spin::Mutex<Writer>
}

impl fmt::Write for WrappedWriter {
    fn write_str(&mut self, s: &str) -> fmt::Result {
        self.value.lock().write_string(s);
        Ok(())
    }
}

impl Deref for WrappedWriter {
    type Target = spin::Mutex<Writer>;

    fn deref(&self) -> &Self::Target {
        return &self.value;
    }
}

impl DerefMut for WrappedWriter {
    fn deref_mut(&mut self) -> &mut Self::Target {
        return &mut self.value;
    }
}

lazy_static! {
    pub static ref WRITER: WrappedWriter = {
        let mut writer_instance = WrappedWriter {
            value: spin::Mutex::new(
                Writer::new(0, ColorCode::new(Color::Yellow, Color::Black))
            )
        };
        writer_instance
    };
}

#[test_case]
fn test_println_output() {
    let test_str = "Some test string that fits on a single line";
    println!("{}", test_str);
    for (char_index, char) in test_str.chars().enumerate() {
        let screen_char = WRITER.value.lock().buffer.chars[BUFFER_HEIGHT - 2][char_index].read();
        assert_eq!(char::from(screen_char.ascii_character), char);
    }
}

[bjorn3]

You have to call lock() on spin::Mutex<Writer> to get a &mut Writer. You can't directly return &mut Writer from Deref or DerefMut as lock() technically returns a lock guard that derefs to &mut Writer. This &mut Writer can't outlive the lock guard. If you were to return &mut Writer, the lock guard would need to be dropped, invalidating the &mut Writer.