1
Fork 0
mirror of https://github.com/RGBCube/serenity synced 2025-07-26 04:47:34 +00:00

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.
This commit is contained in:
asynts 2021-01-17 16:06:30 +01:00 committed by Andreas Kling
parent 6dc2c38fd0
commit 5c5665c1e7
8 changed files with 86 additions and 82 deletions

View file

@ -399,3 +399,21 @@ constexpr bool debug_keyboard_shortcuts = true;
#else #else
constexpr bool debug_keyboard_shortcuts = false; constexpr bool debug_keyboard_shortcuts = false;
#endif #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

View file

@ -24,6 +24,7 @@
* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/ */
#include <AK/Debug.h>
#include <AK/StringBuilder.h> #include <AK/StringBuilder.h>
#include <LibMarkdown/Table.h> #include <LibMarkdown/Table.h>
@ -181,9 +182,7 @@ OwnPtr<Table> Table::parse(Vector<StringView>::ConstIterator& lines)
size_t relative_width = delimiter.length(); size_t relative_width = delimiter.length();
for (auto ch : delimiter) { for (auto ch : delimiter) {
if (ch != '-') { if (ch != '-') {
#ifdef DEBUG_MARKDOWN dbgln<debug_markdown>("Invalid character _{}_ in table heading delimiter (ignored)", ch);
dbg() << "Invalid character _" << ch << "_ in table heading delimiter (ignored)";
#endif
--relative_width; --relative_width;
} }
} }

View file

@ -27,6 +27,7 @@
#include "RegexByteCode.h" #include "RegexByteCode.h"
#include "AK/StringBuilder.h" #include "AK/StringBuilder.h"
#include "RegexDebug.h" #include "RegexDebug.h"
#include <AK/Debug.h>
#include <ctype.h> #include <ctype.h>
@ -369,10 +370,10 @@ ALWAYS_INLINE ExecutionResult OpCode_SaveRightNamedCaptureGroup::execute(const M
auto& map = output.named_capture_group_matches.at(input.match_index); auto& map = output.named_capture_group_matches.at(input.match_index);
#ifdef REGEX_DEBUG if constexpr (debug_regex) {
ASSERT(start_position + length <= input.view.length()); 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(); dbgln("Save named capture group with name={} and content='{}'", capture_group_name, input.view.substring_view(start_position, length));
#endif }
ASSERT(start_position + length <= input.view.length()); ASSERT(start_position + length <= input.view.length());
auto view = input.view.substring_view(start_position, length); auto view = input.view.substring_view(start_position, length);

View file

@ -289,3 +289,11 @@ struct MatchOutput {
} }
using regex::RegexStringView; using regex::RegexStringView;
template<>
struct AK::Formatter<regex::RegexStringView> : Formatter<StringView> {
void format(FormatBuilder& builder, const regex::RegexStringView& value)
{
return Formatter<StringView>::format(builder, { value.characters_without_null_termination(), value.length() });
}
};

View file

@ -27,6 +27,7 @@
#include "RegexMatcher.h" #include "RegexMatcher.h"
#include "RegexDebug.h" #include "RegexDebug.h"
#include "RegexParser.h" #include "RegexParser.h"
#include <AK/Debug.h>
#include <AK/ScopedValueRollback.h> #include <AK/ScopedValueRollback.h>
#include <AK/String.h> #include <AK/String.h>
#include <AK/StringBuilder.h> #include <AK/StringBuilder.h>
@ -147,9 +148,7 @@ RegexResult Matcher<Parser>::match(const Vector<RegexStringView> views, Optional
for (auto& view : views) { for (auto& view : views) {
input.view = view; input.view = view;
#ifdef REGEX_DEBUG dbgln<debug_regex>("[match] Starting match with view ({}): _{}_", view.length(), view);
dbg() << "[match] Starting match with view (" << view.length() << "): _" << view.to_string() << "_";
#endif
auto view_length = view.length(); auto view_length = view.length();
size_t view_index = m_pattern.start_offset; size_t view_index = m_pattern.start_offset;
@ -215,10 +214,11 @@ RegexResult Matcher<Parser>::match(const Vector<RegexStringView> views, Optional
continue; continue;
} }
#ifdef REGEX_DEBUG if constexpr (debug_regex) {
dbg() << "state.string_position: " << state.string_position << " view_index: " << view_index; dbgln("state.string_position={}, view_index={}", state.string_position, 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(); dbgln("[match] Found a match (length={}): '{}'", state.string_position - view_index, input.view.substring_view(view_index, state.string_position - view_index));
#endif }
++match_count; ++match_count;
if (continue_search) { if (continue_search) {

View file

@ -24,6 +24,7 @@
* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/ */
#include <AK/Debug.h>
#include <AK/Endian.h> #include <AK/Endian.h>
#include <AK/Random.h> #include <AK/Random.h>
@ -111,9 +112,7 @@ ssize_t TLSv12::handle_hello(ReadonlyBytes buffer, WritePacketStage& write_packe
return (i8)Error::NoCommonCipher; return (i8)Error::NoCommonCipher;
} }
m_context.cipher = cipher; m_context.cipher = cipher;
#ifdef TLS_DEBUG dbgln<debug_tls>("Cipher: {}", (u16)cipher);
dbg() << "Cipher: " << (u16)cipher;
#endif
// The handshake hash function is _always_ SHA256 // The handshake hash function is _always_ SHA256
m_context.handshake_hash.initialize(Crypto::Hash::HashKind::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)); u16 extension_length = AK::convert_between_host_and_network_endian(*(const u16*)buffer.offset_pointer(res));
res += 2; res += 2;
#ifdef TLS_DEBUG dbgln<debug_tls>("extension {} with length {}", (u16)extension_type, extension_length);
dbg() << "extension " << (u16)extension_type << " with length " << extension_length;
#endif
if (extension_length) { if (extension_length) {
if (buffer.size() - res < extension_length) { if (buffer.size() - res < extension_length) {
dbgln("not enough data for extension"); 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]; u32 size = buffer[0] * 0x10000 + buffer[1] * 0x100 + buffer[2];
if (size < 12) { if (size < 12) {
#ifdef TLS_DEBUG dbgln<debug_tls>("finished packet smaller than minimum size: {}", size);
dbg() << "finished packet smaller than minimum size: " << size;
#endif
return (i8)Error::BrokenPacket; return (i8)Error::BrokenPacket;
} }
if (size < buffer.size() - index) { if (size < buffer.size() - index) {
#ifdef TLS_DEBUG dbgln<debug_tls>("not enough data after length: {} > {}", size, buffer.size() - index);
dbg() << "not enough data after length: " << size << " > " << buffer.size() - index;
#endif
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }
@ -330,9 +324,7 @@ ssize_t TLSv12::handle_payload(ReadonlyBytes vbuffer)
auto type = buffer[0]; auto type = buffer[0];
auto write_packets { WritePacketStage::Initial }; auto write_packets { WritePacketStage::Initial };
size_t payload_size = buffer[1] * 0x10000 + buffer[2] * 0x100 + buffer[3] + 3; size_t payload_size = buffer[1] * 0x10000 + buffer[2] * 0x100 + buffer[3] + 3;
#ifdef TLS_DEBUG dbgln<debug_tls>("payload size: {} buffer length: {}", payload_size, buffer_length);
dbg() << "payload size: " << payload_size << " buffer length: " << buffer_length;
#endif
if (payload_size + 1 > buffer_length) if (payload_size + 1 > buffer_length)
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;

View file

@ -24,8 +24,8 @@
* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/ */
#include <AK/Debug.h>
#include <AK/Endian.h> #include <AK/Endian.h>
#include <AK/MemoryStream.h> #include <AK/MemoryStream.h>
#include <LibCore/Timer.h> #include <LibCore/Timer.h>
#include <LibCrypto/ASN1/DER.h> #include <LibCrypto/ASN1/DER.h>
@ -39,16 +39,12 @@ void TLSv12::write_packet(ByteBuffer& packet)
m_context.tls_buffer.append(packet.data(), packet.size()); m_context.tls_buffer.append(packet.data(), packet.size());
if (m_context.connection_status > ConnectionStatus::Disconnected) { if (m_context.connection_status > ConnectionStatus::Disconnected) {
if (!m_has_scheduled_write_flush) { if (!m_has_scheduled_write_flush) {
#ifdef TLS_DEBUG dbgln<debug_tls>("Scheduling write of {}", m_context.tls_buffer.size());
dbg() << "Scheduling write of " << m_context.tls_buffer.size();
#endif
deferred_invoke([this](auto&) { write_into_socket(); }); deferred_invoke([this](auto&) { write_into_socket(); });
m_has_scheduled_write_flush = true; m_has_scheduled_write_flush = true;
} else { } else {
// multiple packet are available, let's flush some out // multiple packet are available, let's flush some out
#ifdef TLS_DEBUG dbgln<debug_tls>("Flushing scheduled write of {}", m_context.tls_buffer.size());
dbg() << "Flushing scheduled write of " << m_context.tls_buffer.size();
#endif
write_into_socket(); write_into_socket();
// the deferred invoke is still in place // the deferred invoke is still in place
m_has_scheduled_write_flush = true; m_has_scheduled_write_flush = true;
@ -219,10 +215,12 @@ ByteBuffer TLSv12::hmac_message(const ReadonlyBytes& buf, const Optional<Readonl
} }
auto digest = hmac.digest(); auto digest = hmac.digest();
auto mac = ByteBuffer::copy(digest.immutable_data(), digest.data_length()); auto mac = ByteBuffer::copy(digest.immutable_data(), digest.data_length());
#ifdef TLS_DEBUG
dbg() << "HMAC of the block for sequence number " << sequence_number; if constexpr (debug_tls) {
print_buffer(mac); dbgln("HMAC of the block for sequence number {}", sequence_number);
#endif print_buffer(mac);
}
return mac; return mac;
} }
@ -232,9 +230,8 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer)
size_t header_size = res; size_t header_size = res;
ssize_t payload_res = 0; ssize_t payload_res = 0;
#ifdef TLS_DEBUG dbgln<debug_tls>("buffer size: {}", buffer.size());
dbg() << "buffer size: " << buffer.size();
#endif
if (buffer.size() < 5) { if (buffer.size() < 5) {
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }
@ -243,37 +240,33 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer)
size_t buffer_position { 1 }; size_t buffer_position { 1 };
// FIXME: Read the version and verify it // FIXME: Read the version and verify it
#ifdef TLS_DEBUG
auto version = (Version) * (const u16*)buffer.offset_pointer(buffer_position); if constexpr (debug_tls) {
dbg() << "type: " << (u8)type << " version: " << (u16)version; auto version = (Version) * (const u16*)buffer.offset_pointer(buffer_position);
#endif dbgln("type={}, version={}", (u8)type, (u16)version);
}
buffer_position += 2; buffer_position += 2;
auto length = AK::convert_between_host_and_network_endian(*(const u16*)buffer.offset_pointer(buffer_position)); auto length = AK::convert_between_host_and_network_endian(*(const u16*)buffer.offset_pointer(buffer_position));
#ifdef TLS_DEBUG dbgln<debug_tls>("record length: {} at offset: {}", length, buffer_position);
dbg() << "record length: " << length << " at offset: " << buffer_position;
#endif
buffer_position += 2; buffer_position += 2;
if (buffer_position + length > buffer.size()) { if (buffer_position + length > buffer.size()) {
#ifdef TLS_DEBUG dbgln<debug_tls>("record length more than what we have: {}", buffer.size());
dbg() << "record length more than what we have: " << buffer.size();
#endif
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }
#ifdef TLS_DEBUG dbgln<debug_tls>("message type: {}, length: {}", (u8)type, length);
dbg() << "message type: " << (u8)type << ", length: " << length;
#endif
auto plain = buffer.slice(buffer_position, buffer.size() - buffer_position); auto plain = buffer.slice(buffer_position, buffer.size() - buffer_position);
ByteBuffer decrypted; ByteBuffer decrypted;
if (m_context.cipher_spec_set && type != MessageType::ChangeCipher) { if (m_context.cipher_spec_set && type != MessageType::ChangeCipher) {
#ifdef TLS_DEBUG if constexpr (debug_tls) {
dbgln("Encrypted: "); dbgln("Encrypted: ");
print_buffer(buffer.slice(header_size, length)); print_buffer(buffer.slice(header_size, length));
#endif }
if (is_aead()) { if (is_aead()) {
ASSERT(m_aes_remote.gcm); ASSERT(m_aes_remote.gcm);
@ -396,9 +389,7 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer)
auto packet = build_alert(true, (u8)AlertDescription::UnexpectedMessage); auto packet = build_alert(true, (u8)AlertDescription::UnexpectedMessage);
write_packet(packet); write_packet(packet);
} else { } else {
#ifdef TLS_DEBUG dbgln<debug_tls>("application data message of size {}", plain.size());
dbg() << "application data message of size " << plain.size();
#endif
m_context.application_buffer.append(plain.data(), plain.size()); m_context.application_buffer.append(plain.data(), plain.size());
} }
@ -423,13 +414,11 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer)
} }
break; break;
case MessageType::Alert: case MessageType::Alert:
#ifdef TLS_DEBUG dbgln<debug_tls>("alert message of length {}", length);
dbg() << "alert message of length " << length;
#endif
if (length >= 2) { if (length >= 2) {
#ifdef TLS_DEBUG if constexpr (debug_tls)
print_buffer(plain); print_buffer(plain);
#endif
auto level = plain[0]; auto level = plain[0];
auto code = plain[1]; auto code = plain[1];
if (level == (u8)AlertLevel::Critical) { if (level == (u8)AlertLevel::Critical) {
@ -438,7 +427,7 @@ ssize_t TLSv12::handle_message(ReadonlyBytes buffer)
try_disambiguate_error(); try_disambiguate_error();
res = (i8)Error::UnknownError; res = (i8)Error::UnknownError;
} else { } else {
dbg() << "Alert: " << code; dbgln("Alert: {}", code);
} }
if (code == 0) { if (code == 0) {
// close notify // close notify

View file

@ -24,6 +24,7 @@
* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/ */
#include <AK/Debug.h>
#include <LibCore/DateTime.h> #include <LibCore/DateTime.h>
#include <LibCore/Timer.h> #include <LibCore/Timer.h>
#include <LibCrypto/ASN1/DER.h> #include <LibCrypto/ASN1/DER.h>
@ -173,9 +174,8 @@ void TLSv12::read_from_socket()
void TLSv12::write_into_socket() void TLSv12::write_into_socket()
{ {
#ifdef TLS_DEBUG dbgln<debug_tls>("Flushing cached records: {} established? {}", m_context.tls_buffer.size(), is_established());
dbg() << "Flushing cached records: " << m_context.tls_buffer.size() << " established? " << is_established();
#endif
m_has_scheduled_write_flush = false; m_has_scheduled_write_flush = false;
if (!check_connection_state(false)) if (!check_connection_state(false))
return; return;
@ -199,9 +199,8 @@ bool TLSv12::check_connection_state(bool read)
m_context.connection_finished = true; m_context.connection_finished = true;
} }
if (m_context.critical_error) { if (m_context.critical_error) {
#ifdef TLS_DEBUG dbgln<debug_tls>("CRITICAL ERROR {} :(", m_context.critical_error);
dbg() << "CRITICAL ERROR " << m_context.critical_error << " :(";
#endif
if (on_tls_error) if (on_tls_error)
on_tls_error((AlertDescription)m_context.critical_error); on_tls_error((AlertDescription)m_context.critical_error);
return false; return false;
@ -212,9 +211,9 @@ bool TLSv12::check_connection_state(bool read)
on_tls_finished(); on_tls_finished();
} }
if (m_context.tls_buffer.size()) { if (m_context.tls_buffer.size()) {
#ifdef TLS_DEBUG dbgln<debug_tls>("connection closed without finishing data transfer, {} bytes still in buffer and {} bytes in application buffer",
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"; m_context.tls_buffer.size(),
#endif m_context.application_buffer.size());
} else { } else {
m_context.connection_finished = false; m_context.connection_finished = false;
#ifdef TLS_DEBUG #ifdef TLS_DEBUG
@ -248,9 +247,7 @@ bool TLSv12::flush()
} }
if (m_context.send_retries++ == 10) { if (m_context.send_retries++ == 10) {
// drop the records, we can't send // drop the records, we can't send
#ifdef TLS_DEBUG dbgln<debug_tls>("Dropping {} bytes worth of TLS records as max retries has been reached", write_buffer().size());
dbg() << "Dropping " << write_buffer().size() << " bytes worth of TLS records as max retries has been reached";
#endif
write_buffer().clear(); write_buffer().clear();
m_context.send_retries = 0; m_context.send_retries = 0;
} }