[kernel] Move the logger from kutil into kernel

Part one of a series of code moves. The kutil library is not very
useful, as most of its code is kernel-specific. This was originally for
testing purposes, but that can be achieved in other ways with the
current build system. I find this mostly creates a strange division in
the kernel code.

Instead, I'm going to move everything kernel-specific to actually be in
the kernel, and replace kutil with just 'util' for generic utility code
I want to share.

This commit:

- Moves the logger into the kernel.
- Updates the 'printf' library used from mpaland/printf to
  eyalroz/printf and moved it into the kernel, as it's only used by the
  logger in kutil.
- Removes some other unused kutil headers from some files, to help
  future code rearrangement.

Note that the (now redundant-seeming) log.cpp/h in kernel is currently
still there - these files are more about log output than the logging
system, and will get replaced once I add user-space log output.

src/kernel/acpi_tables.h

@@ -4,7 +4,6 @@
 #include <stdint.h>
 
 #include "enum_bitfields.h"
-#include "kutil/coord.h"
 #include "kutil/misc.h"
 
 struct acpi_table_header

src/kernel/console.cpp

@@ -1,8 +1,6 @@
-#include "kutil/coord.h"
-#include "kutil/guid.h"
 #include "kutil/memory.h"
 #include "kutil/no_construct.h"
-#include "kutil/printf.h"
+#include "printf/printf.h"
 #include "console.h"
 #include "serial.h"
 
@@ -81,6 +79,6 @@ void console::vprintf(const char *fmt, va_list args)
 {
     static const unsigned buf_size = 256;
     char buffer[buf_size];
-    vsnprintf_(buffer, buf_size, fmt, args);
+    vsnprintf(buffer, buf_size, fmt, args);
     puts(buffer);
 }

src/kernel/interrupts.cpp

@@ -1,7 +1,7 @@
 #include <stdint.h>
 
 #include "kernel_memory.h"
-#include "kutil/printf.h"
+#include "printf/printf.h"
 
 #include "cpu.h"
 #include "device_manager.h"
@@ -130,7 +130,7 @@ isr_handler(cpu_state *regs)
                 break;
 
             snprintf(message, sizeof(message),
-                "Page fault: %016llx%s%s%s%s%s", cr2,
+                "Page fault: %016lx%s%s%s%s%s", cr2,
                 (regs->errorcode & 0x01) ? " present" : "",
                 (regs->errorcode & 0x02) ? " write" : "",
                 (regs->errorcode & 0x04) ? " user" : "",
@@ -153,7 +153,7 @@ isr_handler(cpu_state *regs)
         return;
 
     default:
-        snprintf(message, sizeof(message), "Unknown interrupt 0x%x", regs->interrupt);
+        snprintf(message, sizeof(message), "Unknown interrupt 0x%lx", regs->interrupt);
         kassert(false, message);
     }
 
@@ -170,7 +170,7 @@ irq_handler(cpu_state *regs)
     if (! device_manager::get().dispatch_irq(irq)) {
         char message[100];
         snprintf(message, sizeof(message),
-            "Unknown IRQ: %d (vec 0x%x)", irq, regs->interrupt);
+            "Unknown IRQ: %d (vec 0x%lx)", irq, regs->interrupt);
         kassert(false, message);
     }
 

src/kernel/kernel.module

@@ -26,6 +26,7 @@ kernel = module("kernel",
         "interrupts.s",
         "io.cpp",
         "log.cpp",
+        "logger.cpp",
         "memory_bootstrap.cpp",
         "msr.cpp",
         "objects/channel.cpp",
@@ -38,6 +39,7 @@ kernel = module("kernel",
         "page_table.cpp",
         "page_tree.cpp",
         "pci.cpp",
+        "printf/printf.c",
         "scheduler.cpp",
         "serial.cpp",
         "syscalls/channel.cpp",

src/kernel/log.cpp

@@ -28,6 +28,9 @@ output_log(log::area_t area, log::level severity, const char *message)
     cons->set_color();
 }
 
+// For printf.c
+extern "C" void putchar_(char c) {}
+
 static void
 log_flush()
 {

src/kernel/log.h

@@ -1,9 +1,6 @@
 #pragma once
 
-#include "kutil/logger.h"
-
-namespace log = kutil::log;
-namespace logs = kutil::logs;
+#include "logger.h"
 
 void logger_init();
 void logger_clear_immediate();

src/kernel/logger.cpp

@@ -0,0 +1,172 @@
+#include "kutil/assert.h"
+#include "kutil/constexpr_hash.h"
+#include "kutil/memory.h"
+#include "printf/printf.h"
+
+#include "logger.h"
+
+namespace logs {
+#define LOG(name, lvl) \
+    const log::area_t name = #name ## _h; \
+    const char * name ## _name = #name;
+#include "j6/tables/log_areas.inc"
+#undef LOG
+}
+
+namespace log {
+
+using kutil::memset;
+using kutil::memcpy;
+
+logger *logger::s_log = nullptr;
+const char *logger::s_level_names[] = {"", "debug", "info", "warn", "error", "fatal"};
+
+logger::logger(logger::immediate_cb output) :
+    m_buffer(nullptr, 0),
+    m_immediate(output),
+    m_flush(nullptr),
+    m_sequence(0)
+{
+    memset(&m_levels, 0, sizeof(m_levels));
+    memset(&m_names, 0, sizeof(m_names));
+    s_log = this;
+}
+
+logger::logger(uint8_t *buffer, size_t size, logger::immediate_cb output) :
+    m_buffer(buffer, size),
+    m_immediate(output),
+    m_flush(nullptr),
+    m_sequence(0)
+{
+    memset(&m_levels, 0, sizeof(m_levels));
+    memset(&m_names, 0, sizeof(m_names));
+    s_log = this;
+
+#define LOG(name, lvl) \
+    register_area(logs::name, logs::name ## _name, log::level::lvl);
+#include "j6/tables/log_areas.inc"
+#undef LOG
+}
+
+void
+logger::set_level(area_t area, level l)
+{
+    unsigned uarea = static_cast<unsigned>(area);
+    uint8_t ulevel = static_cast<uint8_t>(l) & 0x0f;
+    uint8_t &flags = m_levels[uarea / 2];
+    if (uarea & 1)
+        flags = (flags & 0x0f) | (ulevel << 4);
+    else
+        flags = (flags & 0xf0) | ulevel;
+}
+
+level
+logger::get_level(area_t area)
+{
+    unsigned uarea = static_cast<unsigned>(area);
+    uint8_t &flags = m_levels[uarea / 2];
+    if (uarea & 1)
+        return static_cast<level>((flags & 0xf0) >> 4);
+    else
+        return static_cast<level>(flags & 0x0f);
+}
+
+void
+logger::register_area(area_t area, const char *name, level verbosity)
+{
+    m_names[area] = name;
+    set_level(area, verbosity);
+}
+
+void
+logger::output(level severity, area_t area, const char *fmt, va_list args)
+{
+    uint8_t buffer[256];
+    entry *header = reinterpret_cast<entry *>(buffer);
+    header->bytes = sizeof(entry);
+    header->area = area;
+    header->severity = severity;
+    header->sequence = m_sequence++;
+
+    header->bytes +=
+        vsnprintf(header->message, sizeof(buffer) - sizeof(entry), fmt, args);
+
+    kutil::scoped_lock lock {m_lock};
+
+    if (m_immediate) {
+        buffer[header->bytes] = 0;
+        m_immediate(area, severity, header->message);
+        return;
+    }
+
+    uint8_t *out;
+    size_t n = m_buffer.reserve(header->bytes, reinterpret_cast<void**>(&out));
+    if (n < sizeof(entry)) {
+        m_buffer.commit(0); // Cannot even write the header, abort
+        return;
+    }
+
+    if (n < header->bytes)
+        header->bytes = n;
+
+    memcpy(out, buffer, n);
+    m_buffer.commit(n);
+
+    if (m_flush)
+        m_flush();
+}
+
+size_t
+logger::get_entry(void *buffer, size_t size)
+{
+    kutil::scoped_lock lock {m_lock};
+
+    void *out;
+    size_t out_size = m_buffer.get_block(&out);
+    if (out_size == 0 || out == 0)
+        return 0;
+
+    kassert(out_size >= sizeof(entry), "Couldn't read a full entry");
+    if (out_size < sizeof(entry))
+        return 0;
+
+    entry *ent = reinterpret_cast<entry *>(out);
+    if (size >= ent->bytes) {
+        memcpy(buffer, out, ent->bytes);
+        m_buffer.consume(ent->bytes);
+    }
+
+    return ent->bytes;
+}
+
+#define LOG_LEVEL_FUNCTION(name) \
+    void name (area_t area, const char *fmt, ...) { \
+        logger *l = logger::s_log; \
+        if (!l) return; \
+        level limit = l->get_level(area); \
+        if (limit == level::none || level::name < limit) return; \
+        va_list args; \
+        va_start(args, fmt); \
+        l->output(level::name, area, fmt, args); \
+        va_end(args); \
+    }
+
+LOG_LEVEL_FUNCTION(debug);
+LOG_LEVEL_FUNCTION(info);
+LOG_LEVEL_FUNCTION(warn);
+LOG_LEVEL_FUNCTION(error);
+
+void fatal(area_t area, const char *fmt, ...)
+{
+    logger *l = logger::s_log;
+    if (!l) return;
+
+    va_list args;
+    va_start(args, fmt);
+    l->output(level::fatal, area, fmt, args);
+    va_end(args);
+
+    kassert(false, "log::fatal");
+}
+
+} // namespace log

src/kernel/logger.h

@@ -0,0 +1,134 @@
+#pragma once
+/// \file logger.h
+/// Kernel logging facility.
+
+#include <stdarg.h>
+#include <stdint.h>
+
+#include "kutil/bip_buffer.h"
+#include "kutil/spinlock.h"
+
+namespace log {
+
+using area_t = uint8_t;
+enum class level : uint8_t {
+    none, debug, info, warn, error, fatal, max
+};
+
+class logger
+{
+public:
+    /// Callback type for immediate-mode logging
+    typedef void (*immediate_cb)(area_t, level, const char *);
+
+    /// Callback type for log flushing
+    typedef void (*flush_cb)();
+
+    /// Default constructor. Creates a logger without a backing store.
+    /// \arg output  Immediate-mode logging output function
+    logger(immediate_cb output = nullptr);
+
+    /// Constructor. Logs are written to the given buffer.
+    /// \arg buffer  Buffer to which logs are written
+    /// \arg size    Size of `buffer`, in bytes
+    /// \arg output  Immediate-mode logging output function
+    logger(uint8_t *buffer, size_t size, immediate_cb output = nullptr);
+
+    /// Register a log area for future use.
+    /// \arg area      The key for the new area
+    /// \arg name      The area name
+    /// \arg verbosity What level of logs to print for this area
+    void register_area(area_t area, const char *name, level verbosity);
+
+    /// Register an immediate-mode log callback
+    inline void set_immediate(immediate_cb cb) { m_immediate = cb; }
+
+    /// Register a flush callback
+    inline void set_flush(flush_cb cb) { m_flush = cb; }
+
+    /// Get the default logger.
+    inline logger & get() { return *s_log; }
+
+    /// Get the registered name for a given area
+    inline const char * area_name(area_t area) const { return m_names[area]; }
+
+    /// Get the name of a level
+    inline const char * level_name(level l) const { return s_level_names[static_cast<unsigned>(l)]; }
+
+    /// Write to the log
+    /// \arg severity  The severity of the message
+    /// \arg area      The log area to write to
+    /// \arg fmt       A printf-like format string
+    inline void log(level severity, area_t area, const char *fmt, ...)
+    {
+        level limit = get_level(area);
+        if (limit == level::none || severity < limit)
+            return;
+
+        va_list args;
+        va_start(args, fmt);
+        output(severity, area, fmt, args);
+        va_end(args);
+    }
+
+    struct entry
+    {
+        uint8_t bytes;
+        area_t area;
+        level severity;
+        uint8_t sequence;
+        char message[0];
+    };
+
+    /// Get the next log entry from the buffer
+    /// \arg buffer  The buffer to copy the log message into
+    /// \arg size    Size of the passed-in buffer, in bytes
+    /// \returns     The size of the log entry (if larger than the
+    ///              buffer, then no data was copied)
+    size_t get_entry(void *buffer, size_t size);
+
+    /// Get whether there is currently data in the log buffer
+    inline bool has_log() const { return m_buffer.size(); }
+
+private:
+    friend void debug(area_t area, const char *fmt, ...);
+    friend void info (area_t area, const char *fmt, ...);
+    friend void warn (area_t area, const char *fmt, ...);
+    friend void error(area_t area, const char *fmt, ...);
+    friend void fatal(area_t area, const char *fmt, ...);
+
+    void output(level severity, area_t area, const char *fmt, va_list args);
+
+    void set_level(area_t area, level l);
+    level get_level(area_t area);
+
+    static const unsigned num_areas = 1 << (sizeof(area_t) * 8);
+    uint8_t m_levels[num_areas / 2];
+    const char *m_names[num_areas];
+    immediate_cb m_immediate;
+    flush_cb m_flush;
+
+    uint8_t m_sequence;
+
+    kutil::bip_buffer m_buffer;
+    kutil::spinlock m_lock;
+
+    static logger *s_log;
+    static const char *s_level_names[static_cast<unsigned>(level::max)];
+};
+
+void debug(area_t area, const char *fmt, ...);
+void info (area_t area, const char *fmt, ...);
+void warn (area_t area, const char *fmt, ...);
+void error(area_t area, const char *fmt, ...);
+void fatal(area_t area, const char *fmt, ...);
+
+extern log::logger &g_logger;
+
+} // namespace log
+
+namespace logs {
+#define LOG(name, lvl) extern const log::area_t name;
+#include "j6/tables/log_areas.inc"
+#undef LOG
+} // namespace logs

src/kernel/panic.serial/display.cpp

@@ -1,6 +1,7 @@
+#include "printf/printf.h"
+
 #include "cpu.h"
 #include "display.h"
-#include "kutil/printf.h"
 #include "serial.h"
 #include "symbol_table.h"
 
@@ -25,7 +26,7 @@ print_header(
     out.write(":");
 
     char linestr[6];
-    snprintf(linestr, sizeof(linestr), "%d", line);
+    snprintf(linestr, sizeof(linestr), "%ld", line);
     out.write(linestr);
 
     out.write("\n \e[0;31m===================================================================================\n");
@@ -56,7 +57,7 @@ print_reg(serial_port &out, const char *name, uint64_t val, const char *color)
 {
     char message[512];
 
-    snprintf(message, sizeof(message), " \e[0;%sm%-3s %016llx\e[0m", color, name, val);
+    snprintf(message, sizeof(message), " \e[0;%sm%-3s %016lx\e[0m", color, name, val);
     out.write(message);
 }
 
@@ -102,3 +103,6 @@ print_cpu_state(serial_port &out, const cpu_state &regs)
 }
 
 } // namespace panic
+
+// For printf.c
+extern "C" void putchar_(char c) {}

src/kernel/panic.serial/serial.module

@@ -11,6 +11,7 @@ panic = module("panic.serial",
         "main.cpp",
         "serial.cpp",
         "symbol_table.cpp",
+        "../printf/printf.c",
     ])
 
 panic.variables['ldflags'] = ["${ldflags}", "-T", "${source_root}/src/kernel/panic.serial/panic.serial.ld"]

src/kernel/printf/printf.h

@@ -0,0 +1,151 @@
+/**
+ * @author (c) Eyal Rozenberg <eyalroz1@gmx.com>
+ *             2021, Haifa, Palestine/Israel
+ * @author (c) Marco Paland (info@paland.com)
+ *             2014-2019, PALANDesign Hannover, Germany
+ *
+ * @note Others have made smaller contributions to this file: see the
+ * contributors page at https://github.com/eyalroz/printf/graphs/contributors
+ * or ask one of the authors.
+ *
+ * @brief Small stand-alone implementation of the printf family of functions
+ * (`(v)printf`, `(v)s(n)printf` etc., geared towards use on embedded systems with
+ * a very limited resources.
+ *
+ * @note the implementations are thread-safe; re-entrant; use no functions from
+ * the standard library; and do not dynamically allocate any memory.
+ *
+ * @license The MIT License (MIT)
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+ * THE SOFTWARE.
+ */
+
+#ifndef PRINTF_H_
+#define PRINTF_H_
+
+#include <stdarg.h>
+#include <stddef.h>
+
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+#ifdef __GNUC__
+# define ATTR_PRINTF(one_based_format_index, first_arg) \
+__attribute__((format(__printf__, (one_based_format_index), (first_arg))))
+# define ATTR_VPRINTF(one_based_format_index) ATTR_PRINTF(one_based_format_index, 0)
+#else
+# define ATTR_PRINTF(one_based_format_index, first_arg)
+# define ATTR_VPRINTF(one_based_format_index)
+#endif
+
+#ifndef PRINTF_ALIAS_STANDARD_FUNCTION_NAMES
+#define PRINTF_ALIAS_STANDARD_FUNCTION_NAMES 0
+#endif
+
+#if PRINTF_ALIAS_STANDARD_FUNCTION_NAMES
+# define printf_    printf
+# define sprintf_   sprintf
+# define vsprintf_  vsprintf
+# define snprintf_  snprintf
+# define vsnprintf_ vsnprintf
+# define vprintf_   vprintf
+#endif
+
+/**
+ * Output a character to a custom device like UART, used by the printf() function
+ * This function is declared here only. You have to write your custom implementation somewhere
+ * @param character Character to output
+ */
+void putchar_(char character);
+
+
+/**
+ * Tiny printf implementation
+ * You have to implement putchar_ if you use printf()
+ * To avoid conflicts with the regular printf() API it is overridden by macro defines
+ * and internal underscore-appended functions like printf_() are used
+ * @param format A string that specifies the format of the output
+ * @return The number of characters that are written into the array, not counting the terminating null character
+ */
+int printf_(const char* format, ...) ATTR_PRINTF(1, 2);
+
+
+/**
+ * Tiny sprintf/vsprintf implementation
+ * Due to security reasons (buffer overflow) YOU SHOULD CONSIDER USING (V)SNPRINTF INSTEAD!
+ * @param buffer A pointer to the buffer where to store the formatted string. MUST be big enough to store the output!
+ * @param format A string that specifies the format of the output
+ * @param va A value identifying a variable arguments list
+ * @return The number of characters that are WRITTEN into the buffer, not counting the terminating null character
+ */
+int  sprintf_(char* buffer, const char* format, ...) ATTR_PRINTF(2, 3);
+int vsprintf_(char* buffer, const char* format, va_list va) ATTR_VPRINTF(2);
+
+
+/**
+ * Tiny snprintf/vsnprintf implementation
+ * @param buffer A pointer to the buffer where to store the formatted string
+ * @param count The maximum number of characters to store in the buffer, including a terminating null character
+ * @param format A string that specifies the format of the output
+ * @param va A value identifying a variable arguments list
+ * @return The number of characters that COULD have been written into the buffer, not counting the terminating
+ *         null character. A value equal or larger than count indicates truncation. Only when the returned value
+ *         is non-negative and less than count, the string has been completely written.
+ */
+int  snprintf_(char* buffer, size_t count, const char* format, ...) ATTR_PRINTF(3, 4);
+int vsnprintf_(char* buffer, size_t count, const char* format, va_list va) ATTR_VPRINTF(3);
+
+
+/**
+ * Tiny vprintf implementation
+ * @param format A string that specifies the format of the output
+ * @param va A value identifying a variable arguments list
+ * @return The number of characters that are WRITTEN into the buffer, not counting the terminating null character
+ */
+int vprintf_(const char* format, va_list va) ATTR_VPRINTF(1);
+
+
+/**
+ * printf/vprintf with output function
+ * You may use this as dynamic alternative to printf() with its fixed _putchar() output
+ * @param out An output function which takes one character and an argument pointer
+ * @param arg An argument pointer for user data passed to output function
+ * @param format A string that specifies the format of the output
+ * @param va A value identifying a variable arguments list
+ * @return The number of characters that are sent to the output function, not counting the terminating null character
+ */
+int fctprintf(void (*out)(char character, void* arg), void* arg, const char* format, ...) ATTR_PRINTF(3, 4);
+int vfctprintf(void (*out)(char character, void* arg), void* arg, const char* format, va_list va) ATTR_VPRINTF(3);
+
+#ifdef __cplusplus
+}
+#endif
+
+#if PRINTF_ALIAS_STANDARD_FUNCTION_NAMES
+# undef printf_
+# undef sprintf_
+# undef vsprintf_
+# undef snprintf_
+# undef vsnprintf_
+# undef vprintf_
+#endif
+
+#endif  // PRINTF_H_

src/kernel/printf/printf_config.h

@@ -0,0 +1,10 @@
+#pragma once
+
+// \file printf_config.h
+// Configuration for eyalroz/printf
+
+#define PRINTF_SUPPORT_DECIMAL_SPECIFIERS       0
+#define PRINTF_SUPPORT_EXPONENTIAL_SPECIFIERS   0
+#define PRINTF_SUPPORT_WRITEBACK_SPECIFIER      0
+#define PRINTF_SUPPORT_LONG_LONG                1
+#define PRINTF_ALIAS_STANDARD_FUNCTION_NAMES    1