diff --git a/definitions/objects/system.def b/definitions/objects/system.def index c95ac02..adb7aa2 100644 --- a/definitions/objects/system.def +++ b/definitions/objects/system.def @@ -10,9 +10,10 @@ object system : object { change_iopl ] - # Get a log line from the kernel log + # Get the next log line from the kernel log method get_log [cap:get_log] { - param buffer buffer [out zero_ok] # Buffer for the log message data structure + param seen uint64 # Last seen log id + param buffer buffer [out zero_ok] # Buffer for the log message data structure } # Ask the kernel to send this process messages whenever diff --git a/src/kernel/logger.cpp b/src/kernel/logger.cpp index fd6cc21..6d7e8fc 100644 --- a/src/kernel/logger.cpp +++ b/src/kernel/logger.cpp @@ -18,18 +18,31 @@ log::logger &g_logger = __g_logger_storage.value; namespace log { +namespace { + +} // anon namespace + logger *logger::s_log = nullptr; logger::logger() : - m_buffer {nullptr, 0} + m_buffer {nullptr, 0}, + m_start {0}, + m_end {0}, + m_count {0} { memset(&m_levels, 0, sizeof(m_levels)); s_log = this; } logger::logger(util::buffer data) : - m_buffer {data.pointer, data.count} + m_buffer {data}, + m_start {0}, + m_end {0}, + m_count {0} { + kassert((data.count & (data.count - 1)) == 0, + "log buffer size must be a power of two"); + memset(&m_levels, 0, sizeof(m_levels)); s_log = this; @@ -42,59 +55,56 @@ logger::logger(util::buffer data) : void logger::output(level severity, logs area, const char *fmt, va_list args) { - char buffer[256]; + static constexpr size_t buffer_len = 256; + static constexpr size_t message_len = buffer_len - sizeof(entry); + char buffer[buffer_len]; entry *header = reinterpret_cast(buffer); - header->bytes = sizeof(entry); - header->area = area; - header->severity = severity; - size_t mlen = util::vformat({header->message, sizeof(buffer) - sizeof(entry) - 1}, fmt, args); - header->message[mlen] = 0; - header->bytes += mlen + 1; + size_t size = sizeof(buffer); + size += util::vformat({header->message, message_len}, fmt, args); util::scoped_lock lock {m_lock}; - uint8_t *out; - size_t n = m_buffer.reserve(header->bytes, reinterpret_cast(&out)); - if (n < header->bytes) { - m_buffer.commit(0); // Cannot write the message, give up - return; + while (free() < size) { + // Remove old entries until there's enough space + const entry *first = util::at(m_buffer, start()); + m_start += first->bytes; } - memcpy(out, buffer, n); - m_buffer.commit(n); + header->id = ++m_count; + header->bytes = size; + header->severity = severity; + header->area = area; + + memcpy(util::at(m_buffer, end()), buffer, size); + m_end += size; m_waiting.clear(); } size_t -logger::get_entry(void *buffer, size_t size) +logger::get_entry(uint64_t seen, void *buffer, size_t size) { util::scoped_lock lock {m_lock}; - void *out; - size_t out_size = m_buffer.get_block(&out); - if (out_size == 0 || out == 0) { + while (seen == m_count) { lock.release(); m_waiting.wait(); lock.reacquire(); - 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(out); - if (size >= ent->bytes) { - memcpy(buffer, out, ent->bytes); - m_buffer.consume(ent->bytes); + size_t off = m_start; + entry *ent = util::at(m_buffer, off); + while (seen >= ent->id) { + off += ent->bytes; + kassert(off < m_end, "Got to the end while looking for new log entry"); + ent = util::at(m_buffer, off); } + if (size >= ent->bytes) + memcpy(buffer, ent, ent->bytes); + return ent->bytes; } diff --git a/src/kernel/logger.h b/src/kernel/logger.h index b788111..50605c7 100644 --- a/src/kernel/logger.h +++ b/src/kernel/logger.h @@ -5,7 +5,6 @@ #include #include -#include #include #include @@ -20,7 +19,7 @@ enum class logs : uint8_t { namespace log { -/// Size of the log ring buffer +/// Size of the log ring buffer. Must be a power of two. inline constexpr unsigned log_pages = 16; enum class level : uint8_t { @@ -60,21 +59,25 @@ public: struct entry { - uint8_t bytes; - logs area; - level severity; + uint64_t id : 42; + uint16_t bytes : 11; + level severity : 4; + logs area : 7; char message[0]; }; - /// Get the next log entry from the buffer + /// Get the next log entry from the buffer. Blocks the current thread until + /// a log arrives if there are no entries newer than `seen`. + /// \arg seen The id of the last-seen log entry, or 0 for none /// \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); + size_t get_entry(uint64_t seen, void *buffer, size_t size); - /// Get whether there is currently data in the log buffer - inline bool has_log() const { return m_buffer.size(); } + /// Check whether or not there's a new log entry to get + /// \arg seen The id of the last-seen log entry, or 0 for none + inline bool has_entry(uint64_t seen) { return seen < m_count; } private: friend void spam (logs area, const char *fmt, ...); @@ -94,11 +97,19 @@ private: return m_levels[static_cast(area)]; } - wait_queue m_waiting; + inline size_t offset(size_t i) const { return i & (m_buffer.count - 1); } + + inline size_t start() const { return offset(m_start); } + inline size_t end() const { return offset(m_end); } + inline size_t free() const { return m_buffer.count - (m_end - m_start); } level m_levels[areas_count]; - util::bip_buffer m_buffer; + util::buffer m_buffer; + size_t m_start, m_end; + uint64_t m_count; + + wait_queue m_waiting; util::spinlock m_lock; static logger *s_log; diff --git a/src/kernel/syscalls/system.cpp b/src/kernel/syscalls/system.cpp index 2d98a16..1750a01 100644 --- a/src/kernel/syscalls/system.cpp +++ b/src/kernel/syscalls/system.cpp @@ -45,10 +45,10 @@ test_finish(uint32_t exit_code) } j6_status_t -system_get_log(system *self, void *buffer, size_t *buffer_len) +system_get_log(system *self, uint64_t seen, void *buffer, size_t *buffer_len) { size_t orig_size = *buffer_len; - *buffer_len = g_logger.get_entry(buffer, *buffer_len); + *buffer_len = g_logger.get_entry(seen, buffer, *buffer_len); return (*buffer_len > orig_size) ? j6_err_insufficient : j6_status_ok; } diff --git a/src/user/srv.logger/main.cpp b/src/user/srv.logger/main.cpp index 484e6e1..1e91d72 100644 --- a/src/user/srv.logger/main.cpp +++ b/src/user/srv.logger/main.cpp @@ -22,9 +22,10 @@ j6_handle_t g_handle_sys = j6_handle_invalid; struct entry { - uint8_t bytes; - uint8_t area; - uint8_t severity; + uint64_t id : 42; + uint16_t bytes : 11; + uint8_t severity : 4; + uint8_t area : 7; char message[0]; }; @@ -79,9 +80,11 @@ log_pump_proc(j6_handle_t cout) if (result != j6_status_ok) return; + uint64_t seen = 0; + while (true) { size_t size = buffer_size; - j6_status_t s = j6_system_get_log(g_handle_sys, message_buffer, &size); + j6_status_t s = j6_system_get_log(g_handle_sys, seen, message_buffer, &size); if (s == j6_err_insufficient) { free(message_buffer); @@ -95,6 +98,7 @@ log_pump_proc(j6_handle_t cout) const entry *e = reinterpret_cast(message_buffer); + seen = e->id; const char *area_name = area_names[e->area]; const char *level_name = level_names[e->severity]; uint8_t level_color = level_colors[e->severity];