From 038dd9f30edbb53e99088050708faddad88881ca Mon Sep 17 00:00:00 2001 From: Tom Date: Thu, 2 Jul 2020 08:34:08 -0600 Subject: [PATCH] AK: Serialize entire log statements Prior to this, we wrote to the log every time the << operator was used, which meant that only these parts of the log statement were serialized. If the thread was preempted, or especially with multiple CPUs the debug output was hard to decipher. Instead, we buffer up the log statements. To avoid allocations we'll attempt to use stack space, which covers most log statements. --- AK/ByteBuffer.h | 1 - AK/LogStream.cpp | 14 +++++++--- AK/LogStream.h | 72 ++++++++++++++++++++++++++++++++++++++---------- 3 files changed, 68 insertions(+), 19 deletions(-) diff --git a/AK/ByteBuffer.h b/AK/ByteBuffer.h index 945461eee34..9772e2091fb 100644 --- a/AK/ByteBuffer.h +++ b/AK/ByteBuffer.h @@ -26,7 +26,6 @@ #pragma once -#include #include #include #include diff --git a/AK/LogStream.cpp b/AK/LogStream.cpp index 8a637bf5a22..52185d1530e 100644 --- a/AK/LogStream.cpp +++ b/AK/LogStream.cpp @@ -153,15 +153,21 @@ DebugLogStream klog() #ifdef KERNEL KernelLogStream::~KernelLogStream() { - char newline = '\n'; - write(&newline, 1); + if (!empty()) { + char newline = '\n'; + write(&newline, 1); + kernelputstr(reinterpret_cast(data()), size()); + } } #endif DebugLogStream::~DebugLogStream() { - char newline = '\n'; - write(&newline, 1); + if (!empty()) { + char newline = '\n'; + write(&newline, 1); + dbgputstr(reinterpret_cast(data()), size()); + } } #ifndef KERNEL diff --git a/AK/LogStream.h b/AK/LogStream.h index e51556d351a..1a1a937ad0e 100644 --- a/AK/LogStream.h +++ b/AK/LogStream.h @@ -28,6 +28,7 @@ #include #include +#include #include #if !defined(KERNEL) @@ -47,7 +48,7 @@ public: #endif { } - virtual ~LogStream() {} + virtual ~LogStream() { } virtual void write(const char*, int) const = 0; @@ -57,15 +58,63 @@ private: #endif }; -class DebugLogStream final : public LogStream { -public: - DebugLogStream() {} - virtual ~DebugLogStream() override; +class BufferedLogStream : public LogStream { + mutable size_t m_size { 0 }; + mutable size_t m_capacity { 128 }; + union { + mutable u8* m_buffer { nullptr }; + mutable u8 m_local_buffer[128]; + } u; - virtual void write(const char* characters, int length) const override + void grow(size_t bytes_needed) const { - dbgputstr(characters, length); + size_t new_capacity = (m_size + bytes_needed + 0x7F) & ~0x7F; + u8* new_data = static_cast(kmalloc(new_capacity)); + if (m_capacity <= sizeof(u.m_local_buffer)) { + __builtin_memcpy(new_data, u.m_local_buffer, m_size); + } else if (u.m_buffer) { + __builtin_memcpy(new_data, u.m_buffer, m_size); + kfree(u.m_buffer); + } + u.m_buffer = new_data; + m_capacity = new_capacity; } + +protected: + u8* data() const + { + if (m_capacity <= sizeof(u.m_local_buffer)) + return u.m_local_buffer; + return u.m_buffer; + } + + size_t size() const { return m_size; } + + bool empty() const { return m_size == 0; } + +public: + BufferedLogStream() { } + + virtual ~BufferedLogStream() override + { + if (m_capacity > sizeof(u.m_local_buffer)) + kfree(u.m_buffer); + } + + virtual void write(const char* str, int len) const override + { + size_t new_size = m_size + len; + if (new_size > m_capacity) + grow(len); + __builtin_memcpy(data() + m_size, str, len); + m_size = new_size; + } +}; + +class DebugLogStream final : public BufferedLogStream { +public: + DebugLogStream() { } + virtual ~DebugLogStream() override; }; #if !defined(KERNEL) @@ -87,15 +136,10 @@ inline StdLogStream warn() { return StdLogStream(STDERR_FILENO); } #endif #ifdef KERNEL -class KernelLogStream final : public LogStream { +class KernelLogStream final : public BufferedLogStream { public: - KernelLogStream() {} + KernelLogStream() { } virtual ~KernelLogStream() override; - - virtual void write(const char* characters, int length) const override - { - kernelputstr(characters, length); - } }; #endif