From 5c5665c1e753d3123415326ebbc06ec6111e2486 Mon Sep 17 00:00:00 2001 From: asynts Date: Sun, 17 Jan 2021 16:06:30 +0100 Subject: [PATCH] Everywhere: Replace a bundle of dbg with dbgln. These changes are arbitrarily divided into multiple commits to make it easier to find potentially introduced bugs with git bisect. --- AK/Debug.h | 18 +++++ Userland/Libraries/LibMarkdown/Table.cpp | 5 +- Userland/Libraries/LibRegex/RegexByteCode.cpp | 9 +-- Userland/Libraries/LibRegex/RegexMatch.h | 8 +++ Userland/Libraries/LibRegex/RegexMatcher.cpp | 14 ++-- Userland/Libraries/LibTLS/ClientHandshake.cpp | 22 ++---- Userland/Libraries/LibTLS/Record.cpp | 71 ++++++++----------- Userland/Libraries/LibTLS/Socket.cpp | 21 +++--- 8 files changed, 86 insertions(+), 82 deletions(-) diff --git a/AK/Debug.h b/AK/Debug.h index 44649cc006..6ff72e73f0 100644 --- a/AK/Debug.h +++ b/AK/Debug.h @@ -399,3 +399,21 @@ constexpr bool debug_keyboard_shortcuts = true; #else constexpr bool debug_keyboard_shortcuts = false; #endif + +#ifdef DEBUG_MARKDOWN +constexpr bool debug_markdown = true; +#else +constexpr bool debug_markdown = false; +#endif + +#ifdef REGEX_DEBUG +constexpr bool debug_regex = true; +#else +constexpr bool debug_regex = false; +#endif + +#ifdef TLS_DEBUG +constexpr bool debug_tls = true; +#else +constexpr bool debug_tls = false; +#endif diff --git a/Userland/Libraries/LibMarkdown/Table.cpp b/Userland/Libraries/LibMarkdown/Table.cpp index b33fb9c532..81bd1c5360 100644 --- a/Userland/Libraries/LibMarkdown/Table.cpp +++ b/Userland/Libraries/LibMarkdown/Table.cpp @@ -24,6 +24,7 @@ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. */ +#include #include #include @@ -181,9 +182,7 @@ OwnPtr Table::parse(Vector::ConstIterator& lines) size_t relative_width = delimiter.length(); for (auto ch : delimiter) { if (ch != '-') { -#ifdef DEBUG_MARKDOWN - dbg() << "Invalid character _" << ch << "_ in table heading delimiter (ignored)"; -#endif + dbgln("Invalid character _{}_ in table heading delimiter (ignored)", ch); --relative_width; } } diff --git a/Userland/Libraries/LibRegex/RegexByteCode.cpp b/Userland/Libraries/LibRegex/RegexByteCode.cpp index 63f526ee9a..5f124b3468 100644 --- a/Userland/Libraries/LibRegex/RegexByteCode.cpp +++ b/Userland/Libraries/LibRegex/RegexByteCode.cpp @@ -27,6 +27,7 @@ #include "RegexByteCode.h" #include "AK/StringBuilder.h" #include "RegexDebug.h" +#include #include @@ -369,10 +370,10 @@ ALWAYS_INLINE ExecutionResult OpCode_SaveRightNamedCaptureGroup::execute(const M auto& map = output.named_capture_group_matches.at(input.match_index); -#ifdef REGEX_DEBUG - ASSERT(start_position + length <= input.view.length()); - dbg() << "Save named capture group with name=" << capture_group_name << " and content: " << input.view.substring_view(start_position, length).to_string(); -#endif + if constexpr (debug_regex) { + ASSERT(start_position + length <= input.view.length()); + dbgln("Save named capture group with name={} and content='{}'", capture_group_name, input.view.substring_view(start_position, length)); + } ASSERT(start_position + length <= input.view.length()); auto view = input.view.substring_view(start_position, length); diff --git a/Userland/Libraries/LibRegex/RegexMatch.h b/Userland/Libraries/LibRegex/RegexMatch.h index 26f31d7eeb..d688dcab0f 100644 --- a/Userland/Libraries/LibRegex/RegexMatch.h +++ b/Userland/Libraries/LibRegex/RegexMatch.h @@ -289,3 +289,11 @@ struct MatchOutput { } using regex::RegexStringView; + +template<> +struct AK::Formatter : Formatter { + void format(FormatBuilder& builder, const regex::RegexStringView& value) + { + return Formatter::format(builder, { value.characters_without_null_termination(), value.length() }); + } +}; diff --git a/Userland/Libraries/LibRegex/RegexMatcher.cpp b/Userland/Libraries/LibRegex/RegexMatcher.cpp index fd2f7dab75..14c461fbb4 100644 --- a/Userland/Libraries/LibRegex/RegexMatcher.cpp +++ b/Userland/Libraries/LibRegex/RegexMatcher.cpp @@ -27,6 +27,7 @@ #include "RegexMatcher.h" #include "RegexDebug.h" #include "RegexParser.h" +#include #include #include #include @@ -147,9 +148,7 @@ RegexResult Matcher::match(const Vector views, Optional for (auto& view : views) { input.view = view; -#ifdef REGEX_DEBUG - dbg() << "[match] Starting match with view (" << view.length() << "): _" << view.to_string() << "_"; -#endif + dbgln("[match] Starting match with view ({}): _{}_", view.length(), view); auto view_length = view.length(); size_t view_index = m_pattern.start_offset; @@ -215,10 +214,11 @@ RegexResult Matcher::match(const Vector views, Optional continue; } -#ifdef REGEX_DEBUG - dbg() << "state.string_position: " << state.string_position << " view_index: " << view_index; - dbg() << "[match] Found a match (length = " << state.string_position - view_index << "): " << input.view.substring_view(view_index, state.string_position - view_index).to_string(); -#endif + if constexpr (debug_regex) { + dbgln("state.string_position={}, view_index={}", state.string_position, view_index); + dbgln("[match] Found a match (length={}): '{}'", state.string_position - view_index, input.view.substring_view(view_index, state.string_position - view_index)); + } + ++match_count; if (continue_search) { diff --git a/Userland/Libraries/LibTLS/ClientHandshake.cpp b/Userland/Libraries/LibTLS/ClientHandshake.cpp index 6a5d855a3b..ddd754e785 100644 --- a/Userland/Libraries/LibTLS/ClientHandshake.cpp +++ b/Userland/Libraries/LibTLS/ClientHandshake.cpp @@ -24,6 +24,7 @@ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. */ +#include #include #include @@ -111,9 +112,7 @@ ssize_t TLSv12::handle_hello(ReadonlyBytes buffer, WritePacketStage& write_packe return (i8)Error::NoCommonCipher; } m_context.cipher = cipher; -#ifdef TLS_DEBUG - dbg() << "Cipher: " << (u16)cipher; -#endif + dbgln("Cipher: {}", (u16)cipher); // The handshake hash function is _always_ SHA256 m_context.handshake_hash.initialize(Crypto::Hash::HashKind::SHA256); @@ -147,9 +146,8 @@ ssize_t TLSv12::handle_hello(ReadonlyBytes buffer, WritePacketStage& write_packe u16 extension_length = AK::convert_between_host_and_network_endian(*(const u16*)buffer.offset_pointer(res)); res += 2; -#ifdef TLS_DEBUG - dbg() << "extension " << (u16)extension_type << " with length " << extension_length; -#endif + dbgln("extension {} with length {}", (u16)extension_type, extension_length); + if (extension_length) { if (buffer.size() - res < extension_length) { dbgln("not enough data for extension"); @@ -220,16 +218,12 @@ ssize_t TLSv12::handle_finished(ReadonlyBytes buffer, WritePacketStage& write_pa u32 size = buffer[0] * 0x10000 + buffer[1] * 0x100 + buffer[2]; if (size < 12) { -#ifdef TLS_DEBUG - dbg() << "finished packet smaller than minimum size: " << size; -#endif + dbgln("finished packet smaller than minimum size: {}", size); return (i8)Error::BrokenPacket; } if (size < buffer.size() - index) { -#ifdef TLS_DEBUG - dbg() << "not enough data after length: " << size << " > " << buffer.size() - index; -#endif + dbgln("not enough data after length: {} > {}", size, buffer.size() - index); return (i8)Error::NeedMoreData; } @@ -330,9 +324,7 @@ ssize_t TLSv12::handle_payload(ReadonlyBytes vbuffer) auto type = buffer[0]; auto write_packets { WritePacketStage::Initial }; size_t payload_size = buffer[1] * 0x10000 + buffer[2] * 0x100 + buffer[3] + 3; -#ifdef TLS_DEBUG - dbg() << "payload size: " << payload_size << " buffer length: " << buffer_length; -#endif + dbgln("payload size: {} buffer length: {}", payload_size, buffer_length); if (payload_size + 1 > buffer_length) return (i8)Error::NeedMoreData; diff --git a/Userland/Libraries/LibTLS/Record.cpp b/Userland/Libraries/LibTLS/Record.cpp index c877bd2f21..1850e03818 100644 --- a/Userland/Libraries/LibTLS/Record.cpp +++ b/Userland/Libraries/LibTLS/Record.cpp @@ -24,8 +24,8 @@ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. */ +#include #include - #include #include #include @@ -39,16 +39,12 @@ void TLSv12::write_packet(ByteBuffer& packet) m_context.tls_buffer.append(packet.data(), packet.size()); if (m_context.connection_status > ConnectionStatus::Disconnected) { if (!m_has_scheduled_write_flush) { -#ifdef TLS_DEBUG - dbg() << "Scheduling write of " << m_context.tls_buffer.size(); -#endif + dbgln("Scheduling write of {}", m_context.tls_buffer.size()); deferred_invoke([this](auto&) { write_into_socket(); }); m_has_scheduled_write_flush = true; } else { // multiple packet are available, let's flush some out -#ifdef TLS_DEBUG - dbg() << "Flushing scheduled write of " << m_context.tls_buffer.size(); -#endif + dbgln("Flushing scheduled write of {}", m_context.tls_buffer.size()); write_into_socket(); // the deferred invoke is still in place m_has_scheduled_write_flush = true; @@ -219,10 +215,12 @@ ByteBuffer TLSv12::hmac_message(const ReadonlyBytes& buf, const Optional("buffer size: {}", buffer.size()); + if (buffer.size() < 5) { return (i8)Error::NeedMoreData; } @@ -243,37 +240,33 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer) size_t buffer_position { 1 }; // FIXME: Read the version and verify it -#ifdef TLS_DEBUG - auto version = (Version) * (const u16*)buffer.offset_pointer(buffer_position); - dbg() << "type: " << (u8)type << " version: " << (u16)version; -#endif + + if constexpr (debug_tls) { + auto version = (Version) * (const u16*)buffer.offset_pointer(buffer_position); + dbgln("type={}, version={}", (u8)type, (u16)version); + } + buffer_position += 2; auto length = AK::convert_between_host_and_network_endian(*(const u16*)buffer.offset_pointer(buffer_position)); -#ifdef TLS_DEBUG - dbg() << "record length: " << length << " at offset: " << buffer_position; -#endif + dbgln("record length: {} at offset: {}", length, buffer_position); buffer_position += 2; if (buffer_position + length > buffer.size()) { -#ifdef TLS_DEBUG - dbg() << "record length more than what we have: " << buffer.size(); -#endif + dbgln("record length more than what we have: {}", buffer.size()); return (i8)Error::NeedMoreData; } -#ifdef TLS_DEBUG - dbg() << "message type: " << (u8)type << ", length: " << length; -#endif + dbgln("message type: {}, length: {}", (u8)type, length); auto plain = buffer.slice(buffer_position, buffer.size() - buffer_position); ByteBuffer decrypted; if (m_context.cipher_spec_set && type != MessageType::ChangeCipher) { -#ifdef TLS_DEBUG - dbgln("Encrypted: "); - print_buffer(buffer.slice(header_size, length)); -#endif + if constexpr (debug_tls) { + dbgln("Encrypted: "); + print_buffer(buffer.slice(header_size, length)); + } if (is_aead()) { ASSERT(m_aes_remote.gcm); @@ -396,9 +389,7 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer) auto packet = build_alert(true, (u8)AlertDescription::UnexpectedMessage); write_packet(packet); } else { -#ifdef TLS_DEBUG - dbg() << "application data message of size " << plain.size(); -#endif + dbgln("application data message of size {}", plain.size()); m_context.application_buffer.append(plain.data(), plain.size()); } @@ -423,13 +414,11 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer) } break; case MessageType::Alert: -#ifdef TLS_DEBUG - dbg() << "alert message of length " << length; -#endif + dbgln("alert message of length {}", length); if (length >= 2) { -#ifdef TLS_DEBUG - print_buffer(plain); -#endif + if constexpr (debug_tls) + print_buffer(plain); + auto level = plain[0]; auto code = plain[1]; if (level == (u8)AlertLevel::Critical) { @@ -438,7 +427,7 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer) try_disambiguate_error(); res = (i8)Error::UnknownError; } else { - dbg() << "Alert: " << code; + dbgln("Alert: {}", code); } if (code == 0) { // close notify diff --git a/Userland/Libraries/LibTLS/Socket.cpp b/Userland/Libraries/LibTLS/Socket.cpp index fd7c97761f..bf38aaa7b5 100644 --- a/Userland/Libraries/LibTLS/Socket.cpp +++ b/Userland/Libraries/LibTLS/Socket.cpp @@ -24,6 +24,7 @@ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. */ +#include #include #include #include @@ -173,9 +174,8 @@ void TLSv12::read_from_socket() void TLSv12::write_into_socket() { -#ifdef TLS_DEBUG - dbg() << "Flushing cached records: " << m_context.tls_buffer.size() << " established? " << is_established(); -#endif + dbgln("Flushing cached records: {} established? {}", m_context.tls_buffer.size(), is_established()); + m_has_scheduled_write_flush = false; if (!check_connection_state(false)) return; @@ -199,9 +199,8 @@ bool TLSv12::check_connection_state(bool read) m_context.connection_finished = true; } if (m_context.critical_error) { -#ifdef TLS_DEBUG - dbg() << "CRITICAL ERROR " << m_context.critical_error << " :("; -#endif + dbgln("CRITICAL ERROR {} :(", m_context.critical_error); + if (on_tls_error) on_tls_error((AlertDescription)m_context.critical_error); return false; @@ -212,9 +211,9 @@ bool TLSv12::check_connection_state(bool read) on_tls_finished(); } if (m_context.tls_buffer.size()) { -#ifdef TLS_DEBUG - dbg() << "connection closed without finishing data transfer, " << m_context.tls_buffer.size() << " bytes still in buffer & " << m_context.application_buffer.size() << " bytes in application buffer"; -#endif + dbgln("connection closed without finishing data transfer, {} bytes still in buffer and {} bytes in application buffer", + m_context.tls_buffer.size(), + m_context.application_buffer.size()); } else { m_context.connection_finished = false; #ifdef TLS_DEBUG @@ -248,9 +247,7 @@ bool TLSv12::flush() } if (m_context.send_retries++ == 10) { // drop the records, we can't send -#ifdef TLS_DEBUG - dbg() << "Dropping " << write_buffer().size() << " bytes worth of TLS records as max retries has been reached"; -#endif + dbgln("Dropping {} bytes worth of TLS records as max retries has been reached", write_buffer().size()); write_buffer().clear(); m_context.send_retries = 0; }