1
Fork 0
mirror of https://github.com/RGBCube/serenity synced 2025-05-30 23:28:12 +00:00

LibTLS: Put lots of debug spam behind TLS_DEBUG

This commit is contained in:
Andreas Kling 2020-05-26 23:46:28 +02:00
parent b0eca4023f
commit 5049e41223
5 changed files with 47 additions and 3 deletions

View file

@ -87,8 +87,10 @@ ssize_t TLSv12::handle_hello(const ByteBuffer& buffer, WritePacketStage& write_p
if (session_length && session_length <= 32) { if (session_length && session_length <= 32) {
memcpy(m_context.session_id, buffer.offset_pointer(res), session_length); memcpy(m_context.session_id, buffer.offset_pointer(res), session_length);
m_context.session_id_size = session_length; m_context.session_id_size = session_length;
#ifdef TLS_DEBUG
dbg() << "Remote session ID:"; dbg() << "Remote session ID:";
print_buffer(ByteBuffer::wrap(m_context.session_id, session_length)); print_buffer(ByteBuffer::wrap(m_context.session_id, session_length));
#endif
} else { } else {
m_context.session_id_size = 0; m_context.session_id_size = 0;
} }
@ -106,7 +108,9 @@ ssize_t TLSv12::handle_hello(const ByteBuffer& buffer, WritePacketStage& write_p
return (i8)Error::NoCommonCipher; return (i8)Error::NoCommonCipher;
} }
m_context.cipher = cipher; m_context.cipher = cipher;
#ifdef TLS_DEBUG
dbg() << "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);
@ -140,7 +144,9 @@ ssize_t TLSv12::handle_hello(const ByteBuffer& buffer, WritePacketStage& write_p
u16 extension_length = convert_between_host_and_network(*(const u16*)buffer.offset_pointer(res)); u16 extension_length = convert_between_host_and_network(*(const u16*)buffer.offset_pointer(res));
res += 2; res += 2;
#ifdef TLS_DEBUG
dbg() << "extension " << (u16)extension_type << " with length " << 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) {
dbg() << "not enough data for extension"; dbg() << "not enough data for extension";
@ -212,17 +218,23 @@ ssize_t TLSv12::handle_finished(const ByteBuffer& buffer, WritePacketStage& writ
index += 3; index += 3;
if (size < 12) { if (size < 12) {
#ifdef TLS_DEBUG
dbg() << "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
dbg() << "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;
} }
// TODO: Compare Hashes // TODO: Compare Hashes
#ifdef TLS_DEBUG
dbg() << "FIXME: handle_finished :: Check message validity"; dbg() << "FIXME: handle_finished :: Check message validity";
#endif
m_context.connection_status = ConnectionStatus::Established; m_context.connection_status = ConnectionStatus::Established;
return handle_message(buffer); return handle_message(buffer);
@ -279,7 +291,9 @@ void TLSv12::build_random(PacketBuilder& builder)
ssize_t TLSv12::handle_payload(const ByteBuffer& vbuffer) ssize_t TLSv12::handle_payload(const ByteBuffer& vbuffer)
{ {
if (m_context.connection_status == ConnectionStatus::Established) { if (m_context.connection_status == ConnectionStatus::Established) {
#ifdef TLS_DEBUG
dbg() << "Renegotiation attempt ignored"; dbg() << "Renegotiation attempt ignored";
#endif
// FIXME: We should properly say "NoRenegotiation", but that causes a handshake failure // FIXME: We should properly say "NoRenegotiation", but that causes a handshake failure
// so we just roll with it and pretend that we _did_ renegotiate // so we just roll with it and pretend that we _did_ renegotiate
// This will cause issues when we decide to have long-lasting connections, but // This will cause issues when we decide to have long-lasting connections, but

View file

@ -199,7 +199,9 @@ ssize_t TLSv12::handle_message(const ByteBuffer& buffer)
buffer_position += 2; buffer_position += 2;
if (buffer_position + length > buffer.size()) { if (buffer_position + length > buffer.size()) {
#ifdef TLS_DEBUG
dbg() << "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;
} }

View file

@ -75,7 +75,9 @@ ByteBuffer TLSv12::read_line(size_t max_size)
bool TLSv12::write(const ByteBuffer& buffer) bool TLSv12::write(const ByteBuffer& buffer)
{ {
if (m_context.connection_status != ConnectionStatus::Established) { if (m_context.connection_status != ConnectionStatus::Established) {
#ifdef TLS_DEBUG
dbg() << "write request while not connected"; dbg() << "write request while not connected";
#endif
return false; return false;
} }
@ -165,11 +167,15 @@ bool TLSv12::check_connection_state(bool read)
{ {
if (!Core::Socket::is_open() || !Core::Socket::is_connected() || Core::Socket::eof()) { if (!Core::Socket::is_open() || !Core::Socket::is_connected() || Core::Socket::eof()) {
// an abrupt closure (the server is a jerk) // an abrupt closure (the server is a jerk)
#ifdef TLS_DEBUG
dbg() << "Socket not open, assuming abrupt closure"; dbg() << "Socket not open, assuming abrupt closure";
#endif
m_context.connection_finished = true; m_context.connection_finished = true;
} }
if (m_context.critical_error) { if (m_context.critical_error) {
#ifdef TLS_DEBUG
dbg() << "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;
@ -180,10 +186,14 @@ 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
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"; 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
} else { } else {
m_context.connection_finished = false; m_context.connection_finished = false;
#ifdef TLS_DEBUG
dbg() << "FINISHED"; dbg() << "FINISHED";
#endif
} }
if (!m_context.application_buffer.size()) { if (!m_context.application_buffer.size()) {
m_context.connection_status = ConnectionStatus::Disconnected; m_context.connection_status = ConnectionStatus::Disconnected;
@ -212,7 +222,9 @@ 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
dbg() << "Dropping " << write_buffer().size() << " bytes worth of TLS records as max retries has been reached"; 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;
} }

View file

@ -183,13 +183,17 @@ static ssize_t _parse_asn1(const Context& context, Certificate& cert, const u8*
size_t length = _get_asn1_length((const u8*)&buffer[position], size - position, octets); size_t length = _get_asn1_length((const u8*)&buffer[position], size - position, octets);
if (octets > 4 || octets > size - position) { if (octets > 4 || octets > size - position) {
#ifdef TLS_DEBUG
dbg() << "could not read the certificate"; dbg() << "could not read the certificate";
#endif
return position; return position;
} }
position += octets; position += octets;
if (size - position < length) { if (size - position < length) {
#ifdef TLS_DEBUG
dbg() << "not enough data for sequence"; dbg() << "not enough data for sequence";
#endif
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }
@ -368,7 +372,9 @@ static ssize_t _parse_asn1(const Context& context, Certificate& cert, const u8*
hash.initialize(Crypto::Hash::HashKind::SHA512); hash.initialize(Crypto::Hash::HashKind::SHA512);
break; break;
default: default:
#ifdef TLS_DEBUG
dbg() << "Unsupported hash mode " << (u32)cert.key_algorithm; dbg() << "Unsupported hash mode " << (u32)cert.key_algorithm;
#endif
// fallback to md5, it will fail later // fallback to md5, it will fail later
hash.initialize(Crypto::Hash::HashKind::MD5); hash.initialize(Crypto::Hash::HashKind::MD5);
break; break;
@ -410,13 +416,17 @@ ssize_t TLSv12::handle_certificate(const ByteBuffer& buffer)
ssize_t res = 0; ssize_t res = 0;
if (buffer.size() < 3) { if (buffer.size() < 3) {
#ifdef TLS_DEBUG
dbg() << "not enough certificate header data"; dbg() << "not enough certificate header data";
#endif
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }
u32 certificate_total_length = buffer[0] * 0x10000 + buffer[1] * 0x100 + buffer[2]; u32 certificate_total_length = buffer[0] * 0x10000 + buffer[1] * 0x100 + buffer[2];
#ifdef TLS_DEBUG
dbg() << "total length: " << certificate_total_length; dbg() << "total length: " << certificate_total_length;
#endif
if (certificate_total_length <= 4) if (certificate_total_length <= 4)
return 3 * certificate_total_length; return 3 * certificate_total_length;
@ -424,7 +434,9 @@ ssize_t TLSv12::handle_certificate(const ByteBuffer& buffer)
res += 3; res += 3;
if (certificate_total_length > buffer.size() - res) { if (certificate_total_length > buffer.size() - res) {
#ifdef TLS_DEBUG
dbg() << "not enough data for claimed total cert length"; dbg() << "not enough data for claimed total cert length";
#endif
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }
size_t size = certificate_total_length; size_t size = certificate_total_length;
@ -435,14 +447,18 @@ ssize_t TLSv12::handle_certificate(const ByteBuffer& buffer)
while (size > 0) { while (size > 0) {
++index; ++index;
if (buffer.size() - res < 3) { if (buffer.size() - res < 3) {
#ifdef TLS_DEBUG
dbg() << "not enough data for certificate length"; dbg() << "not enough data for certificate length";
#endif
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }
size_t certificate_size = buffer[res] * 0x10000 + buffer[res + 1] * 0x100 + buffer[res + 2]; size_t certificate_size = buffer[res] * 0x10000 + buffer[res + 1] * 0x100 + buffer[res + 2];
res += 3; res += 3;
if (buffer.size() - res < certificate_size) { if (buffer.size() - res < certificate_size) {
#ifdef TLS_DEBUG
dbg() << "not enough data for certificate body"; dbg() << "not enough data for certificate body";
#endif
return (i8)Error::NeedMoreData; return (i8)Error::NeedMoreData;
} }

View file

@ -40,14 +40,14 @@
namespace TLS { namespace TLS {
inline static void print_buffer(const ByteBuffer& buffer) inline void print_buffer(const ByteBuffer& buffer)
{ {
for (size_t i { 0 }; i < buffer.size(); ++i) for (size_t i { 0 }; i < buffer.size(); ++i)
dbgprintf("%02x ", buffer[i]); dbgprintf("%02x ", buffer[i]);
dbgprintf("\n"); dbgprintf("\n");
} }
inline static void print_buffer(const u8* buffer, size_t size) inline void print_buffer(const u8* buffer, size_t size)
{ {
for (size_t i { 0 }; i < size; ++i) for (size_t i { 0 }; i < size; ++i)
dbgprintf("%02x ", buffer[i]); dbgprintf("%02x ", buffer[i]);