Logging in UEFI Application

Now that we have a template for Surtr, the next thing we want to do is to output logs. Log output is very important for debugging, so let's do it first. This time, we will use the UEFI Simple Text Output protocol to output logs.

Table of Contents

• System Table and Simple Text Output Protocol
• Overriding Implementation
• Initialization of Log System
• Scope
• Log Level
• Change Log Level
• Summary
• References

System Table and Simple Text Output Protocol

In UEFI, EFI System Table contains various Boot Services and Runtime Services. Among them, the field ConOut contains a pointer to EFI_SIMPLE_TEXT_OUTPUT_PROTOCOL interface. This protocol allows for easy text output in UEFI application.

A pointer to the System Table is contained in std.os.uefi.system_table. You can get the pointer to the Simpl Output Protocl by:

var status: uefi.Status = undefined;

const con_out = uefi.system_table.con_out orelse return .Aborted;
status = con_out.clearScreen();

After retrieving the Simple Output Protocol, call clearScreen() to clear the screen. By doing this, the output like BdsDxe: loading Boot0001.... that was displayed in the previous chapter should disappear and you should see a blank screen.

To output a string to the screen, use outputString(). Note that the string here uses the UCS-2 character set. UCS-2 represents a character as two bytes. I'll leave the details to other literature, but here we only use the fact that a character is represented by two bytes, <8bit ASCII code> <0x00>, if it is within the range of ASCII characters. Thus, the string "Hello, world!" can be output as follows:

for ("Hello, world!\n") |b| {
    con_out.outputString(&[_:0]u16{ b }).err() catch unreachable;
}

In Zig, string literals are of type [N:0]const u8, Sentinel-Terminated Arrays. In other words, it is a null-terminated array. Thus, the variable b used in the for loop is of type const u8. The type of the argument to outputString() is [*:0]const u16, so the u8 type must be converted to a u16 type. The &[_:0]u16{ b } inside the for loop converts b of type u8 to type u16. By specifying [_:0], 0x00 is added at the end automatically and can be treated as a UCS-2 string.

const array = [3]u8 { 0, 1, 2 };

const array = [_]u8 { 0, 1, 2 };

const array = [_:0]u8 { 0, 1, 2 };

Overriding Implementation

Zig can output logs with functions such as std.log.info(). The entity of these functions, std.log.log(), call std_options.logFn. This defaults to defaultLog(). The implementation of this function is OS-specific, but there're no impl for UEFI platform. Therefore, you need to override std_options.logFn and implement your own logging function that uses Simple Text Output.

Create surtr/log.zig and implement the logging functions. Define the function as per the signature of logFn:

fn log(
    comptime level: stdlog.Level,
    scope: @Type(.EnumLiteral),
    comptime fmt: []const u8,
    args: anytype,
) void {
    _ = level;
    _ = scope;

    std.fmt.format(
        Writer{ .context = {} },
        fmt ++ "\r\n",
        args,
    ) catch unreachable;
}

std.fmt.format() is a function that generates a string from a format string and arguments and writes it to the first argument Writer. The Writer type is defined as follows:

const Writer = std.io.Writer(
    void,
    LogError,
    writerFunction,
);
const LogError = error{};

std.io.Writer() is a function that returns a Writer type based on the information you give. Zig allows functions to return types. The first argument is the context that will be available when Writer is called. In this case, void is specified since no context is needed. The second argument is the error type returned by this Writer. Since no errors are returned, an empty error type LogError should be defined and specified. The third argument, the most important one, specifies the function that actually outputs the data:

fn writerFunction(_: void, bytes: []const u8) LogError!usize {
    for (bytes) |b| {
        con_out.outputString(&[_:0]u16{b}).err() catch unreachable;
    }
    return bytes.len;
}

The first argumect is the type specified when defining the Writer type. Since the void type is specified and we will not use it, it's explicitly ignored with _. The bytes is the string to output. As in the case of outputting “Hello, world!”, it's converted to UCS-2 and passed to outputString().

Now you have implemented your own logging function. All that remains is to set this function in std_options.logFn and override it:

pub const default_log_options = std.Options{
    .logFn = log,
};

It is not documented, but it seems that the std_options variable can be overridden only in root_source_file defined n build.zig. Therefore, the default_log_options variable is pub so that boot.zig can read it. In boot.zig, we reference this variable and override the std_options variable:

const blog = @import("log.zig");
pub const std_options = blog.default_log_options;

Now, your own logging implementation will be called by std.log.info().

Initialization of Log System

Overriding the log function alone will not cause the log to be output to the screen. You must pass the con_out variable used in writerFunction() to log.zig, and set it as a global variable. Prepare a function to output the log:

const Sto = uefi.protocol.SimpleTextOutput;

var con_out: *Sto = undefined;

/// Initialize bootloader log.
pub fn init(out: *Sto) void {
    con_out = out;
}

Then, the log will be output by passing a pointer to the Simple Text Output Protocol that was obtained earlier. Let's try the following:

const log = std.log;

blog.init(con_out);
log.info("Initialized bootloader log.", .{});

Run QEMU to see if logs are printed:

const value = SomeFunction() catch |err| {
    log.error("SomeFunction failed: {?}", .{err});
    @panic();
}

Scope

Now we are ready to output logs. This would be enough, but since we are here, let's take advantage of Zig's logging system a little more.

Zig allows for scoping of logs:

const log = std.log.scoped(.hoge);
log.info("Hello, from hoge scope", .{});

scoped(.hoge) generates a new set of log functions given a scope of hoge. The second argument of the log() function we just implemented accepts this scope. Let's modify it so that it outputs the scope as well:

fn log(
    comptime level: stdlog.Level,
    scope: @Type(.EnumLiteral),
    comptime fmt: []const u8,
    args: anytype,
) void {
    _ = level;
    const scope_str = if (scope == .default) ": " else "(" ++ @tagName(scope) ++ "): ";

    std.fmt.format(
        Writer{ .context = {} },
        scope_str ++ fmt ++ "\r\n",
        args,
    ) catch unreachable;
}

If the received scope is not .default, a string (<SCOPE>) is included in the output. Zig allows array concatnation using the ++ operator. Functions with comptime arguments are evaluated at compile time, so the string generation for scope has no runtime overhead.

In boot.zig, we use the scope .surtr to make it easy to see that the output is from Surtr:

const log = std.log.scoped(.surtr);
log.info("Hello, world!", .{});

The output should look something like this:

(surtr): Hello, world!

Log Level

The last element of the log is the log level. Zig's log levels are defined as std.log.Level enum, with four levels: err/warn/info/debug. The default log level is determined by the optimization level. Logs lower than the program's log level are not output and are removed at compile time.

For clarity, let's also output the log level:

fn log(
    comptime level: stdlog.Level,
    scope: @Type(.EnumLiteral),
    comptime fmt: []const u8,
    args: anytype,
) void {
    const level_str = comptime switch (level) {
        .debug => "[DEBUG]",
        .info => "[INFO ]",
        .warn => "[WARN ]",
        .err => "[ERROR]",
    };
    const scope_str = if (scope == .default) ": " else "(" ++ @tagName(scope) ++ "): ";

    std.fmt.format(
        Writer{ .context = {} },
        level_str ++ " " ++ scope_str ++ fmt ++ "\r\n",
        args,
    ) catch unreachable;
}

comptime switch is a switch statement that is evaluated at compile time. It generates a string corresponding to level, concatenates it with fmt like a scope string, and outputs it. The log output in this state should look like this:

[INFO ] (surtr): Hello, world!

Change Log Level

The log level can be changed by setting std_options.log_level in the code. However, it is not convenient to rewrite the code just to change the log level. Let's modify the build script to change the log level at build time:

// Options
const s_log_level = b.option(
    []const u8,
    "log_level",
    "log_level",
) orelse "info";
const log_level: std.log.Level = b: {
    const eql = std.mem.eql;
    break :b if (eql(u8, s_log_level, "debug"))
        .debug
    else if (eql(u8, s_log_level, "info"))
        .info
    else if (eql(u8, s_log_level, "warn"))
        .warn
    else if (eql(u8, s_log_level, "error"))
        .err
    else
        @panic("Invalid log level");
};

// 新たなオプションの作成
const options = b.addOptions();
options.addOption(std.log.Level, "log_level", log_level);

// Surtr にオプションの追加
surtr.root_module.addOptions("option", options);

A new command line argument is defined by b.option. The string received as an argument is converted to four enum values and added as a new option named log_level with addOption().

The options added here can be referenced in the code as follows:

const option = @import("option"); // build.zig で指定したオプション名
const log_level = option.log_level;

The log_level can be used as a value that's determined at compile time. Set this value to std_options.log_level:

pub const default_log_options = std.Options{
    .log_level = switch (option.log_level) {
        .debug => .debug,
        .info => .info,
        .warn => .warn,
        .err => .err,
    },
    .logFn = log,
};

Then, specify this option at build time to change the log level. For example, you can use log.info() to specify log output, and then specify .warn as the log level at compile time:

zig build -Dlog_level=warn -Doptimize=Debug

The log output should disappear from the QEMU output.

Summary

本チャプターでは UEFI の Simple Text Output Protocol を利用した出力を実装しました。 この出力を Zig のログシステムに組み込むことで、ログのスコープやレベルを自由に変更できるようになりました。 ログ関数は、もちろんフォーマット文字列も利用できます。 今後の開発が捗ること間違いなしですね。

References

• フルスクラッチで作る!UEFIベアメタルプログラミング
• UEFI Specification 2.9 Errata A