[kernel] Add a 'log available' signal to block on

There was previously no good way to block log-display tasks, either the
fb driver or the kernel log task. Now the system object has a signal
(j6_signal_system_has_log) that gets asserted when the log is written
to.
This commit is contained in:
Justin C. Miller
2021-01-18 18:28:15 -08:00
parent 99ef9166ae
commit 847d7ab38d
8 changed files with 111 additions and 28 deletions

View File

@@ -8,9 +8,42 @@
// Signals 16-47 are defined per-object-type // Signals 16-47 are defined per-object-type
// Process signals // Event signals
#define j7_signal_event00 (1ull << 16)
#define j7_signal_event01 (1ull << 17)
#define j7_signal_event02 (1ull << 18)
#define j7_signal_event03 (1ull << 19)
#define j7_signal_event04 (1ull << 20)
#define j7_signal_event05 (1ull << 21)
#define j7_signal_event06 (1ull << 22)
#define j7_signal_event07 (1ull << 23)
#define j7_signal_event08 (1ull << 24)
#define j7_signal_event09 (1ull << 25)
#define j7_signal_event10 (1ull << 26)
#define j7_signal_event11 (1ull << 27)
#define j7_signal_event12 (1ull << 28)
#define j7_signal_event13 (1ull << 29)
#define j7_signal_event14 (1ull << 30)
#define j7_signal_event15 (1ull << 31)
#define j7_signal_event16 (1ull << 32)
#define j7_signal_event17 (1ull << 33)
#define j7_signal_event18 (1ull << 34)
#define j7_signal_event19 (1ull << 35)
#define j7_signal_event20 (1ull << 36)
#define j7_signal_event21 (1ull << 37)
#define j7_signal_event22 (1ull << 38)
#define j7_signal_event23 (1ull << 39)
#define j7_signal_event24 (1ull << 40)
#define j7_signal_event25 (1ull << 41)
#define j7_signal_event26 (1ull << 42)
#define j7_signal_event27 (1ull << 43)
#define j7_signal_event28 (1ull << 44)
#define j7_signal_event29 (1ull << 45)
#define j7_signal_event30 (1ull << 46)
#define j7_signal_event31 (1ull << 47)
// Thread signals // System signals
#define j6_signal_system_has_log (1ull << 16)
// Channel signals // Channel signals
#define j6_signal_channel_can_send (1ull << 16) #define j6_signal_channel_can_send (1ull << 16)

View File

@@ -1,8 +1,10 @@
#include "j6/signals.h"
#include "kutil/memory.h" #include "kutil/memory.h"
#include "kutil/no_construct.h" #include "kutil/no_construct.h"
#include "console.h" #include "console.h"
#include "log.h" #include "log.h"
#include "scheduler.h" #include "objects/system.h"
#include "objects/thread.h"
static uint8_t log_buffer[0x10000]; static uint8_t log_buffer[0x10000];
@@ -26,29 +28,54 @@ output_log(log::area_t area, log::level severity, const char *message)
cons->set_color(); cons->set_color();
} }
static void
log_flush()
{
system &sys = system::get();
sys.assert_signal(j6_signal_system_has_log);
}
void void
logger_task() logger_task()
{ {
uint8_t buffer[257];
auto *ent = reinterpret_cast<log::logger::entry *>(buffer);
auto *cons = console::get(); auto *cons = console::get();
log::info(logs::task, "Starting kernel logger task"); log::info(logs::task, "Starting kernel logger task");
g_logger.set_immediate(nullptr); g_logger.set_immediate(nullptr);
g_logger.set_flush(log_flush);
scheduler &s = scheduler::get(); thread &self = thread::current();
system &sys = system::get();
size_t buffer_size = 1;
uint8_t *buffer = nullptr;
while (true) { while (true) {
if(g_logger.get_entry(buffer, sizeof(buffer))) { size_t size = g_logger.get_entry(buffer, buffer_size);
if (size > buffer_size) {
while (size > buffer_size) buffer_size *= 2;
kutil::kfree(buffer);
buffer = reinterpret_cast<uint8_t*>(kutil::kalloc(buffer_size));
kassert(buffer, "Could not allocate logger task buffer");
continue;
}
if(size) {
auto *ent = reinterpret_cast<log::logger::entry *>(buffer);
buffer[ent->bytes] = 0; buffer[ent->bytes] = 0;
cons->set_color(level_colors[static_cast<int>(ent->severity)]); cons->set_color(level_colors[static_cast<int>(ent->severity)]);
cons->printf("%7s %5s: %s\n", cons->printf("%7s %5s: %s\n",
g_logger.area_name(ent->area), g_logger.area_name(ent->area),
g_logger.level_name(ent->severity), g_logger.level_name(ent->severity),
ent->message); ent->message);
cons->set_color(); cons->set_color();
} else { }
s.schedule();
if (!g_logger.has_log()) {
sys.deassert_signal(j6_signal_system_has_log);
sys.add_blocked_thread(&self);
self.wait_on_signals(&sys, j6_signal_system_has_log);
} }
} }
} }

View File

@@ -200,7 +200,7 @@ kernel_main(args::header *header)
} }
if (!has_video) if (!has_video)
sched->create_kernel_task(logger_task, scheduler::max_priority-1, true); sched->create_kernel_task(logger_task, scheduler::max_priority/2, true);
sched->create_kernel_task(stdout_task, scheduler::max_priority-1, true); sched->create_kernel_task(stdout_task, scheduler::max_priority-1, true);
const char stdout_message[] = "Hello on the fake stdout channel\n"; const char stdout_message[] = "Hello on the fake stdout channel\n";

View File

@@ -10,7 +10,7 @@ class system :
public: public:
static constexpr kobject::type type = kobject::type::event; static constexpr kobject::type type = kobject::type::event;
inline static system * get() { return &s_instance; } inline static system & get() { return s_instance; }
private: private:
static system s_instance; static system s_instance;

View File

@@ -112,7 +112,7 @@ load_process_image(uintptr_t phys, uintptr_t virt, size_t bytes, TCB *tcb)
j6_init_value *initv = push<j6_init_value>(tcb->rsp3); j6_init_value *initv = push<j6_init_value>(tcb->rsp3);
initv->type = j6_init_handle_system; initv->type = j6_init_handle_system;
initv->value = static_cast<uint64_t>(proc.add_handle(system::get())); initv->value = static_cast<uint64_t>(proc.add_handle(&system::get()));
initv = push<j6_init_value>(tcb->rsp3); initv = push<j6_init_value>(tcb->rsp3);
initv->type = j6_init_handle_process; initv->type = j6_init_handle_process;

View File

@@ -5,6 +5,7 @@
#include "log.h" #include "log.h"
#include "objects/endpoint.h" #include "objects/endpoint.h"
#include "objects/thread.h" #include "objects/thread.h"
#include "objects/system.h"
#include "syscalls/helpers.h" #include "syscalls/helpers.h"
extern log::logger &g_logger; extern log::logger &g_logger;
@@ -33,8 +34,15 @@ system_noop()
j6_status_t j6_status_t
system_get_log(j6_handle_t sys, char *buffer, size_t *size) system_get_log(j6_handle_t sys, char *buffer, size_t *size)
{ {
if (!size || (*size && !buffer))
return j6_err_invalid_arg;
size_t orig_size = *size;
*size = g_logger.get_entry(buffer, *size); *size = g_logger.get_entry(buffer, *size);
return j6_status_ok; if (!g_logger.has_log())
system::get().deassert_signal(j6_signal_system_has_log);
return (*size > orig_size) ? j6_err_insufficient : j6_status_ok;
} }
j6_status_t j6_status_t

View File

@@ -19,17 +19,20 @@ class logger
{ {
public: public:
/// Callback type for immediate-mode logging /// Callback type for immediate-mode logging
typedef void (*immediate)(area_t, level, const char *); 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. /// Default constructor. Creates a logger without a backing store.
/// \arg output Immediate-mode logging output function /// \arg output Immediate-mode logging output function
logger(immediate output = nullptr); logger(immediate_cb output = nullptr);
/// Constructor. Logs are written to the given buffer. /// Constructor. Logs are written to the given buffer.
/// \arg buffer Buffer to which logs are written /// \arg buffer Buffer to which logs are written
/// \arg size Size of `buffer`, in bytes /// \arg size Size of `buffer`, in bytes
/// \arg output Immediate-mode logging output function /// \arg output Immediate-mode logging output function
logger(uint8_t *buffer, size_t size, immediate output = nullptr); logger(uint8_t *buffer, size_t size, immediate_cb output = nullptr);
/// Register a log area for future use. /// Register a log area for future use.
/// \arg area The key for the new area /// \arg area The key for the new area
@@ -38,7 +41,10 @@ public:
void register_area(area_t area, const char *name, level verbosity); void register_area(area_t area, const char *name, level verbosity);
/// Register an immediate-mode log callback /// Register an immediate-mode log callback
inline void set_immediate(immediate cb) { m_immediate = cb; } 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. /// Get the default logger.
inline logger & get() { return *s_log; } inline logger & get() { return *s_log; }
@@ -77,9 +83,13 @@ public:
/// Get the next log entry from the buffer /// Get the next log entry from the buffer
/// \arg buffer The buffer to copy the log message into /// \arg buffer The buffer to copy the log message into
/// \arg size Size of the passed-in buffer, in bytes /// \arg size Size of the passed-in buffer, in bytes
/// \returns Number of bytes copied into the buffer /// \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); 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: private:
friend void debug(area_t area, const char *fmt, ...); friend void debug(area_t area, const char *fmt, ...);
friend void info (area_t area, const char *fmt, ...); friend void info (area_t area, const char *fmt, ...);
@@ -95,7 +105,8 @@ private:
static const unsigned num_areas = 1 << (sizeof(area_t) * 8); static const unsigned num_areas = 1 << (sizeof(area_t) * 8);
uint8_t m_levels[num_areas / 2]; uint8_t m_levels[num_areas / 2];
const char *m_names[num_areas]; const char *m_names[num_areas];
immediate m_immediate; immediate_cb m_immediate;
flush_cb m_flush;
uint8_t m_sequence; uint8_t m_sequence;

View File

@@ -21,9 +21,10 @@ using kutil::memcpy;
logger *logger::s_log = nullptr; logger *logger::s_log = nullptr;
const char *logger::s_level_names[] = {"", "debug", "info", "warn", "error", "fatal"}; const char *logger::s_level_names[] = {"", "debug", "info", "warn", "error", "fatal"};
logger::logger(logger::immediate output) : logger::logger(logger::immediate_cb output) :
m_buffer(nullptr, 0), m_buffer(nullptr, 0),
m_immediate(output), m_immediate(output),
m_flush(nullptr),
m_sequence(0) m_sequence(0)
{ {
memset(&m_levels, 0, sizeof(m_levels)); memset(&m_levels, 0, sizeof(m_levels));
@@ -31,9 +32,10 @@ logger::logger(logger::immediate output) :
s_log = this; s_log = this;
} }
logger::logger(uint8_t *buffer, size_t size, logger::immediate output) : logger::logger(uint8_t *buffer, size_t size, logger::immediate_cb output) :
m_buffer(buffer, size), m_buffer(buffer, size),
m_immediate(output), m_immediate(output),
m_flush(nullptr),
m_sequence(0) m_sequence(0)
{ {
memset(&m_levels, 0, sizeof(m_levels)); memset(&m_levels, 0, sizeof(m_levels));
@@ -107,6 +109,9 @@ logger::output(level severity, area_t area, const char *fmt, va_list args)
memcpy(out, buffer, n); memcpy(out, buffer, n);
m_buffer.commit(n); m_buffer.commit(n);
if (m_flush)
m_flush();
} }
size_t size_t
@@ -114,7 +119,6 @@ logger::get_entry(void *buffer, size_t size)
{ {
void *out; void *out;
size_t out_size = m_buffer.get_block(&out); size_t out_size = m_buffer.get_block(&out);
entry *ent = reinterpret_cast<entry *>(out);
if (out_size == 0 || out == 0) if (out_size == 0 || out == 0)
return 0; return 0;
@@ -122,13 +126,13 @@ logger::get_entry(void *buffer, size_t size)
if (out_size < sizeof(entry)) if (out_size < sizeof(entry))
return 0; return 0;
kassert(size >= ent->bytes, "Didn't pass a big enough buffer"); entry *ent = reinterpret_cast<entry *>(out);
if (size < ent->bytes) if (size >= out_size) {
return 0;
memcpy(buffer, out, ent->bytes); memcpy(buffer, out, ent->bytes);
m_buffer.consume(ent->bytes); m_buffer.consume(ent->bytes);
return ent->bytes; }
return out_size;
} }
#define LOG_LEVEL_FUNCTION(name) \ #define LOG_LEVEL_FUNCTION(name) \