Archives
/
lokinet
mirror of https://github.com/oxen-io/lokinet
2
0
Fork 0
Code Issues Projects Releases Wiki Activity

Migrate plainquic logging to llarp logging

Browse Source
pull/1576/head
Jason Rhinelander 3 years ago committed by Jeff Becker
parent 5d897781ef
commit 818b4042e9
No known key found for this signature in database
GPG Key ID: F357B3B42F6F9B05
12 changed files with 199 additions and 404 deletions
Show Stats Download Patch File Download Diff File

15
llarp/quic/client.cpp
Unescape Escape View File

@ -1,6 +1,7 @@
#include "client.hpp"
#include "log.hpp"
#include <llarp/util/logging/buffer.hpp>
#include <llarp/util/logging/logger.hpp>
#include <oxenmq/variant.h>
@ -15,7 +16,7 @@ namespace llarp::quic
{
// Our UDP socket is now set up, so now we initiate contact with the remote QUIC
Path path{local, remote};
Debug("Connecting to ", remote);
llarp::LogDebug("Connecting to ", remote);
if (tunnel_port == 0)
throw std::logic_error{"Cannot tunnel to port 0"};
@ -74,24 +75,24 @@ namespace llarp::quic
void
Client::handle_packet(const Packet& p)
{
Debug("Handling incoming client packet: ", buffer_printer{p.data});
llarp::LogDebug("Handling incoming client packet: ", buffer_printer{p.data});
auto maybe_dcid = handle_packet_init(p);
if (!maybe_dcid)
return;
auto& dcid = *maybe_dcid;
Debug("Incoming connection id ", dcid);
llarp::LogDebug("Incoming connection id ", dcid);
auto [connptr, alias] = get_conn(dcid);
if (!connptr)
{
Debug("CID is ", alias ? "expired alias" : "unknown/expired", "; dropping");
llarp::LogDebug("CID is ", alias ? "expired alias" : "unknown/expired", "; dropping");
return;
}
auto& conn = *connptr;
if (alias)
Debug("CID is alias for primary CID ", conn.base_cid);
llarp::LogDebug("CID is alias for primary CID ", conn.base_cid);
else
Debug("CID is primary CID");
llarp::LogDebug("CID is primary CID");
handle_conn_packet(conn, p);
}

188
llarp/quic/connection.cpp
Unescape Escape View File

@ -1,7 +1,8 @@
#include "connection.hpp"
#include "client.hpp"
#include "log.hpp"
#include "server.hpp"
#include <llarp/util/logging/logger.hpp>
#include <llarp/util/logging/buffer.hpp>
#include <cassert>
#include <charconv>
@ -52,7 +53,7 @@ namespace llarp::quic
int
client_initial(ngtcp2_conn* conn_, void* user_data)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
// Initialization the connection and send our transport parameters to the server. This will
// put the connection into NGTCP2_CS_CLIENT_WAIT_HANDSHAKE state.
@ -61,7 +62,7 @@ namespace llarp::quic
int
recv_client_initial(ngtcp2_conn* conn_, const ngtcp2_cid* dcid, void* user_data)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
// New incoming connection from a client: our server connection starts out here in state
// NGTCP2_CS_SERVER_INITIAL, but we should immediately get into recv_crypto_data because the
@ -85,14 +86,14 @@ namespace llarp::quic
void* user_data)
{
std::basic_string_view data{rawdata, rawdatalen};
Debug("\e[32;1mReceiving crypto data @ level ", crypto_level, "\e[0m ", buffer_printer{data});
LogTrace("Receiving crypto data @ level ", crypto_level, " ", buffer_printer{data});
auto& conn = *static_cast<Connection*>(user_data);
switch (crypto_level)
{
case NGTCP2_CRYPTO_LEVEL_EARLY:
// We don't currently use or support 0rtt
Warn("Invalid EARLY crypto level");
LogWarn("Invalid EARLY crypto level");
return FAIL;
case NGTCP2_CRYPTO_LEVEL_INITIAL:
@ -131,7 +132,7 @@ namespace llarp::quic
// Check that we received the above as expected
if (data != handshake_magic)
{
Warn("Invalid handshake crypto frame from client: did not find expected magic");
LogWarn("Invalid handshake crypto frame from client: did not find expected magic");
return NGTCP2_ERR_CALLBACK_FAILURE;
}
}
@ -145,7 +146,7 @@ namespace llarp::quic
break;
default:
Warn("Unhandled crypto_level ", crypto_level);
LogWarn("Unhandled crypto_level ", crypto_level);
return FAIL;
}
conn.io_ready();
@ -163,8 +164,8 @@ namespace llarp::quic
const uint8_t* ad,
size_t adlen)
{
Debug("######################", __func__);
Debug("Lengths: ", plaintextlen, "+", noncelen, "+", adlen);
LogTrace("######################", __func__);
LogTrace("Lengths: ", plaintextlen, "+", noncelen, "+", adlen);
if (dest != plaintext)
std::memmove(dest, plaintext, plaintextlen);
return 0;
@ -181,8 +182,8 @@ namespace llarp::quic
const uint8_t* ad,
size_t adlen)
{
Debug("######################", __func__);
Debug("Lengths: ", ciphertextlen, "+", noncelen, "+", adlen);
LogTrace("######################", __func__);
LogTrace("Lengths: ", ciphertextlen, "+", noncelen, "+", adlen);
if (dest != ciphertext)
std::memmove(dest, ciphertext, ciphertextlen);
return 0;
@ -194,7 +195,7 @@ namespace llarp::quic
const ngtcp2_crypto_cipher_ctx* hp_ctx,
const uint8_t* sample)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
memset(dest, 0, NGTCP2_HP_MASKLEN);
return 0;
}
@ -209,7 +210,7 @@ namespace llarp::quic
void* user_data,
void* stream_user_data)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
return static_cast<Connection*>(user_data)->stream_receive(
{stream_id},
{reinterpret_cast<const std::byte*>(data), datalen},
@ -225,15 +226,15 @@ namespace llarp::quic
void* user_data,
void* stream_user_data)
{
Debug("######################", __func__);
Debug("Ack [", offset, ",", offset + datalen, ")");
LogTrace("######################", __func__);
LogTrace("Ack [", offset, ",", offset + datalen, ")");
return static_cast<Connection*>(user_data)->stream_ack({stream_id}, datalen);
}
int
stream_open(ngtcp2_conn* conn, int64_t stream_id, void* user_data)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
return static_cast<Connection*>(user_data)->stream_opened({stream_id});
}
int
@ -245,7 +246,7 @@ namespace llarp::quic
void* user_data,
void* stream_user_data)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
return static_cast<Connection*>(user_data)->stream_reset({stream_id}, app_error_code);
}
@ -253,8 +254,8 @@ namespace llarp::quic
int
recv_retry(ngtcp2_conn* conn, const ngtcp2_pkt_hd* hd, void* user_data)
{
Debug("######################", __func__);
Error("FIXME UNIMPLEMENTED ", __func__);
LogTrace("######################", __func__);
LogError("FIXME UNIMPLEMENTED ", __func__);
// FIXME
return 0;
}
@ -265,7 +266,7 @@ namespace llarp::quic
const ngtcp2_rand_ctx* rand_ctx,
[[maybe_unused]] ngtcp2_rand_usage usage)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
randombytes_buf(dest, destlen);
return 0;
}
@ -273,7 +274,7 @@ namespace llarp::quic
get_new_connection_id(
ngtcp2_conn* conn_, ngtcp2_cid* cid_, uint8_t* token, size_t cidlen, void* user_data)
{
Debug("######################", __func__);
LogTrace("######################", __func__);
auto& conn = *static_cast<Connection*>(user_data);
auto cid = conn.make_alias_id(cidlen);
@ -281,7 +282,7 @@ namespace llarp::quic
*cid_ = cid;
conn.endpoint.make_stateless_reset_token(cid, token);
Debug(
LogDebug(
"make stateless reset token ",
oxenmq::to_hex(token, token + NGTCP2_STATELESS_RESET_TOKENLEN));
@ -290,8 +291,8 @@ namespace llarp::quic
int
remove_connection_id(ngtcp2_conn* conn, const ngtcp2_cid* cid, void* user_data)
{
Debug("######################", __func__);
Error("FIXME UNIMPLEMENTED ", __func__);
LogTrace("######################", __func__);
LogError("FIXME UNIMPLEMENTED ", __func__);
// FIXME
return 0;
}
@ -312,26 +313,20 @@ namespace llarp::quic
// This is a no-op since we don't encrypt anything in the first place
return 0;
}
/*
int recv_new_token(ngtcp2_conn* conn, const ngtcp2_vec* token, void* user_data) {
Debug("######################", __func__);
Error("FIXME UNIMPLEMENTED ", __func__);
// FIXME
return 0;
}
*/
#pragma GCC diagnostic pop
} // namespace
#ifndef NDEBUG
extern "C" inline void
debug_logger([[maybe_unused]] void* user_data, const char* fmt, ...)
ngtcp_trace_logger([[maybe_unused]] void* user_data, const char* fmt, ...)
{
va_list ap;
va_start(ap, fmt);
vfprintf(stderr, fmt, ap);
if (char* msg; vasprintf(&msg, sizeof(ngtcp_debug_out), fmt, ap) >= 0) {
LogTraceExplicit("external/ngtcp2/*.c", 0, msg);
std::free(msg);
}
va_end(ap);
fprintf(stderr, "\n");
}
#endif
@ -344,7 +339,7 @@ namespace llarp::quic
if (!send_data.empty())
{
Debug("Sending packet: ", buffer_printer{send_data});
LogDebug("Sending packet: ", buffer_printer{send_data});
rv = endpoint.send_packet(path.remote, send_data, send_pkt_info.ecn);
if (rv.blocked())
{
@ -362,8 +357,8 @@ namespace llarp::quic
else if (!rv)
{
// FIXME: disconnect here?
Warn("packet send failed: ", rv.str());
Error("FIXME - should disconnect");
LogWarn("packet send failed: ", rv.str());
LogError("FIXME - should disconnect");
}
else if (wpoll_active)
{
@ -392,10 +387,10 @@ namespace llarp::quic
retransmit_timer = endpoint.loop->resource<uvw::TimerHandle>();
retransmit_timer->on<uvw::TimerEvent>([this](auto&, auto&) {
Debug("Retransmit timer fired!");
LogTrace("Retransmit timer fired!");
if (auto rv = ngtcp2_conn_handle_expiry(*this, get_timestamp()); rv != 0)
{
Warn("expiry handler invocation returned an error: ", ngtcp2_strerror(rv));
LogWarn("expiry handler invocation returned an error: ", ngtcp2_strerror(rv));
endpoint.close_connection(*this, ngtcp2_err_infer_quic_transport_error_code(rv), false);
}
else
@ -423,7 +418,7 @@ namespace llarp::quic
ngtcp2_settings_default(&settings);
#ifndef NDEBUG
settings.log_printf = debug_logger;
settings.log_printf = ngtcp_trace_logger;
#endif
settings.initial_ts = get_timestamp();
// FIXME: IPv6
@ -445,7 +440,7 @@ namespace llarp::quic
tparams.max_idle_timeout = std::chrono::nanoseconds(IDLE_TIMEOUT).count();
tparams.active_connection_id_limit = 8;
Debug("Done basic connection initialization");
LogDebug("Done basic connection initialization");
return result;
}
@ -458,7 +453,7 @@ namespace llarp::quic
cb.recv_client_initial = recv_client_initial;
Debug("header.type = ", +header.type);
LogDebug("header.type = ", header.type);
// ConnectionIDs are a little complicated:
// - when a client creates a new connection to us, it creates a random source connection ID
@ -484,7 +479,7 @@ namespace llarp::quic
tparams.original_dcid = header.dcid;
Debug("original_dcid is now set to ", ConnectionID(tparams.original_dcid));
LogDebug("original_dcid is now set to ", ConnectionID(tparams.original_dcid));
settings.token = header.token;
@ -493,7 +488,7 @@ namespace llarp::quic
tparams.stateless_reset_token_present = 1;
ngtcp2_conn* connptr;
Debug("server_new, path=", path);
LogDebug("server_new, path=", path);
if (auto rv = ngtcp2_conn_server_new(
&connptr,
&dest_cid,
@ -509,7 +504,7 @@ namespace llarp::quic
throw std::runtime_error{"Failed to initialize server connection: "s + ngtcp2_strerror(rv)};
conn.reset(connptr);
Debug("Created new server conn ", base_cid);
LogDebug("Created new server conn ", base_cid);
}
Connection::Connection(
@ -546,7 +541,7 @@ namespace llarp::quic
throw std::runtime_error{"Failed to initialize client connection: "s + ngtcp2_strerror(rv)};
conn.reset(connptr);
Debug("Created new client conn ", scid);
LogDebug("Created new client conn ", scid);
}
Connection::~Connection()
@ -566,9 +561,9 @@ namespace llarp::quic
void
Connection::on_io_ready()
{
Debug(__func__);
LogTrace(__func__);
flush_streams();
Debug("done ", __func__);
LogTrace("done ", __func__);
}
void
@ -586,9 +581,7 @@ namespace llarp::quic
if (!ts)
ts = get_timestamp();
Debug("send_buffer size = ", send_buffer.size());
Debug("datalen = ", datalen);
Debug("flags = ", flags);
LogTrace("send_buffer size=", send_buffer.size(), ", datalen=", datalen, ", flags=", flags);
nwrite = ngtcp2_conn_writev_stream(
conn.get(),
&path.path,
@ -606,7 +599,7 @@ namespace llarp::quic
auto send_packet = [&](auto nwrite) -> bool {
send_buffer_size = nwrite;
Debug("Sending ", send_buffer_size, "B packet");
LogDebug("Sending ", send_buffer_size, "B packet");
// FIXME: update remote addr? ecn?
auto sent = send();
@ -616,11 +609,11 @@ namespace llarp::quic
send_buffer_size = 0;
if (!sent)
{
Warn("I/O error while trying to send packet: ", sent.str());
LogWarn("I/O error while trying to send packet: ", sent.str());
// FIXME: disconnect?
return false;
}
Debug("packet away!");
LogDebug("packet away!");
return true;
};
@ -660,14 +653,14 @@ namespace llarp::quic
buf_sizes += '+';
buf_sizes += std::to_string(b.size());
}
Debug("Sending ", buf_sizes.empty() ? "no" : buf_sizes, " data for ", stream.id());
LogDebug("Sending ", buf_sizes.empty() ? "no" : buf_sizes, " data for ", stream.id());
}
#endif
uint32_t extra_flags = 0;
if (stream.is_closing && !stream.sent_fin)
{
Debug("Sending FIN");
LogDebug("Sending FIN");
extra_flags |= NGTCP2_WRITE_STREAM_FLAG_FIN;
stream.sent_fin = true;
}
@ -678,18 +671,18 @@ namespace llarp::quic
auto [nwrite, consumed] =
add_stream_data(stream.id(), vecs.data(), vecs.size(), extra_flags);
Debug(
LogDebug(
"add_stream_data for stream ", stream.id(), " returned [", nwrite, ",", consumed, "]");
if (nwrite > 0)
{
if (consumed >= 0)
{
Debug("consumed ", consumed, " bytes from stream ", stream.id());
LogDebug("consumed ", consumed, " bytes from stream ", stream.id());
stream.wrote(consumed);
}
Debug("Sending stream data packet");
LogDebug("Sending stream data packet");
if (!send_packet(nwrite))
return;
++stream_packets;
@ -700,14 +693,14 @@ namespace llarp::quic
switch (nwrite)
{
case 0:
Debug(
LogDebug(
"Done stream writing to ",
stream.id(),
" (either stream is congested or we have nothing else to send right now)");
assert(consumed <= 0);
break;
case NGTCP2_ERR_WRITE_MORE:
Debug(
LogDebug(
"consumed ", consumed, " bytes from stream ", stream.id(), " and have space left");
stream.wrote(consumed);
if (stream.unsent() > 0)
@ -718,14 +711,14 @@ namespace llarp::quic
}
break;
case NGTCP2_ERR_STREAM_DATA_BLOCKED:
Debug("cannot add to stream ", stream.id(), " right now: stream is blocked");
LogDebug("cannot add to stream ", stream.id(), " right now: stream is blocked");
break;
case NGTCP2_ERR_STREAM_SHUT_WR:
Debug("cannot write to ", stream.id(), ": stream is shut down");
LogDebug("cannot write to ", stream.id(), ": stream is shut down");
break;
default:
assert(consumed <= 0);
Warn("Error writing to stream ", stream.id(), ": ", ngtcp2_strerror(nwrite));
LogWarn("Error writing to stream ", stream.id(), ": ", ngtcp2_strerror(nwrite));
break;
}
it = strs.erase(it);
@ -737,28 +730,28 @@ namespace llarp::quic
for (;;)
{
auto [nwrite, consumed] = add_stream_data(StreamID{}, nullptr, 0);
Debug("add_stream_data for non-stream returned [", nwrite, ",", consumed, "]");
LogDebug("add_stream_data for non-stream returned [", nwrite, ",", consumed, "]");
assert(consumed <= 0);
if (nwrite == NGTCP2_ERR_WRITE_MORE)
{
Debug("Writing non-stream data, and have space left");
LogDebug("Writing non-stream data, and have space left");
continue;
}
if (nwrite < 0)
{
Warn("Error writing non-stream data: ", ngtcp2_strerror(nwrite));
LogWarn("Error writing non-stream data: ", ngtcp2_strerror(nwrite));
break;
}
if (nwrite == 0)
{
Debug("Nothing else to write for non-stream data for now (or we are congested)");
LogDebug("Nothing else to write for non-stream data for now (or we are congested)");
ngtcp2_conn_stat cstat;
ngtcp2_conn_get_conn_stat(*this, &cstat);
Debug("Current unacked bytes in flight: ", cstat.bytes_in_flight);
LogDebug("Current unacked bytes in flight: ", cstat.bytes_in_flight);
break;
}
Debug("Sending non-stream data packet");
LogDebug("Sending non-stream data packet");
if (!send_packet(nwrite))
return;
}
@ -770,7 +763,6 @@ namespace llarp::quic
Connection::schedule_retransmit()
{
auto expiry = std::chrono::nanoseconds{ngtcp2_conn_get_expiry(*this)};
Debug("SCHEDULE RETRANSMIT exp ", expiry.count());
if (expiry < 0ns)
{
retransmit_timer->repeat(0ms);
@ -778,7 +770,7 @@ namespace llarp::quic
}
auto expires_in = std::chrono::duration_cast<std::chrono::milliseconds>(
expiry - get_time().time_since_epoch());
Debug("Next retransmit in ", expires_in.count(), "ms");
LogDebug("Next retransmit in ", expires_in.count(), "ms");
if (expires_in < 1ms)
expires_in = 1ms;
retransmit_timer->repeat(expires_in);
@ -788,11 +780,11 @@ namespace llarp::quic
int
Connection::stream_opened(StreamID id)
{
Debug("New stream ", id);
LogDebug("New stream ", id);
auto* serv = server();
if (!serv)
{
Warn("We are a client, incoming streams are not accepted");
LogWarn("We are a client, incoming streams are not accepted");
return NGTCP2_ERR_CALLBACK_FAILURE;
}
@ -803,7 +795,7 @@ namespace llarp::quic
good = serv->stream_open_callback(*serv, *stream, tunnel_port);
if (!good)
{
Debug("stream_open_callback returned failure, dropping stream ", id);
LogDebug("stream_open_callback returned failure, dropping stream ", id);
ngtcp2_conn_shutdown_stream(*this, id.id, 1);
io_ready();
return NGTCP2_ERR_CALLBACK_FAILURE;
@ -811,7 +803,7 @@ namespace llarp::quic
[[maybe_unused]] auto [it, ins] = streams.emplace(id, std::move(stream));
assert(ins);
Debug("Created new incoming stream ", id);
LogDebug("Created new incoming stream ", id);
return 0;
}
@ -820,7 +812,7 @@ namespace llarp::quic
{
auto str = get_stream(id);
if (!str->data_callback)
Debug("Dropping incoming data on stream ", str->id(), ": stream has no data callback set");
LogDebug("Dropping incoming data on stream ", str->id(), ": stream has no data callback set");
else
{
bool good = false;
@ -831,7 +823,7 @@ namespace llarp::quic
}
catch (const std::exception& e)
{
Warn(
LogWarn(
"Stream ",
str->id(),
" data callback raised exception (",
@ -841,7 +833,7 @@ namespace llarp::quic
}
catch (...)
{
Warn(
LogWarn(
"Stream ",
str->id(),
" data callback raised an unknown exception; closing stream with app code ",
@ -871,7 +863,7 @@ namespace llarp::quic
int
Connection::stream_reset(StreamID id, uint64_t app_code)
{
Debug(id, " reset with code ", app_code);
LogDebug(id, " reset with code ", app_code);
auto it = streams.find(id);
if (it == streams.end())
return NGTCP2_ERR_CALLBACK_FAILURE;
@ -880,7 +872,7 @@ namespace llarp::quic
stream.is_closing = true;
if (!was_closing && stream.close_callback)
{
Debug("Invoke stream close callback");
LogDebug("Invoke stream close callback");
stream.close_callback(stream, app_code);
}
@ -934,7 +926,7 @@ namespace llarp::quic
*this, std::move(data_cb), std::move(close_cb), endpoint.default_stream_buffer_size}};
if (int rv = ngtcp2_conn_open_bidi_stream(*this, &stream->stream_id.id, stream.get()); rv != 0)
{
Warn("Creating stream failed: ", ngtcp2_strerror(rv));
LogWarn("Creating stream failed: ", ngtcp2_strerror(rv));
throw std::runtime_error{"Stream creation failed: "s + ngtcp2_strerror(rv)};
}
@ -969,7 +961,7 @@ namespace llarp::quic
{
if (data.substr(0, handshake_magic.size()) != handshake_magic)
{
Warn("Invalid initial crypto frame: did not find expected magic prefix");
LogWarn("Invalid initial crypto frame: did not find expected magic prefix");
return NGTCP2_ERR_CALLBACK_FAILURE;
}
data.remove_prefix(handshake_magic.size());
@ -989,7 +981,7 @@ namespace llarp::quic
// in a second callback to handle them).
if (!data.empty())
{
Warn("Invalid initial crypto frame: unexpected post-magic data found");
LogWarn("Invalid initial crypto frame: unexpected post-magic data found");
return NGTCP2_ERR_CALLBACK_FAILURE;
}
}
@ -1075,20 +1067,20 @@ namespace llarp::quic
{
if (data.substr(0, lokinet_metadata_code.size()) != lokinet_metadata_code)
{
Warn("transport params did not begin with expected lokinet metadata");
LogWarn("transport params did not begin with expected lokinet metadata");
return NGTCP2_ERR_TRANSPORT_PARAM;
}
auto [meta_len, meta_len_bytes] = decode_varint(data.substr(lokinet_metadata_code.size()));
if (meta_len_bytes == 0)
{
Warn("transport params lokinet metadata has truncated size");
LogWarn("transport params lokinet metadata has truncated size");
return NGTCP2_ERR_MALFORMED_TRANSPORT_PARAM;
}
std::string_view lokinet_metadata{
reinterpret_cast<const char*>(
data.substr(lokinet_metadata_code.size() + meta_len_bytes).data()),
meta_len};
Debug("Received bencoded lokinet metadata: ", buffer_printer{lokinet_metadata});
LogDebug("Received bencoded lokinet metadata: ", buffer_printer{lokinet_metadata});
uint16_t port;
try
@ -1097,20 +1089,20 @@ namespace llarp::quic
// '#' contains the port the client wants us to forward to
if (!meta.skip_until("#"))
{
Warn("transport params # (port) is missing but required");
LogWarn("transport params # (port) is missing but required");
return NGTCP2_ERR_TRANSPORT_PARAM;
}
port = meta.consume_integer<uint16_t>();
if (port == 0)
{
Warn("transport params tunnel port (#) is invalid: 0 is not permitted");
LogWarn("transport params tunnel port (#) is invalid: 0 is not permitted");
return NGTCP2_ERR_TRANSPORT_PARAM;
}
Debug("decoded lokinet tunnel port = ", port);
LogDebug("decoded lokinet tunnel port = ", port);
}
catch (const oxenmq::bt_deserialize_invalid& c)
{
Warn("transport params lokinet metadata is invalid: ", c.what());
LogWarn("transport params lokinet metadata is invalid: ", c.what());
return NGTCP2_ERR_TRANSPORT_PARAM;
}
@ -1125,7 +1117,7 @@ namespace llarp::quic
// Make sure the server reflected the proper port
if (tunnel_port != port)
{
Warn("server returned invalid port; expected ", tunnel_port, ", got ", port);
LogWarn("server returned invalid port; expected ", tunnel_port, ", got ", port);
return NGTCP2_ERR_TRANSPORT_PARAM;
}
}
@ -1136,13 +1128,13 @@ namespace llarp::quic
: NGTCP2_TRANSPORT_PARAMS_TYPE_ENCRYPTED_EXTENSIONS;
auto rv = ngtcp2_decode_transport_params(&params, exttype, data.data(), data.size());
Debug("Decode transport params ", rv == 0 ? "success" : "fail: "s + ngtcp2_strerror(rv));
Debug("params orig dcid = ", ConnectionID(params.original_dcid));
Debug("params init scid = ", ConnectionID(params.initial_scid));
LogDebug("Decode transport params ", rv == 0 ? "success" : "fail: "s + ngtcp2_strerror(rv));
LogTrace("params orig dcid = ", ConnectionID(params.original_dcid));
LogTrace("params init scid = ", ConnectionID(params.initial_scid));
if (rv == 0)
{
rv = ngtcp2_conn_set_remote_transport_params(*this, &params);
Debug("Set remote transport params ", rv == 0 ? "success" : "fail: "s + ngtcp2_strerror(rv));
LogDebug("Set remote transport params ", rv == 0 ? "success" : "fail: "s + ngtcp2_strerror(rv));
}
if (rv != 0)
@ -1216,7 +1208,7 @@ namespace llarp::quic
conn_buffer.clear();
return nwrite;
}
Debug("encoded transport params: ", buffer_printer{conn_buffer});
LogDebug("encoded transport params: ", buffer_printer{conn_buffer});
return ngtcp2_conn_submit_crypto_data(*this, level, u8data(conn_buffer), conn_buffer.size());
}

64
llarp/quic/endpoint.cpp
Unescape Escape View File

@ -1,8 +1,8 @@
#include "endpoint.hpp"
#include "client.hpp"
#include "log.hpp"
#include "server.hpp"
#include <llarp/crypto/crypto.hpp>
#include <llarp/util/logging/buffer.hpp>
#include <iostream>
#include <random>
@ -47,7 +47,7 @@ namespace llarp::quic
getsockname(fd, &sa.sa, &salen);
assert(salen == sizeof(sockaddr_in)); // FIXME: IPv4-only for now
local = {&sa, salen};
Debug("Bound to ", local, addr ? "" : " (auto-selected)");
LogDebug("Bound to ", local, addr ? "" : " (auto-selected)");
// Set up the socket to provide us with incoming ECN (IP_TOS) info
// NB: This is for IPv4; on AF_INET6 this would be IPPROTO_IPV6, IPV6_RECVTCLASS
@ -87,7 +87,7 @@ namespace llarp::quic
expiry_timer->on<uvw::TimerEvent>([this](const auto&, auto&) { check_timeouts(); });
expiry_timer->start(250ms, 250ms);
Debug("Created endpoint");
LogDebug("Created endpoint");
}
Endpoint::~Endpoint()
@ -107,7 +107,7 @@ namespace llarp::quic
void
Endpoint::on_readable()
{
Debug("poll callback on readable");
LogDebug("poll callback on readable");
#ifdef LOKINET_HAVE_RECVMMSG
// NB: recvmmsg is linux-specific but ought to offer some performance benefits
@ -115,11 +115,11 @@ namespace llarp::quic
if (n_msg == -1)
{
if (errno != EAGAIN && errno != ENOTCONN)
Warn("Error recv'ing from ", local.to_string(), ": ", strerror(errno));
LogWarn("Error recv'ing from ", local.to_string(), ": ", strerror(errno));
return;
}
Debug("Recv'd ", n_msg, " messages");
LogDebug("Recv'd ", n_msg, " messages");
for (int i = 0; i < n_msg; i++)
{
auto& [msg_hdr, msg_len] = msgs[i];
@ -130,14 +130,14 @@ namespace llarp::quic
auto& msg_hdr = msgs[0];
auto n_bytes = recvmsg(socket_fd(), &msg_hdr, 0);
if (n_bytes == -1 && errno != EAGAIN && errno != ENOTCONN)
Warn("Error recv'ing from ", local.to_string(), ": ", strerror(errno));
LogWarn("Error recv'ing from ", local.to_string(), ": ", strerror(errno));
if (n_bytes <= 0)
return;
auto msg_len = static_cast<unsigned int>(n_bytes);
bstring_view data{buf.data(), msg_len};
#endif
Debug(
LogDebug(
"header [",
msg_hdr.msg_namelen,
"]: ",
@ -145,7 +145,7 @@ namespace llarp::quic
if (!msg_hdr.msg_name || msg_hdr.msg_namelen != sizeof(sockaddr_in))
{ // FIXME: IPv6 support?
Warn("Invalid/unknown source address, dropping packet");
LogWarn("Invalid/unknown source address, dropping packet");
continue;
}
@ -164,7 +164,7 @@ namespace llarp::quic
}
}
Debug(
LogDebug(
i,
"[",
pkt.path,
@ -178,7 +178,7 @@ namespace llarp::quic
handle_packet(pkt);
Debug("Done handling packet");
LogDebug("Done handling packet");
#ifdef LOKINET_HAVE_RECVMMSG // Help editor's { } matching:
}
@ -205,15 +205,15 @@ namespace llarp::quic
send_version_negotiation(vi, p.path.remote);
return std::nullopt;
}
else if (rv != 0)
if (rv != 0)
{
Warn("QUIC packet header decode failed: ", ngtcp2_strerror(rv));
LogWarn("QUIC packet header decode failed: ", ngtcp2_strerror(rv));
return std::nullopt;
}
if (vi.dcid_len > ConnectionID::max_size())
{
Warn("Internal error: destination ID is longer than should be allowed");
LogWarn("Internal error: destination ID is longer than should be allowed");
return std::nullopt;
}
@ -224,13 +224,13 @@ namespace llarp::quic
{
if (ngtcp2_conn_is_in_closing_period(conn))
{
Debug("Connection is in closing period, dropping");
LogDebug("Connection is in closing period, dropping");
close_connection(conn);
return;
}
if (conn.draining)
{
Debug("Connection is draining, dropping");
LogDebug("Connection is draining, dropping");
// "draining" state means we received a connection close and we're keeping the
// connection alive just to catch (and discard) straggling packets that arrive
// out of order w.r.t to connection close.
@ -239,24 +239,24 @@ namespace llarp::quic
if (auto result = read_packet(p, conn); !result)
{
Warn("Read packet failed! ", ngtcp2_strerror(result.error_code));
LogWarn("Read packet failed! ", ngtcp2_strerror(result.error_code));
}
// FIXME - reset idle timer?
Debug("Done with incoming packet");
LogDebug("Done with incoming packet");
}
io_result
Endpoint::read_packet(const Packet& p, Connection& conn)
{
Debug("Reading packet from ", p.path);
LogDebug("Reading packet from ", p.path);
auto rv =
ngtcp2_conn_read_pkt(conn, p.path, &p.info, u8data(p.data), p.data.size(), get_timestamp());
if (rv == 0)
conn.io_ready();
else
Warn("read pkt error: ", ngtcp2_strerror(rv));
LogWarn("read pkt error: ", ngtcp2_strerror(rv));
if (rv == NGTCP2_ERR_DRAINING)
start_draining(conn);
@ -274,7 +274,7 @@ namespace llarp::quic
{
if (-1
== setsockopt(socket_fd(), IPPROTO_IP, IP_TOS, &ecn, static_cast<socklen_t>(sizeof(ecn))))
Warn("setsockopt failed to set IP_TOS: ", strerror(errno));
LogWarn("setsockopt failed to set IP_TOS: ", strerror(errno));
// IPv6 version:
// int tclass = this->ecn;
@ -309,11 +309,11 @@ namespace llarp::quic
if (nwrite == -1)
{
Warn("sendmsg failed: ", strerror(errno));
LogWarn("sendmsg failed: ", strerror(errno));
return {errno};
}
Debug(
LogDebug(
"[",
to.to_string(),
",ecn=0x",
@ -347,7 +347,7 @@ namespace llarp::quic
versions.data(),
versions.size());
if (nwrote < 0)
Warn("Failed to construct version negotiation packet: ", ngtcp2_strerror(nwrote));
LogWarn("Failed to construct version negotiation packet: ", ngtcp2_strerror(nwrote));
if (nwrote <= 0)
return;
@ -357,7 +357,7 @@ namespace llarp::quic
void
Endpoint::close_connection(Connection& conn, uint64_t code, bool application)
{
Debug("Closing connection ", conn.base_cid);
LogDebug("Closing connection ", conn.base_cid);
if (!conn.closing)
{
conn.conn_buffer.resize(max_pkt_size_v4);
@ -376,7 +376,7 @@ namespace llarp::quic
get_timestamp());
if (written <= 0)
{
Warn(
LogWarn(
"Failed to write connection close packet: ",
written < 0 ? ngtcp2_strerror(written) : "unknown error: closing is 0 bytes??");
return;
@ -395,7 +395,7 @@ namespace llarp::quic
if (auto sent = send_packet(conn.path.remote, conn.conn_buffer, 0); !sent)
{
Warn(
LogWarn(
"Failed to send packet: ",
strerror(sent.error_code),
"; removing connection ",
@ -413,7 +413,7 @@ namespace llarp::quic
{
if (conn.draining)
return;
Debug("Putting ", conn.base_cid, " into draining mode");
LogDebug("Putting ", conn.base_cid, " into draining mode");
conn.draining = true;
// Recommended draining time is 3*Probe Timeout
draining.emplace(conn.base_cid, get_time() + ngtcp2_conn_get_pto(conn) * 3 * 1ns);
@ -433,7 +433,7 @@ namespace llarp::quic
{
if (std::holds_alternative<primary_conn_ptr>(it->second))
cleanup = true;
Debug("Deleting connection ", it->first);
LogDebug("Deleting connection ", it->first);
conns.erase(it);
}
draining.pop();
@ -472,12 +472,12 @@ namespace llarp::quic
auto it = conns.find(cid);
if (it == conns.end())
{
Debug("Cannot delete connection ", cid, ": cid not found");
LogDebug("Cannot delete connection ", cid, ": cid not found");
return false;
}
bool primary = std::holds_alternative<primary_conn_ptr>(it->second);
Debug("Deleting ", primary ? "primary" : "alias", " connection ", cid);
LogDebug("Deleting ", primary ? "primary" : "alias", " connection ", cid);
conns.erase(it);
if (primary)
clean_alias_conns();
@ -506,7 +506,7 @@ namespace llarp::quic
cid = ConnectionID::random(cid_length);
inserted = conns.emplace(cid, conn.weak_from_this()).second;
}
Debug("Created cid ", cid, " alias for ", conn.base_cid);
LogDebug("Created cid ", cid, " alias for ", conn.base_cid);
return cid;
}

45
llarp/quic/log.cpp
Unescape Escape View File

@ -1,45 +0,0 @@
#include "log.hpp"
namespace llarp::quic
{
std::ostream&
operator<<(std::ostream& o, const buffer_printer& bp)
{
auto& b = bp.buf;
auto oldfill = o.fill();
o.fill('0');
o << "Buffer[" << b.size() << "/0x" << std::hex << b.size() << " bytes]:";
for (size_t i = 0; i < b.size(); i += 32)
{
o << "\n" << std::setw(4) << i << " ";
size_t stop = std::min(b.size(), i + 32);
for (size_t j = 0; j < 32; j++)
{
auto k = i + j;
if (j % 4 == 0)
o << ' ';
if (k >= stop)
o << " ";
else
o << std::setw(2) << std::to_integer<uint_fast16_t>(b[k]);
}
o << u8" ┃";
for (size_t j = i; j < stop; j++)
{
auto c = std::to_integer<char>(b[j]);
if (c == 0x00)
o << u8"∅";
else if (c < 0x20 || c > 0x7e)
o << u8"·";
else
o << c;
}
o << u8"┃";
}
o << std::dec;
o.fill(oldfill);
return o;
}
} // namespace llarp::quic

146
llarp/quic/log.hpp
Unescape Escape View File

@ -1,146 +0,0 @@
#pragma once
#include <cstdarg>
#include <cstddef>
#include <iostream>
#include <iomanip>
#include <type_traits>
// Temporary logging code to be replaced with lokinet logging
#include <oxenmq/hex.h>
#ifdef __cpp_lib_source_location
#include <source_location>
namespace slns = std;
#else
#include <experimental/source_location>
namespace slns = std::experimental;
#endif
namespace llarp::quic
{
struct buffer_printer
{
std::basic_string_view<std::byte> buf;
template <typename T, typename = std::enable_if_t<sizeof(T) == 1>>
explicit buffer_printer(std::basic_string_view<T> buf)
: buf{reinterpret_cast<const std::byte*>(buf.data()), buf.size()}
{}
template <typename T, typename = std::enable_if_t<sizeof(T) == 1>>
explicit buffer_printer(const std::basic_string<T>& buf)
: buffer_printer(std::basic_string_view<T>{buf})
{}
template <typename T, typename = std::enable_if_t<sizeof(T) == 1>>
explicit buffer_printer(std::basic_string<T>&& buf) = delete;
template <typename T, typename = std::enable_if_t<sizeof(T) == 1>>
explicit buffer_printer(const T* data, size_t size)
: buffer_printer(std::basic_string_view<T>{data, size})
{}
};
std::ostream&
operator<<(std::ostream& o, const buffer_printer& bp);
namespace detail
{
template <typename T, typename... V>
constexpr bool is_same_any_v = (std::is_same_v<T, V> || ...);
template <typename T, typename... More>
void
log_print_vals(T&& val, More&&... more)
{
using PlainT = std::remove_reference_t<T>;
if constexpr (is_same_any_v<PlainT, char, unsigned char, signed char, uint8_t, std::byte>)
std::cerr
<< +val; // Promote chars to int so that they get printed as numbers, not literal chars
else
std::cerr << val;
if constexpr (sizeof...(More))
log_print_vals(std::forward<More>(more)...);
}
template <typename... T>
void
log_print(const slns::source_location& location, T&&... args)
{
std::string_view filename{location.file_name()};
if (auto pos = filename.rfind('/'); pos != std::string::npos
&& (pos = filename.substr(0, pos).rfind('/')) != std::string::npos)
{
filename.remove_prefix(pos + 1);
}
std::cerr << "\e[3m[" << filename << ':' << location.line() << "]\e[23m";
if constexpr (sizeof...(T))
{
std::cerr << ": ";
detail::log_print_vals(std::forward<T>(args)...);
}
std::cerr << '\n';
}
} // namespace detail
#ifndef NDEBUG
template <typename... T>
struct Debug
{
Debug(T&&... args, const slns::source_location& location = slns::source_location::current())
{
std::cerr << "DBG";
detail::log_print(location, std::forward<T>(args)...);
}
};
template <typename... T>
Debug(T&&...) -> Debug<T...>;
#else
template <typename... T>
void
Debug(T&&...)
{}
#endif
template <typename... T>
struct Info
{
Info(T&&... args, const slns::source_location& location = slns::source_location::current())
{
std::cerr << "\e[32mNFO";
detail::log_print(location, std::forward<T>(args)...);
std::cerr << "\e[0m";
}
};
template <typename... T>
Info(T&&...) -> Info<T...>;
template <typename... T>
struct Warn
{
Warn(T&&... args, const slns::source_location& location = slns::source_location::current())
{
std::cerr << "\e[33;1mWRN";
detail::log_print(location, std::forward<T>(args)...);
std::cerr << "\e[0m";
}
};
template <typename... T>
Warn(T&&...) -> Warn<T...>;
template <typename... T>
struct Error
{
Error(T&&... args, const slns::source_location& location = slns::source_location::current())
{
std::cerr << "\e[31;1mWRN";
detail::log_print(location, std::forward<T>(args)...);
std::cerr << "\e[0m";
}
};
template <typename... T>
Error(T&&...) -> Error<T...>;
} // namespace llarp::quic

4
llarp/quic/null_crypto.cpp
Unescape Escape View File

@ -1,5 +1,5 @@
#include "null_crypto.hpp"
#include "log.hpp"
#include <llarp/util/logging/logger.hpp>
#include <limits>
@ -41,7 +41,7 @@ namespace llarp::quic
void
NullCrypto::server_initial(Connection& conn)
{
Debug("Server initial null crypto setup");
LogDebug("Server initial null crypto setup");
ngtcp2_conn_set_initial_crypto_ctx(conn, &null_ctx);
ngtcp2_conn_install_initial_key(
conn,

36
llarp/quic/server.cpp
Unescape Escape View File

@ -1,5 +1,6 @@
#include "server.hpp"
#include "log.hpp"
#include <llarp/util/logging/buffer.hpp>
#include <llarp/util/logging/logger.hpp>
#include <oxenmq/hex.h>
#include <oxenmq/variant.h>
@ -19,14 +20,14 @@ namespace llarp::quic
void
Server::handle_packet(const Packet& p)
{
Debug("Handling incoming server packet: ", buffer_printer{p.data});
LogDebug("Handling incoming server packet: ", buffer_printer{p.data});
auto maybe_dcid = handle_packet_init(p);
if (!maybe_dcid)
return;
auto& dcid = *maybe_dcid;
// See if we have an existing connection already established for it
Debug("Incoming connection id ", dcid);
LogDebug("Incoming connection id ", dcid);
primary_conn_ptr connptr;
if (auto conn_it = conns.find(dcid); conn_it != conns.end())
{
@ -34,14 +35,14 @@ namespace llarp::quic
{
connptr = wptr->lock();
if (!connptr)
Debug("CID is an expired alias");
LogDebug("CID is an expired alias");
else
Debug("CID is an alias for primary CID ", connptr->base_cid);
LogDebug("CID is an alias for primary CID ", connptr->base_cid);
}
else
{
connptr = var::get<primary_conn_ptr>(conn_it->second);
Debug("CID is primary");
LogDebug("CID is primary");
}
}
else
@ -51,7 +52,7 @@ namespace llarp::quic
if (!connptr)
{
Warn("invalid or expired connection, ignoring");
LogWarn("invalid or expired connection, ignoring");
return;
}
@ -61,25 +62,21 @@ namespace llarp::quic
std::shared_ptr<Connection>
Server::accept_connection(const Packet& p)
{
Debug("Accepting new connection");
LogDebug("Accepting new connection");
// This is a new incoming connection
ngtcp2_pkt_hd hd;
auto rv = ngtcp2_accept(&hd, u8data(p.data), p.data.size());
if (rv == -1)
{ // Invalid packet
Warn("Invalid packet received, length=", p.data.size());
#ifndef NDEBUG
Debug("packet body:");
for (size_t i = 0; i < p.data.size(); i += 50)
Debug(" ", oxenmq::to_hex(p.data.substr(i, 50)));
#endif
LogWarn("Invalid packet received, length=", p.data.size());
LogTrace("packet body: ", buffer_printer{p.data});
return nullptr;
}
if (rv == 1)
{ // Invalid/unexpected version, send a version negotiation
Debug("Invalid/unsupported version; sending version negotiation");
LogDebug("Invalid/unsupported version; sending version negotiation");
send_version_negotiation(
version_info{hd.version, hd.dcid.data, hd.dcid.datalen, hd.scid.data, hd.scid.datalen},
p.path.remote);
@ -92,13 +89,14 @@ namespace llarp::quic
*/
if (hd.type == NGTCP2_PKT_0RTT)
{
Warn("Received 0-RTT packet, which shouldn't happen in our implementation; dropping");
LogWarn("Received 0-RTT packet, which shouldn't happen in our implementation; dropping");
return nullptr;
}
else if (hd.type == NGTCP2_PKT_INITIAL && hd.token.len)
if (hd.type == NGTCP2_PKT_INITIAL && hd.token.len)
{
// This is a normal QUIC thing, but we don't do it:
Warn("Unexpected token in initial packet");
LogWarn("Unexpected token in initial packet");
}
// create and store Connection
@ -108,7 +106,7 @@ namespace llarp::quic
{
auto connptr = std::make_shared<Connection>(*this, it->first, hd, p.path);
it->second = connptr;
Debug("Created local Connection ", it->first, " for incoming connection");
LogDebug("Created local Connection ", it->first, " for incoming connection");
return connptr;
}
}

18
llarp/quic/stream.cpp
Unescape Escape View File

@ -1,7 +1,7 @@
#include "stream.hpp"
#include "connection.hpp"
#include "endpoint.hpp"
#include "log.hpp"
#include <llarp/util/logging/logger.hpp>
#include <cassert>
#include <iostream>
@ -110,7 +110,7 @@ namespace llarp::quic
auto data_split = data.begin() + (buffer.size() - wpos);
std::copy(data.begin(), data_split, buffer.begin() + wpos);
std::copy(data_split, data.end(), buffer.begin());
Debug(
LogTrace(
"Wrote ",
data.size(),
" bytes to buffer ranges [",
@ -125,10 +125,10 @@ namespace llarp::quic
{
// No wrap needs, it fits before the end:
std::copy(data.begin(), data.end(), buffer.begin() + wpos);
Debug("Wrote ", data.size(), " bytes to buffer range [", wpos, ",", wpos + data.size(), ")");
LogTrace("Wrote ", data.size(), " bytes to buffer range [", wpos, ",", wpos + data.size(), ")");
}
size += data.size();
Debug("New stream buffer: ", size, "/", buffer.size(), " bytes beginning at ", start);
LogTrace("New stream buffer: ", size, "/", buffer.size(), " bytes beginning at ", start);
conn.io_ready();
return true;
}
@ -162,7 +162,7 @@ namespace llarp::quic
//
assert(bytes <= unacked_size && unacked_size <= size);
Debug("Acked ", bytes, " bytes of ", unacked_size, "/", size, " unacked/total");
LogDebug("Acked ", bytes, " bytes of ", unacked_size, "/", size, " unacked/total");
unacked_size -= bytes;
size -= bytes;
@ -290,7 +290,7 @@ namespace llarp::quic
// [ áaarrrrrr ] or [rr áaar]
// to:
// [ áaaaaarrr ] or [aa áaaa]
Debug("wrote ", bytes, ", unsent=", unsent());
LogDebug("wrote ", bytes, ", unsent=", unsent());
assert(bytes <= unsent());
unacked_size += bytes;
}
@ -298,20 +298,20 @@ namespace llarp::quic
void
Stream::close(std::optional<uint64_t> error_code)
{
Debug(
LogDebug(
"Closing ",
stream_id,
error_code ? " immediately with code " + std::to_string(*error_code) : " gracefully");
if (is_shutdown)
Debug("Stream is already shutting down");
LogDebug("Stream is already shutting down");
else if (error_code)
{
is_closing = is_shutdown = true;
ngtcp2_conn_shutdown_stream(conn, stream_id.id, *error_code);
}
else if (is_closing)
Debug("Stream is already closing");
LogDebug("Stream is already closing");
else
is_closing = true;

19
llarp/quic/tunnel.cpp
Unescape Escape View File

@ -1,6 +1,7 @@
#include "tunnel.hpp"
#include "log.hpp"
#include "stream.hpp"
#include <llarp/util/logging/buffer.hpp>
#include <llarp/util/logging/logger.hpp>
namespace llarp::quic::tunnel
{
@ -12,12 +13,12 @@ namespace llarp::quic::tunnel
assert(stream);
std::string_view data{event.data.get(), event.length};
auto peer = client.peer();
llarp::quic::Debug(peer.ip, ":", peer.port, " → lokinet ", llarp::quic::buffer_printer{data});
LogDebug(peer.ip, ":", peer.port, " → lokinet ", buffer_printer{data});
// Steal the buffer from the DataEvent's unique_ptr<char[]>:
stream->append_buffer(reinterpret_cast<const std::byte*>(event.data.release()), event.length);
if (stream->used() >= PAUSE_SIZE)
{
llarp::quic::Debug(
LogDebug(
"quic tunnel is congested (have ",
stream->used(),
" bytes in flight); pausing local tcp connection reads");
@ -26,7 +27,7 @@ namespace llarp::quic::tunnel
auto client = s.data<uvw::TCPHandle>();
if (s.used() < PAUSE_SIZE)
{
llarp::quic::Debug("quic tunnel is no longer congested; resuming tcp connection reading");
LogDebug("quic tunnel is no longer congested; resuming tcp connection reading");
client->read();
return true;
}
@ -35,7 +36,7 @@ namespace llarp::quic::tunnel
}
else
{
llarp::quic::Debug("Queued ", event.length, " bytes");
LogDebug("Queued ", event.length, " bytes");
}
}
@ -47,7 +48,7 @@ namespace llarp::quic::tunnel
assert(tcp);
std::string_view data{reinterpret_cast<const char*>(bdata.data()), bdata.size()};
auto peer = tcp->peer();
llarp::quic::Debug(peer.ip, ":", peer.port, " ← lokinet ", llarp::quic::buffer_printer{data});
LogTrace(peer.ip, ":", peer.port, " ← lokinet ", buffer_printer{data});
if (data.empty())
return;
@ -73,7 +74,7 @@ namespace llarp::quic::tunnel
tcp.on<uvw::CloseEvent>([](auto&, uvw::TCPHandle& c) {
// This fires sometime after we call `close()` to signal that the close is done.
llarp::quic::Error(
LogError(
"Connection with ",
c.peer().ip,
":",
@ -83,12 +84,12 @@ namespace llarp::quic::tunnel
});
tcp.on<uvw::EndEvent>([](auto&, uvw::TCPHandle& c) {
// This fires on eof, most likely because the other side of the TCP connection closed it.
llarp::quic::Error(
LogError(
"EOF on connection with ", c.peer().ip, ":", c.peer().port, ", closing quic stream");
c.data<llarp::quic::Stream>()->close();
});
tcp.on<uvw::ErrorEvent>([](const uvw::ErrorEvent& e, uvw::TCPHandle& tcp) {
llarp::quic::Error(
LogError(
"ErrorEvent[",
e.name(),
": ",

1
llarp/quic/tunnel.hpp
Unescape Escape View File

@ -1,7 +1,6 @@
#pragma once
#include "stream.hpp"
#include "log.hpp"
#include <charconv>
#include <cstdint>

26
llarp/quic/tunnel_client.cpp
Unescape Escape View File

@ -1,8 +1,10 @@
#include "connection.hpp"
#include "client.hpp"
#include "log.hpp"
#include "stream.hpp"
#include "tunnel.hpp"
#include <llarp/util/logging/logger.hpp>
#include <oxenmq/hex.h>
#include <util/str.hpp>
@ -22,7 +24,7 @@ namespace llarp::quic::tunnel
void
on_new_connection(const uvw::ListenEvent&, uvw::TCPHandle& server)
{
llarp::quic::Debug("New connection!\n");
LogDebug("New connection!\n");
auto client = server.loop().resource<uvw::TCPHandle>();
server.accept(*client);
@ -30,7 +32,7 @@ namespace llarp::quic::tunnel
std::shared_ptr<llarp::quic::Stream> stream;
try
{
llarp::quic::Debug("open stream");
LogTrace("open stream");
stream = conn->open_stream(
[client](llarp::quic::Stream& stream, llarp::quic::bstring_view bdata) {
if (bdata.empty())
@ -46,11 +48,11 @@ namespace llarp::quic::tunnel
bdata.remove_prefix(1);
stream.data_callback(stream, std::move(bdata));
}
llarp::quic::Debug("starting client reading");
LogTrace("starting client reading");
}
else
{
llarp::quic::Warn(
LogWarn(
"Remote connection returned invalid initial byte (0x",
oxenmq::to_hex(bdata.begin(), bdata.begin() + 1),
"); dropping connection");
@ -61,14 +63,14 @@ namespace llarp::quic::tunnel
},
[client](llarp::quic::Stream&, std::optional<uint64_t> error_code) mutable {
if (error_code && *error_code == tunnel::ERROR_CONNECT)
llarp::quic::Debug("Remote TCP connection failed, closing local connection");
LogDebug("Remote TCP connection failed, closing local connection");
else
llarp::quic::Warn(
LogWarn(
"Stream connection closed ",
error_code ? "with error " + std::to_string(*error_code) : "gracefully",
"; closing local TCP connection.");
auto peer = client->peer();
llarp::quic::Debug("Closing connection to ", peer.ip, ":", peer.port);
LogDebug("Closing connection to ", peer.ip, ":", peer.port);
if (error_code)
client->closeReset();
else
@ -78,12 +80,12 @@ namespace llarp::quic::tunnel
}
catch (const std::exception& e)
{
llarp::quic::Debug("open stream failed");
LogDebug("open stream failed");
client->closeReset();
return;
}
llarp::quic::Debug("setup stream");
LogTrace("done stream setup");
conn->io_ready();
}
@ -116,14 +118,14 @@ namespace llarp::quic::tunnel
signal(SIGPIPE, SIG_IGN);
llarp::quic::Debug("Initializing client");
LogDebug("Initializing client");
auto tunnel_client = std::make_shared<llarp::quic::Client>(
llarp::quic::Address{{127, 0, 0, 1}, server_port}, // server addr
loop,
dest_port // tunnel destination port
);
tunnel_client->default_stream_buffer_size = 0; // We steal uvw's provided buffers
llarp::quic::Debug("Initialized client");
LogDebug("Initialized client");
// Start listening for TCP connections:
auto server = loop->resource<uvw::TCPHandle>();

41
llarp/quic/tunnel_server.cpp
Unescape Escape View File

@ -2,7 +2,7 @@
#include "tunnel.hpp"
#include "connection.hpp"
#include "server.hpp"
#include "log.hpp"
#include <llarp/util/logging/logger.hpp>
#include <util/str.hpp>
@ -69,43 +69,36 @@ namespace llarp::quic::tunnel
// be the localhost.loki address for lokinet).
std::string localhost = "127.0.0.1";
llarp::quic::Debug("Initializing server");
LogInfo("Initializing QUIC server");
llarp::quic::Server s{
listen_addr,
loop,
[loop, localhost, allowed_ports](
llarp::quic::Server&, llarp::quic::Stream& stream, uint16_t port) {
llarp::quic::Debug(
"\e[33mNew incoming quic stream ",
LogDebug(
"New incoming quic stream ",
stream.id(),
" to reach ",
localhost,
":",
port,
"\e[0m");
port);
if (port == 0 || !(allowed_ports.empty() || allowed_ports.count(port)))
{
llarp::quic::Warn(
LogWarn(
"quic stream denied by configuration: ", port, " is not a permitted local port");
return false;
}
/*
stream.data_callback = [init_seen=false](llarp::quic::Stream& stream,
llarp::quic::bstring_view bdata) mutable { if (init_seen) { llarp::quic::Warn("Invalid
remote data: received multiple bytes before connection confirmation");
}
};
*/
stream.close_callback = [](llarp::quic::Stream& strm,
std::optional<uint64_t> error_code) {
llarp::quic::Debug(
LogDebug(
error_code ? "Remote side" : "We",
" closed the quic stream, closing localhost tcp connection");
if (error_code && *error_code > 0)
llarp::quic::Warn("Remote quic stream was closed with error code ", *error_code);
LogWarn("Remote quic stream was closed with error code ", *error_code);
auto tcp = strm.data<uvw::TCPHandle>();
if (!tcp)
llarp::quic::Debug("Local TCP connection already closed");
LogDebug("Local TCP connection already closed");
else
tcp->close();
};
@ -116,7 +109,7 @@ namespace llarp::quic::tunnel
auto tcp = loop->resource<uvw::TCPHandle>();
auto error_handler = tcp->once<uvw::ErrorEvent>(
[&stream, localhost, port](const uvw::ErrorEvent&, uvw::TCPHandle&) {
llarp::quic::Error(
LogWarn(
"Failed to connect to ", localhost, ":", port, ", shutting down quic stream");
stream.close(tunnel::ERROR_CONNECT);
});
@ -127,7 +120,7 @@ namespace llarp::quic::tunnel
auto stream = streamw.lock();
if (!stream)
{
llarp::quic::Warn(
LogWarn(
"Connected to ",
peer.ip,
":",
@ -136,14 +129,13 @@ namespace llarp::quic::tunnel
tcp.closeReset();
return;
}
llarp::quic::Debug(
"\e[32mConnected to ",
LogDebug(
"Connected to ",
peer.ip,
":",
peer.port,
" for quic ",
stream->id(),
"\e[0m");
stream->id());
tcp.erase(error_handler);
tunnel::install_stream_forwarding(tcp, *stream);
assert(stream->used() == 0);
@ -152,12 +144,13 @@ namespace llarp::quic::tunnel
tcp.read();
});
// FIXME, need to configure this
tcp->connect("127.0.0.1", port);
return true;
}};
s.default_stream_buffer_size = 0; // We steal uvw's provided buffers
llarp::quic::Debug("Initialized server");
LogDebug("Initialized server");
std::cout << "Listening on localhost:" << listen_port
<< " with tunnel(s) to localhost port(s):";
if (allowed_ports.empty())

Write Preview
Loading…
Cancel
Save