This is an automated email from the ASF dual-hosted git repository. scw00 pushed a commit to branch qlog in repository https://gitbox.apache.org/repos/asf/trafficserver.git
commit 1d9cf486ba9b4c960aa605616938a2537b70fe19 Author: scw00 <sc...@apache.org> AuthorDate: Mon May 25 13:54:49 2020 +0800 QUIC: add qlog support --- iocore/cache/Makefile.am | 3 +- iocore/dns/Makefile.am | 3 +- iocore/hostdb/Makefile.am | 3 +- iocore/net/P_QUICNetVConnection.h | 4 + iocore/net/QUICNetVConnection.cc | 22 +- iocore/net/quic/Makefile.am | 7 +- iocore/net/quic/QUICCongestionController.h | 2 + iocore/net/quic/QUICContext.cc | 11 +- iocore/net/quic/QUICContext.h | 11 +- iocore/net/quic/QUICFrame.cc | 18 +- iocore/net/quic/QUICFrame.h | 5 +- iocore/net/quic/QUICFrameDispatcher.cc | 10 +- iocore/net/quic/QUICFrameDispatcher.h | 4 +- iocore/net/quic/QUICLog.cc | 76 +++ iocore/net/quic/QUICLog.h | 113 ++++ iocore/net/quic/QUICLogEvent.cc | 294 +++++++++ iocore/net/quic/QUICLogEvent.h | 984 +++++++++++++++++++++++++++++ iocore/net/quic/QUICLogFrame.cc | 258 ++++++++ iocore/net/quic/QUICLogFrame.h | 286 +++++++++ iocore/net/quic/QUICLogUtils.h | 40 ++ iocore/net/quic/QUICLossDetector.cc | 3 + iocore/net/quic/QUICTypes.cc | 27 + iocore/net/quic/QUICTypes.h | 8 + iocore/net/quic/test/test_QUICType.cc | 32 + mgmt/Makefile.am | 3 +- proxy/hdrs/Makefile.am | 3 +- proxy/http/Makefile.am | 3 +- proxy/http2/Makefile.am | 3 +- proxy/http3/Makefile.am | 3 +- proxy/shared/Makefile.am | 3 +- src/traffic_quic/Makefile.inc | 3 +- src/traffic_server/Makefile.inc | 3 +- 32 files changed, 2224 insertions(+), 24 deletions(-) diff --git a/iocore/cache/Makefile.am b/iocore/cache/Makefile.am index 307f05b..e7a8803 100644 --- a/iocore/cache/Makefile.am +++ b/iocore/cache/Makefile.am @@ -27,7 +27,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy/http/remap \ -I$(abs_top_srcdir)/mgmt \ -I$(abs_top_srcdir)/mgmt/utils \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ noinst_LIBRARIES = libinkcache.a diff --git a/iocore/dns/Makefile.am b/iocore/dns/Makefile.am index a7287d2..8507b90 100644 --- a/iocore/dns/Makefile.am +++ b/iocore/dns/Makefile.am @@ -25,7 +25,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy/hdrs \ -I$(abs_top_srcdir)/mgmt \ -I$(abs_top_srcdir)/mgmt/utils \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ noinst_LIBRARIES = libinkdns.a diff --git a/iocore/hostdb/Makefile.am b/iocore/hostdb/Makefile.am index 8f49b12..5ecc4dc 100644 --- a/iocore/hostdb/Makefile.am +++ b/iocore/hostdb/Makefile.am @@ -25,7 +25,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy/http \ -I$(abs_top_srcdir)/mgmt \ -I$(abs_top_srcdir)/mgmt/utils \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ EXTRA_DIST = I_HostDB.h diff --git a/iocore/net/P_QUICNetVConnection.h b/iocore/net/P_QUICNetVConnection.h index f603dfe..cc2901c 100644 --- a/iocore/net/P_QUICNetVConnection.h +++ b/iocore/net/P_QUICNetVConnection.h @@ -69,6 +69,7 @@ #include "quic/QUICPacketProtectionKeyInfo.h" #include "quic/QUICContext.h" #include "quic/QUICTokenCreator.h" +#include "quic/QUICLog.h" // Size of connection ids for debug log : e.g. aaaaaaaa-bbbbbbbb\0 static constexpr size_t MAX_CIDS_SIZE = 8 + 1 + 8 + 1; @@ -372,6 +373,9 @@ private: QUICAddrVerifyState _verified_state; std::unique_ptr<QUICContextImpl> _context; + + QLog::QUICLog _qlog; + QLog::Trace *_trace; }; typedef int (QUICNetVConnection::*QUICNetVConnHandler)(int, void *); diff --git a/iocore/net/QUICNetVConnection.cc b/iocore/net/QUICNetVConnection.cc index 7940ae4..32cf1ab 100644 --- a/iocore/net/QUICNetVConnection.cc +++ b/iocore/net/QUICNetVConnection.cc @@ -42,6 +42,7 @@ #include "QUICHandshake.h" #include "QUICConfig.h" #include "QUICIntUtil.h" +#include "QUICLogUtils.h" using namespace std::literals; static constexpr std::string_view QUIC_DEBUG_TAG = "quic_net"sv; @@ -247,6 +248,8 @@ QUICNetVConnection::init(QUICConnectionId peer_cid, QUICConnectionId original_ci this->_update_cids(); + this->_trace = &this->_qlog.new_trace({"ats", QLog::Trace::VantagePointType::client, QLog::Trace::VantagePointType::client}, + this->_original_quic_connection_id.hex()); if (is_debug_tag_set(QUIC_DEBUG_TAG.data())) { QUICConDebug("dcid=%s scid=%s", this->_peer_quic_connection_id.hex().c_str(), this->_quic_connection_id.hex().c_str()); } @@ -275,6 +278,8 @@ QUICNetVConnection::init(QUICConnectionId peer_cid, QUICConnectionId original_ci this->_update_cids(); + this->_trace = &this->_qlog.new_trace({"ats", QLog::Trace::VantagePointType::server, QLog::Trace::VantagePointType::server}, + this->_original_quic_connection_id.hex()); if (is_debug_tag_set(QUIC_DEBUG_TAG.data())) { QUICConDebug("dcid=%s scid=%s", this->_peer_quic_connection_id.hex().c_str(), this->_quic_connection_id.hex().c_str()); } @@ -388,7 +393,8 @@ QUICNetVConnection::start() }); this->_path_manager = new QUICPathManagerImpl(*this, *this->_path_validator); - this->_context = std::make_unique<QUICContextImpl>(&this->_rtt_measure, this, &this->_pp_key_info, this->_path_manager); + this->_context = + std::make_unique<QUICContextImpl>(*this->_trace, &this->_rtt_measure, this, &this->_pp_key_info, this->_path_manager); this->_five_tuple.update(this->local_addr, this->remote_addr, SOCK_DGRAM); QUICPath trusted_path = {{}, {}}; // Version 0x00000001 uses stream 0 for cryptographic handshake with TLS 1.3, but newer version may not @@ -422,7 +428,7 @@ QUICNetVConnection::start() this->_application_map = new QUICApplicationMap(); - this->_frame_dispatcher = new QUICFrameDispatcher(this); + this->_frame_dispatcher = new QUICFrameDispatcher(*this->_context, this); // Create frame handlers this->_pinger = new QUICPinger(); @@ -487,6 +493,7 @@ QUICNetVConnection::free(EThread *t) super::clear(); */ + this->_qlog.dump(); ALPNSupport::clear(); this->_packet_handler->close_connection(this); } @@ -660,6 +667,9 @@ QUICNetVConnection::stream_manager() void QUICNetVConnection::handle_received_packet(UDPPacket *packet) { + auto dr = std::make_unique<QLog::Transport::DatagramReceived>(); + dr->set_byte_length(static_cast<int>(packet->getPktLength())); + this->_trace->push_event(std::move(dr)); this->_packet_recv_queue.enqueue(packet); } @@ -1576,6 +1586,7 @@ QUICNetVConnection::_packetize_frames(uint8_t *packet_buf, QUICEncryptionLevel l bool crypto = false; uint8_t frame_instance_buffer[QUICFrame::MAX_INSTANCE_SIZE]; // This is for a frame instance but not serialized frame data QUICFrame *frame = nullptr; + std::vector<QLog::QLogFrameUPtr> qframes; for (auto g : this->_frame_generators.generators()) { // a non-ack_eliciting packet is ready, but we can not send continuous two ack_eliciting packets. while (g->will_generate_frame(level, len, ack_eliciting, seq_num)) { @@ -1625,6 +1636,7 @@ QUICNetVConnection::_packetize_frames(uint8_t *packet_buf, QUICEncryptionLevel l crypto = true; } + qframes.push_back(QLog::QLogFrameFactory::create(*frame)); frame->~QUICFrame(); } else { // Move to next generator @@ -1637,6 +1649,12 @@ QUICNetVConnection::_packetize_frames(uint8_t *packet_buf, QUICEncryptionLevel l if (len != 0) { // Packet is retransmittable if it's not ack only packet packet = this->_build_packet(packet_buf, level, first_block, ack_eliciting, probing, crypto); + std::unique_ptr<QLog::Transport::PacketSent> ps = + std::make_unique<QLog::Transport::PacketSent>(QLog::PacketTypeToName(packet->type()), QLog::QUICPacketToLogPacket(*packet)); + for (auto &it : qframes) { + ps->append_frames(std::move(it)); + } + this->_trace->push_event(std::move(ps)); } return packet; diff --git a/iocore/net/quic/Makefile.am b/iocore/net/quic/Makefile.am index 982c281..d651d2d 100644 --- a/iocore/net/quic/Makefile.am +++ b/iocore/net/quic/Makefile.am @@ -29,7 +29,7 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/mgmt \ -I$(abs_top_srcdir)/mgmt/utils \ $(TS_INCLUDES) \ - @OPENSSL_INCLUDES@ + @OPENSSL_INCLUDES@ @YAMLCPP_INCLUDES@ noinst_LIBRARIES = libquic.a @@ -103,7 +103,10 @@ libquic_a_SOURCES = \ QUICStreamFactory.cc \ QUICPadder.cc \ QUICContext.cc \ - QUICTokenCreator.cc + QUICTokenCreator.cc \ + QUICLogFrame.cc \ + QUICLogEvent.cc \ + QUICLog.cc # # Check Programs diff --git a/iocore/net/quic/QUICCongestionController.h b/iocore/net/quic/QUICCongestionController.h index 46341dc..9c6bfaf 100644 --- a/iocore/net/quic/QUICCongestionController.h +++ b/iocore/net/quic/QUICCongestionController.h @@ -23,6 +23,8 @@ #pragma once +#include "QUICFrame.h" + struct QUICPacketInfo { // 6.3.1. Sent Packet Fields QUICPacketNumber packet_number; diff --git a/iocore/net/quic/QUICContext.cc b/iocore/net/quic/QUICContext.cc index 640dffd..ec84265 100644 --- a/iocore/net/quic/QUICContext.cc +++ b/iocore/net/quic/QUICContext.cc @@ -100,9 +100,10 @@ private: const QUICConfigParams *_params; }; -QUICContextImpl::QUICContextImpl(QUICRTTProvider *rtt, QUICConnectionInfoProvider *info, +QUICContextImpl::QUICContextImpl(QLog::Trace &trace, QUICRTTProvider *rtt, QUICConnectionInfoProvider *info, QUICPacketProtectionKeyInfoProvider *key_info, QUICPathManager *path_manager) - : _key_info(key_info), + : _qlog_trace(trace), + _key_info(key_info), _connection_info(info), _rtt_provider(rtt), _path_manager(path_manager), @@ -152,3 +153,9 @@ QUICContextImpl::path_manager() const { return _path_manager; } + +QLog::Trace & +QUICContextImpl::qlog_trace() +{ + return this->_qlog_trace; +} \ No newline at end of file diff --git a/iocore/net/quic/QUICContext.h b/iocore/net/quic/QUICContext.h index b5b4023..65044fb 100644 --- a/iocore/net/quic/QUICContext.h +++ b/iocore/net/quic/QUICContext.h @@ -25,6 +25,7 @@ #include "QUICConnection.h" #include "QUICConfig.h" +#include "QUICLog.h" class QUICRTTProvider; class QUICCongestionController; @@ -39,6 +40,7 @@ public: virtual ~QUICContext(){}; virtual QUICConnectionInfoProvider *connection_info() const = 0; virtual QUICConfig::scoped_config config() const = 0; + virtual QLog::Trace &qlog_trace() = 0; }; class QUICLDContext @@ -48,6 +50,7 @@ public: virtual QUICConnectionInfoProvider *connection_info() const = 0; virtual QUICLDConfig &ld_config() const = 0; virtual QUICPacketProtectionKeyInfoProvider *key_info() const = 0; + virtual QLog::Trace &qlog_trace() = 0; }; class QUICCCContext @@ -57,6 +60,7 @@ public: virtual QUICConnectionInfoProvider *connection_info() const = 0; virtual QUICCCConfig &cc_config() const = 0; virtual QUICRTTProvider *rtt_provider() const = 0; + virtual QLog::Trace &qlog_trace() = 0; }; class QUICStreamManagerContext @@ -66,13 +70,14 @@ public: virtual QUICConnectionInfoProvider *connection_info() const = 0; virtual QUICRTTProvider *rtt_provider() const = 0; virtual QUICPathManager *path_manager() const = 0; + virtual QLog::Trace &qlog_trace() = 0; }; class QUICContextImpl : public QUICContext, public QUICCCContext, public QUICLDContext, public QUICStreamManagerContext { public: - QUICContextImpl(QUICRTTProvider *rtt, QUICConnectionInfoProvider *info, QUICPacketProtectionKeyInfoProvider *key_info, - QUICPathManager *path_manager); + QUICContextImpl(QLog::Trace &trace, QUICRTTProvider *rtt, QUICConnectionInfoProvider *info, + QUICPacketProtectionKeyInfoProvider *key_info, QUICPathManager *path_manager); virtual QUICConnectionInfoProvider *connection_info() const override; virtual QUICConfig::scoped_config config() const override; @@ -85,8 +90,10 @@ public: virtual QUICCCConfig &cc_config() const override; virtual QUICPathManager *path_manager() const override; + virtual QLog::Trace &qlog_trace() override; private: + QLog::Trace &_qlog_trace; QUICConfig::scoped_config _config; QUICPacketProtectionKeyInfoProvider *_key_info = nullptr; QUICConnectionInfoProvider *_connection_info = nullptr; diff --git a/iocore/net/quic/QUICFrame.cc b/iocore/net/quic/QUICFrame.cc index 2cffbd1..d4c939d 100644 --- a/iocore/net/quic/QUICFrame.cc +++ b/iocore/net/quic/QUICFrame.cc @@ -541,6 +541,22 @@ QUICCryptoFrame::data() const // ACK frame // +std::set<QUICAckFrame::PacketNumberRange> +QUICAckFrame::ranges() const +{ + std::set<QUICAckFrame::PacketNumberRange> numbers; + QUICPacketNumber x = this->largest_acknowledged(); + numbers.insert({x, static_cast<uint64_t>(x) - this->ack_block_section()->first_ack_block()}); + x -= this->ack_block_section()->first_ack_block() + 1; + for (auto &&block : *(this->ack_block_section())) { + x -= block.gap() + 1; + numbers.insert({x, static_cast<uint64_t>(x) - block.length()}); + x -= block.length() + 1; + } + + return numbers; +} + QUICAckFrame::QUICAckFrame(const uint8_t *buf, size_t len, const QUICPacketR *packet) : QUICFrame(0, nullptr, packet) { this->parse(buf, len, packet); @@ -2885,7 +2901,7 @@ QUICFrameFactory::create(uint8_t *buf, const uint8_t *src, size_t len, const QUI } } -const QUICFrame & +QUICFrame & QUICFrameFactory::fast_create(const uint8_t *buf, size_t len, const QUICPacketR *packet) { if (QUICFrame::type(buf) == QUICFrameType::UNKNOWN) { diff --git a/iocore/net/quic/QUICFrame.h b/iocore/net/quic/QUICFrame.h index 0086804..24f8743 100644 --- a/iocore/net/quic/QUICFrame.h +++ b/iocore/net/quic/QUICFrame.h @@ -30,6 +30,7 @@ #include "I_IOBuffer.h" #include <vector> #include <iterator> +#include <set> #include "QUICTypes.h" @@ -268,6 +269,7 @@ public: QUICAckFrame(const uint8_t *buf, size_t len, const QUICPacketR *packet = nullptr); QUICAckFrame(QUICPacketNumber largest_acknowledged, uint64_t ack_delay, uint64_t first_ack_block, QUICFrameId id = 0, QUICFrameGenerator *owner = nullptr); + std::set<PacketNumberRange> ranges() const; // There's no reasont restrict copy, but we need to write the copy constructor. Otherwise it will crash on destruct. QUICAckFrame(const QUICAckFrame &) = delete; @@ -745,6 +747,7 @@ public: class QUICUnknownFrame : public QUICFrame { +public: QUICFrameType type() const override; size_t size() const override; virtual Ptr<IOBufferBlock> to_io_buffer_block(size_t limit) const override; @@ -767,7 +770,7 @@ public: * This works almost the same as create() but it reuses created objects for performance. * If you create a frame object which has the same frame type that you created before, the object will be reset by new data. */ - const QUICFrame &fast_create(const uint8_t *buf, size_t len, const QUICPacketR *packet); + QUICFrame &fast_create(const uint8_t *buf, size_t len, const QUICPacketR *packet); /* * Creates a STREAM frame. diff --git a/iocore/net/quic/QUICFrameDispatcher.cc b/iocore/net/quic/QUICFrameDispatcher.cc index 6832c7f..8229054 100644 --- a/iocore/net/quic/QUICFrameDispatcher.cc +++ b/iocore/net/quic/QUICFrameDispatcher.cc @@ -23,6 +23,7 @@ #include "QUICFrameDispatcher.h" #include "QUICDebugNames.h" +#include "QUICLogUtils.h" static constexpr char tag[] = "quic_net"; @@ -31,7 +32,7 @@ static constexpr char tag[] = "quic_net"; // // Frame Dispatcher // -QUICFrameDispatcher::QUICFrameDispatcher(QUICConnectionInfoProvider *info) : _info(info) {} +QUICFrameDispatcher::QUICFrameDispatcher(QUICContext &context, QUICConnectionInfoProvider *info) : _context(context), _info(info) {} void QUICFrameDispatcher::add_handler(QUICFrameHandler *handler) @@ -50,8 +51,10 @@ QUICFrameDispatcher::receive_frames(QUICEncryptionLevel level, const uint8_t *pa is_flow_controlled = false; QUICConnectionErrorUPtr error = nullptr; + std::unique_ptr<QLog::Transport::PacketReceived> qe = + std::make_unique<QLog::Transport::PacketReceived>(QLog::PacketTypeToName(packet->type()), QLog::QUICPacketToLogPacket(*packet)); while (cursor < size) { - const QUICFrame &frame = this->_frame_factory.fast_create(payload + cursor, size - cursor, packet); + QUICFrame &frame = this->_frame_factory.fast_create(payload + cursor, size - cursor, packet); if (frame.type() == QUICFrameType::UNKNOWN) { QUICDebug("Failed to create a frame (%u bytes skipped)", size - cursor); break; @@ -67,6 +70,8 @@ QUICFrameDispatcher::receive_frames(QUICEncryptionLevel level, const uint8_t *pa is_flow_controlled = true; } + qe->append_frames(QLog::QLogFrameFactory::create(frame)); + if (is_debug_tag_set(tag) && type != QUICFrameType::PADDING) { char msg[1024]; frame.debug_msg(msg, sizeof(msg)); @@ -87,5 +92,6 @@ QUICFrameDispatcher::receive_frames(QUICEncryptionLevel level, const uint8_t *pa } } + this->_context.qlog_trace().push_event(std::move(qe)); return error; } diff --git a/iocore/net/quic/QUICFrameDispatcher.h b/iocore/net/quic/QUICFrameDispatcher.h index cbbaef6..c7b48f4 100644 --- a/iocore/net/quic/QUICFrameDispatcher.h +++ b/iocore/net/quic/QUICFrameDispatcher.h @@ -28,11 +28,12 @@ #include "QUICConnection.h" #include "QUICFrame.h" #include "QUICFrameHandler.h" +#include "QUICContext.h" class QUICFrameDispatcher { public: - QUICFrameDispatcher(QUICConnectionInfoProvider *info); + QUICFrameDispatcher(QUICContext &_context, QUICConnectionInfoProvider *info); QUICConnectionErrorUPtr receive_frames(QUICEncryptionLevel level, const uint8_t *payload, uint16_t size, bool &should_send_ackbool, bool &is_flow_controlled, bool *has_non_probing_frame, @@ -41,6 +42,7 @@ public: void add_handler(QUICFrameHandler *handler); private: + QUICContext &_context; QUICConnectionInfoProvider *_info = nullptr; QUICFrameFactory _frame_factory; std::vector<QUICFrameHandler *> _handlers[256]; diff --git a/iocore/net/quic/QUICLog.cc b/iocore/net/quic/QUICLog.cc new file mode 100644 index 0000000..19aaed8 --- /dev/null +++ b/iocore/net/quic/QUICLog.cc @@ -0,0 +1,76 @@ +#include "QUICLog.h" + +namespace QLog +{ +void +Trace::encode(YAML::Node &node) +{ + node["title"] = _title; + node["description"] = _desc; + + // common fields + { + YAML::Node cf; + cf["ODCID"] = _odcid; + cf["reference_time"] = std::to_string(this->_reference_time); + node["common_fields"] = cf; + } + + { + node["event_fields"].push_back("relative_time"); + node["event_fields"].push_back("category"); + node["event_fields"].push_back("event"); + node["event_fields"].push_back("data"); + + if (_vp.name != "") { + node["vantage_point"]["name"] = _vp.name; + } + + if (vantage_point_type_name(_vp.type)) { + node["vantage_point"]["type"] = vantage_point_type_name(_vp.type); + } + + if (vantage_point_type_name(_vp.flow)) { + node["vantage_point"]["flow"] = vantage_point_type_name(_vp.flow); + } + } + + // events + for (auto &&it : _events) { + YAML::Node sub(YAML::NodeType::value::Sequence); + sub.push_back((it->get_time() - this->_reference_time) / 1000000); + sub.push_back(it->category()); + sub.push_back(it->event()); + YAML::Node event; + it->encode(event); + sub.push_back(event); + node["events"].push_back(sub); + } +} + +void +QUICLog::dump() +{ + YAML::Node root; + root["qlog_version"] = this->_ver; + root["title"] = this->_title; + root["description"] = this->_desc; + for (auto &&it : this->_traces) { + YAML::Node node; + it->encode(node); + root["traces"].push_back(node); + } + + std::cout << "traces: " << root["traces"].size() << std::endl; + std::cout << "events: " << root["traces"][0]["events"].size() << std::endl; + + std::ofstream ofs; + ofs.open(this->_file, std::ofstream::in | std::ofstream::trunc); + + YAML::Emitter emitter(ofs); + emitter << YAML::DoubleQuoted << YAML::Flow << root; + ofs << "\n"; + ofs.close(); +} + +} // namespace QLog \ No newline at end of file diff --git a/iocore/net/quic/QUICLog.h b/iocore/net/quic/QUICLog.h new file mode 100644 index 0000000..5314292 --- /dev/null +++ b/iocore/net/quic/QUICLog.h @@ -0,0 +1,113 @@ + + +#pragma once + +#include <fstream> +#include <yaml-cpp/yaml.h> + +#include "QUICLogEvent.h" + +namespace QLog +{ +class Trace +{ +public: + enum class VantagePointType : uint8_t { + client, + server, + network, + unknown, + }; + + struct VantagePoint { + std::string name; + VantagePointType type; + VantagePointType flow = VantagePointType::unknown; + }; + + Trace(std::string odcid, std::string title = "", std::string desc = "") : _reference_time(Thread::get_hrtime()) {} + + Trace(const VantagePoint &vp, std::string odcid, std::string title = "", std::string desc = "") : Trace(odcid, title, desc) + { + set_vantage_point(vp); + } + + static const char * + vantage_point_type_name(VantagePointType ty) + { + switch (ty) { + case VantagePointType::client: + return "client"; + case VantagePointType::server: + return "server"; + case VantagePointType::network: + return "network"; + case VantagePointType::unknown: + return "unknown"; + default: + return nullptr; + } + } + + void + set_vantage_point(const VantagePoint &vp) + { + this->_vp = vp; + } + + Trace & + push_event(QLogEventUPtr e) + { + this->_events.push_back(std::move(e)); + return *this; + } + + void encode(YAML::Node &node); + +private: + int64_t _reference_time = Thread::get_hrtime(); + std::string _odcid; + std::string _title; + std::string _desc; + + VantagePoint _vp; + + std::vector<QLogEventUPtr> _events; +}; + +class QUICLog +{ +public: + static constexpr char QLOG_VERSION[] = "draft-01"; + // FIXME configurable + static constexpr char FILENAME[] = "ats.qlog"; + QUICLog(std::string filename = FILENAME, std::string title = "", std::string desc = "", std::string ver = QLOG_VERSION) + : _file(filename), _title(title), _desc(desc), _ver(ver) + { + } + + Trace & + new_trace(Trace::VantagePoint vp, std::string odcid, std::string title = "", std::string desc = "") + { + this->_traces.push_back(std::make_unique<Trace>(vp, odcid, title, desc)); + return *this->_traces.back().get(); + } + + Trace & + new_trace(std::string odcid, std::string title = "", std::string desc = "") + { + this->_traces.push_back(std::make_unique<Trace>(odcid, title, desc)); + return *this->_traces.back().get(); + } + + void dump(); + +private: + std::string _file; + std::string _title; + std::string _desc; + std::string _ver; + std::vector<std::unique_ptr<Trace>> _traces; +}; + +} // namespace QLog diff --git a/iocore/net/quic/QUICLogEvent.cc b/iocore/net/quic/QUICLogEvent.cc new file mode 100644 index 0000000..4d69cca --- /dev/null +++ b/iocore/net/quic/QUICLogEvent.cc @@ -0,0 +1,294 @@ +#include "QUICLogEvent.h" + +namespace QLog +{ +void +check_and_set(YAML::Node &node, std::string key, std::string val) +{ + if (val.length() > 0) { + node[key] = val; + } +} + +void +check_and_set(YAML::Node &node, std::string key, std::vector<std::string> val) +{ + if (val.size() > 0) { + node[key] = val; + } +} + +template <typename T> +void +check_and_set(YAML::Node &node, std::string key, T val) +{ + if (val) { + node[key] = val; + } +} + +namespace Connectivity +{ + void + ServerListening::encode(YAML::Node &node) + { + check_and_set(node, "ip_v4", _ip_v4); + check_and_set(node, "ip_v6", _ip_v6); + check_and_set(node, "port_v4", _port_v4); + check_and_set(node, "port_v6", _port_v6); + check_and_set(node, "stateless_reset_required", _port_v6); + check_and_set(node, "quic_version", _quic_version); + check_and_set(node, "alpn_values", _alpn_values); + } + + void + ConnectionStarted::encode(YAML::Node &node) + { + check_and_set(node, "quic_version", _quic_version); + check_and_set(node, "ip_version", _ip_version); + check_and_set(node, "src_ip", _src_ip); + check_and_set(node, "dst_ip", _dst_ip); + check_and_set(node, "protocol", _protocol); + check_and_set(node, "src_port", _src_port); + check_and_set(node, "dst_port", _dst_port); + check_and_set(node, "src_cid", _src_cid); + check_and_set(node, "dst_cid", _dst_cid); + check_and_set(node, "alpn_values", _alpn_values); + } + + void + ConnectionIdUpdated::encode(YAML::Node &node) + { + check_and_set(node, "src_old", _src_old); + check_and_set(node, "src_new", _src_new); + check_and_set(node, "dst_old", _dst_old); + check_and_set(node, "dst_new", _dst_new); + } + + void + SpinBitUpdated::encode(YAML::Node &node) + { + check_and_set(node, "state", _state); + } + + void + ConnectionStateUpdated::encode(YAML::Node &node) + { + check_and_set(node, "new", static_cast<int>(_new)); + check_and_set(node, "old", static_cast<int>(_old)); + check_and_set(node, "trigger", trigger_name(_trigger)); + } + +} // namespace Connectivity + +namespace Security +{ + void + KeyEvent::encode(YAML::Node &node) + { + node["key_type"] = static_cast<int>(_key_type); + node["new"] = _new; + check_and_set(node, "generation", _generation); + check_and_set(node, "old", _old); + check_and_set(node, "trigger", trigger_name(_trigger)); + } + +} // namespace Security + +namespace Transport +{ + void + ParametersSet::encode(YAML::Node &node) + { + node["owner"] = _owner ? "local" : "remote"; + check_and_set(node, "resumption_allowed", _resumption_allowed); + check_and_set(node, "early_data_enabled", _early_data_enabled); + check_and_set(node, "alpn", _alpn); + check_and_set(node, "version", _version); + check_and_set(node, "tls_cipher", _tls_cipher); + check_and_set(node, "original_connection_id", _original_connection_id); + check_and_set(node, "stateless_reset_token", _stateless_reset_token); + check_and_set(node, "disable_active_migration", _disable_active_migration); + check_and_set(node, "max_idle_timeout", _max_idle_timeout); + check_and_set(node, "max_udp_payload_size", _max_udp_payload_size); + check_and_set(node, "ack_delay_exponent", _ack_delay_exponent); + check_and_set(node, "max_ack_delay", _max_ack_delay); + check_and_set(node, "active_connection_id_limit", _active_connection_id_limit); + check_and_set(node, "initial_max_data", _initial_max_data); + check_and_set(node, "initial_max_stream_data_bidi_local", _initial_max_stream_data_bidi_local); + check_and_set(node, "initial_max_stream_data_bidi_remote", _initial_max_stream_data_bidi_remote); + check_and_set(node, "initial_max_stream_data_uni", _initial_max_stream_data_uni); + check_and_set(node, "initial_max_streams_bidi", _initial_max_streams_bidi); + check_and_set(node, "initial_max_streams_uni", _initial_max_streams_uni); + + if (_preferred_address.ip.length() > 0) { + YAML::Node sub; + check_and_set(sub, _preferred_address.ipv4 ? "ip_v4" : "ip_v6", _preferred_address.ip); + check_and_set(sub, _preferred_address.ipv4 ? "port_v4" : "port_v6", _preferred_address.port); + check_and_set(sub, "connection_id", _preferred_address.connection_id); + check_and_set(sub, "stateless_reset_token", _preferred_address.stateless_reset_token); + node["preferred_address"] = sub; + } + } + + void + PacketEvent::encode(YAML::Node &node) + { + node["packet_type"] = _packet_type; + for (auto &&it : this->_frames) { + YAML::Node sub; + it->encode(sub); + node["frames"].push_back(sub); + } + check_and_set(node, "is_coalesced", _is_coalesced); + check_and_set(node, "stateless_reset_token", _stateless_reset_token); + check_and_set(node, "supported_version", _supported_version); + check_and_set(node, "raw_encrypted", _raw_encrypted); + check_and_set(node, "raw_decrypted", _raw_decrypted); + check_and_set(node, "supported_version", _supported_version); + check_and_set(node, "supported_version", trigger_name(_trigger)); + + node["header"]["packet_number"] = _header.packet_number; + node["header"]["packet_size"] = _header.packet_size; + node["header"]["payload_length"] = _header.payload_length; + node["header"]["version"] = _header.version; + node["header"]["scil"] = _header.scil; + node["header"]["dcil"] = _header.dcil; + node["header"]["scid"] = _header.scid; + node["header"]["dcid"] = _header.dcid; + } + + void + PacketDropped::encode(YAML::Node &node) + { + node["packet_type"] = _packet_type; + check_and_set(node, "packet_size", _packet_size); + check_and_set(node, "raw", _raw); + check_and_set(node, "trigger", trigger_name(_trigger)); + } + + void + PacketBuffered::encode(YAML::Node &node) + { + node["packet_type"] = _packet_type; + check_and_set(node, "trigger", trigger_name(_trigger)); + check_and_set(node, "packet_number", trigger_name(_trigger)); + } + + void + DatagramsEvent::encode(YAML::Node &node) + { + check_and_set(node, "count", _count); + check_and_set(node, "byte_length", _byte_length); + } + + void + DatagramsDropped::encode(YAML::Node &node) + { + check_and_set(node, "byte_length", _byte_length); + } + + void + StreamStateUpdated::encode(YAML::Node &node) + { + node["new"] = static_cast<int>(_new); + node["stream_id"] = _stream_id; + // FXIME + // node["stream_type"] = bidi ? "bidirectional" : "unidirectional"; + // node["stream_side"] = "sending"; + } + + void + FrameProcessed::encode(YAML::Node &node) + { + for (auto &&it : _frames) { + YAML::Node sub; + it->encode(sub); + node["frames"].push_back(sub); + } + } + +} // namespace Transport + +namespace Recovery +{ + void + ParametersSet::encode(YAML::Node &node) + { + check_and_set(node, "reordering_threshold", _reordering_threshold); + check_and_set(node, "time_threshold", _time_threshold); + check_and_set(node, "timer_granularity", _timer_granularity); + check_and_set(node, "initial_rtt", _initial_rtt); + check_and_set(node, "max_datagram_size", _max_datagram_size); + check_and_set(node, "initial_congestion_window", _initial_congestion_window); + check_and_set(node, "minimum_congestion_window", _minimum_congestion_window); + check_and_set(node, "loss_reduction_factor", _loss_reduction_factor); + check_and_set(node, "persistent_congestion_threshold", _persistent_congestion_threshold); + } + + void + MetricsUpdated::encode(YAML::Node &node) + { + check_and_set(node, "min_rtt", _min_rtt); + check_and_set(node, "smoothed_rtt", _smoothed_rtt); + check_and_set(node, "latest_rtt", _latest_rtt); + check_and_set(node, "rtt_variance", _rtt_variance); + check_and_set(node, "max_ack_delay", _max_ack_delay); + check_and_set(node, "pto_count", _pto_count); + check_and_set(node, "congestion_window", _congestion_window); + check_and_set(node, "bytes_in_flight", _bytes_in_flight); + check_and_set(node, "ssthresh", _ssthresh); + check_and_set(node, "packets_in_flight", _packets_in_flight); + check_and_set(node, "in_recovery", _in_recovery); + check_and_set(node, "pacing_rate", _pacing_rate); + } + + void + CongestionStateUpdated::encode(YAML::Node &node) + { + node["new"] = state_to_string(_new); + check_and_set(node, "old", state_to_string(_old)); + check_and_set(node, "old", trigger_name(_trigger)); + } + + void + LossTimerUpdated::encode(YAML::Node &node) + { + node["timer_type"] = _timer_type_ack ? "ack" : "pto"; + check_and_set(node, "event_type", event_type_name(_event_type)); + check_and_set(node, "packet_number_space", _packet_number_space); + if (_event_type == EventType::set) { + check_and_set(node, "delta", _delta); + } + } + + void + PacketLost::encode(YAML::Node &node) + { + node["packet_number"] = _packet_number; + node["packet_type"] = _packet_type; + check_and_set(node, "trigger", trigger_name(_trigger)); + YAML::Node sub; + _header.encode(sub); + node["header"] = sub; + + for (auto &&it : _frames) { + YAML::Node sub; + it->encode(sub); + node["frames"].push_back(sub); + } + } + + void + MarkedForRetransmit::encode(YAML::Node &node) + { + for (auto &&it : _frames) { + YAML::Node sub; + it->encode(sub); + node["frames"].push_back(sub); + } + } + +} // namespace Recovery + +} // namespace QLog diff --git a/iocore/net/quic/QUICLogEvent.h b/iocore/net/quic/QUICLogEvent.h new file mode 100644 index 0000000..f8f2c68 --- /dev/null +++ b/iocore/net/quic/QUICLogEvent.h @@ -0,0 +1,984 @@ +#pragma once + +#include <string> +#include <yaml-cpp/yaml.h> + +#include "QUICTypes.h" +#include "QUICLogFrame.h" + +namespace QLog +{ +class QLogEvent +{ +public: + virtual ~QLogEvent() {} + + virtual std::string category() const = 0; + virtual std::string event() const = 0; + virtual void encode(YAML::Node &) = 0; + + virtual ink_hrtime + get_time() const + { + return this->_time; + }; + +protected: + ink_hrtime _time = Thread::get_hrtime(); +}; + +using QLogEventUPtr = std::unique_ptr<QLogEvent>; + +#define SET(field, type) \ + void set_##field(type v) { this->_node[#field] = v; } + +// enum class PacketType : uint8_t { initial, handshake, zerortt, onertt, retry, version_negotiation, unknown }; +using PacketType = std::string; + +struct PacketHeader { + std::string packet_number; + uint64_t packet_size; + uint64_t payload_length; + + // only if present in the header + // if correctly using NEW_CONNECTION_ID events, + // dcid can be skipped for 1RTT packets + std::string version; + std::string scil; + std::string dcil; + std::string scid; + std::string dcid; + + // Note: short vs long header is implicit through PacketType + void + encode(YAML::Node &node) + { + node["packet_number"] = packet_number; + node["packet_size"] = packet_size; + node["payload_length"] = payload_length; + node["version"] = version; + node["scil"] = scil; + node["dcil"] = dcil; + node["scid"] = scid; + node["dcid"] = dcid; + } +}; + +#define SET_FUNC(cla, field, type) \ +public: \ + cla &set_##field(type v) \ + { \ + this->_##field = v; \ + return *this; \ + } \ + \ +private: \ + type _##field; + +#define APPEND_FUNC(cla, field, type) \ +public: \ + cla &append_##field(type v) \ + { \ + this->_##field.push_back(v); \ + return *this; \ + } \ + \ +private: \ + std::vector<type> _##field; + +#define APPEND_FRAME_FUNC(cla) \ +public: \ + cla &append_frames(QLogFrameUPtr v) \ + { \ + this->_frames.push_back(std::move(v)); \ + return *this; \ + } \ + \ +private: \ + std::vector<QLogFrameUPtr> _frames; + +// +// connectivity +// +namespace Connectivity +{ + class ConnectivityEvent : public QLogEvent + { + public: + std::string + category() const override + { + return "connectivity"; + } + }; + + class ServerListening : public ConnectivityEvent + { + public: + ServerListening(int port, bool v6 = false) + { + if (v6) { + set_port_v6(port); + } else { + set_port_v4(port); + } + } + +#define _SET(a, b) SET_FUNC(ServerListening, a, b) +#define _APPEND(a, b) APPEND_FUNC(ServerListening, a, b) + _SET(port_v4, int) + _SET(port_v6, int) + _SET(ip_v4, std::string) + _SET(ip_v6, std::string) + _SET(stateless_reset_required, bool) + _APPEND(quic_version, std::string) + _APPEND(alpn_values, std::string) + +#undef _SET +#undef _APPEND + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "server_listening"; + } + }; + + class ConnectionStarted : public ConnectivityEvent + { + public: + ConnectionStarted(std::string version, std::string sip, std::string dip, int sport, int dport, std::string protocol = "QUIC") + { + set_ip_version(version); + set_protocol(protocol); + set_src_ip(sip); + set_dst_ip(dip); + set_src_port(sport); + set_dst_port(dport); + } + +#define _SET(a, b) SET_FUNC(ConnectionStarted, a, b) +#define _APPEND(a, b) APPEND_FUNC(ConnectionStarted, a, b) + _SET(quic_version, std::string); + _SET(src_cid, std::string); + _SET(dst_cid, std::string); + _SET(protocol, std::string); + _SET(ip_version, std::string) + _SET(src_ip, std::string) + _SET(dst_ip, std::string) + _SET(src_port, int) + _SET(dst_port, int) + _APPEND(alpn_values, std::string) + +#undef _SET +#undef _APPEND + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "connection_started"; + } + }; + + class ConnectionIdUpdated : public ConnectivityEvent + { + public: + ConnectionIdUpdated(std::string old, std::string n, bool peer = false) + { + if (peer) { + set_dst_old(old); + set_dst_new(n); + } else { + set_src_old(old); + set_src_new(n); + } + } + +#define _SET(a, b) SET_FUNC(ConnectionIdUpdated, a, b) +#define _APPEND(a, b) APPEND_FUNC(ConnectionIdUpdated, a, b) + + _SET(src_old, std::string); + _SET(src_new, std::string); + _SET(dst_old, std::string); + _SET(dst_new, std::string); + +#undef _SET +#undef _APPEND + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "connection_id_updated"; + } + }; + + class SpinBitUpdated : public ConnectivityEvent + { + public: + SpinBitUpdated(bool state) { set_state(state); } + +#define _SET(a, b) SET_FUNC(SpinBitUpdated, a, b) + _SET(state, bool); +#undef _SET + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "spin_bit_updated"; + } + }; + + class ConnectionStateUpdated : public ConnectivityEvent + { + public: + enum class ConnectionState : uint8_t { + attempted, // client initial sent + reset, // stateless reset sent + handshake, // handshake in progress + active, // handshake successful, data exchange + keepalive, // no data for a longer period + draining, // CONNECTION_CLOSE sent + closed // connection actually fully closed, memory freed + }; + + enum class Triggered : uint8_t { + unknown, + error, // when closing because of an unexpected event + clean, // when closing normally + application // e.g., HTTP/3's GOAWAY frame + }; + + ConnectionStateUpdated(ConnectionState n, Triggered tr = Triggered::unknown) + { + set_new(n); + set_trigger(tr); + } + +#define _SET(a, b) SET_FUNC(ConnectionStateUpdated, a, b) + _SET(new, ConnectionState); + _SET(old, ConnectionState); + _SET(trigger, Triggered) + +#undef _SET + + void encode(YAML::Node &) override; + + static const char * + trigger_name(Triggered trigger) + { + switch (trigger) { + case Triggered::error: + return "error"; + case Triggered::clean: + return "clean"; + case Triggered::application: + return "application"; + default: + return nullptr; + } + } + + std::string + event() const override + { + return "connection_state_updated"; + } + }; + +} // namespace Connectivity + +namespace Security +{ + class KeyEvent : public QLogEvent + { + public: + enum class KeyType : uint8_t { + server_initial_secret, + client_initial_secret, + + server_handshake_secret, + client_handshake_secret, + + server_0rtt_secret, + client_0rtt_secret, + + server_1rtt_secret, + client_1rtt_secret + }; + + enum class Triggered : uint8_t { + unknown, + remote_update, + local_update, + tls, + }; + + KeyEvent(KeyType ty, std::string n, int generation, Triggered triggered = Triggered::unknown) + { + set_key_type(ty); + set_new(n); + set_generation(generation); + set_trigger(triggered); + } + +#define _SET(a, b) SET_FUNC(KeyEvent, a, b) + _SET(key_type, KeyType); + _SET(new, std::string) + _SET(old, std::string); + _SET(generation, int) + _SET(trigger, Triggered) +#undef _SET + + void encode(YAML::Node &) override; + + const char * + trigger_name(Triggered triggered) + { + switch (triggered) { + case Triggered::remote_update: + return "remote_update"; + case Triggered::local_update: + return "local_update"; + case Triggered::tls: + return "tls"; + default: + return nullptr; + } + } + + std::string + category() const override + { + return "security"; + } + }; + + class KeyUpdated : public KeyEvent + { + public: + KeyUpdated(KeyType ty, std::string n, int generation, Triggered triggered = KeyEvent::Triggered::unknown) + : KeyEvent(ty, n, generation, triggered) + { + } + + std::string + event() const override + { + return "key_updated"; + } + }; + + class KeyRetired : public KeyEvent + { + public: + KeyRetired(KeyType ty, std::string n, int generation, Triggered triggered = KeyEvent::Triggered::unknown) + : KeyEvent(ty, n, generation, triggered) + { + } + + std::string + event() const override + { + return "key_retired"; + } + }; + +} // namespace Security + +// +// transport event +// +namespace Transport +{ + class TransportEvent : public QLogEvent + { + public: + std::string + category() const override + { + return "transport"; + } + }; + + class ParametersSet : public TransportEvent + { + public: + struct PreferredAddress { + std::string ip; + int port; + std::string connection_id; + std::string stateless_reset_token; + bool ipv4 = true; + }; + + ParametersSet(bool owner) : _owner(owner) {} + + std::string + event() const override + { + return "parameters_set"; + } + +#define _SET(a, b) SET_FUNC(ParametersSet, a, b) + _SET(resumption_allowed, bool); // early data extension was enabled on the TLS layer + _SET(early_data_enabled, bool); // early data extension was enabled on the TLS layer + _SET(alpn, std::string); + _SET(version, std::string); // hex (e.g. 0x); + _SET(tls_cipher, std::string); // (e.g. AES_128_GCM_SHA256); + _SET(original_connection_id, std::string); // hex + _SET(stateless_reset_token, std::string); // hex + _SET(disable_active_migration, bool); + _SET(idle_timeout, int); + _SET(max_packet_size, int); + _SET(ack_delay_exponent, int); + _SET(max_ack_delay, int); + _SET(active_connection_id_limit, int); + _SET(initial_max_data, std::string); + _SET(initial_max_stream_data_bidi_local, std::string); + _SET(initial_max_stream_data_bidi_remote, std::string); + _SET(initial_max_stream_data_uni, std::string); + _SET(initial_max_streams_bidi, std::string); + _SET(initial_max_streams_uni, std::string); + _SET(max_idle_timeout, int64_t) + _SET(max_udp_payload_size, size_t) + _SET(preferred_address, PreferredAddress) +#undef _SET + + void encode(YAML::Node &) override; + + private: + bool _owner = false; + }; + + class PacketEvent : public TransportEvent + { + public: + enum class Triggered : uint8_t { + unknown, + keys_available, // if packet was buffered because it couldn't be decrypted before + retransmit_reordered, // draft-23 5.1.1 + retransmit_timeout, // draft-23 5.1.2 + pto_probe, // draft-23 5.3.1 + retransmit_crypto, // draft-19 6.2 + cc_bandwidth_probe, // needed for some CCs to figure out bandwidth allocations when there are no normal sends + }; + + PacketEvent(PacketType type, PacketHeader h, Triggered tr = Triggered::unknown) + { + set_packet_type(type).set_header(h).set_trigger(tr); + } + +#define _SET(a, b) SET_FUNC(PacketEvent, a, b) +#define _APPEND(a, b) APPEND_FUNC(PacketEvent, a, b) + _SET(packet_type, PacketType) + _SET(header, PacketHeader) + _SET(is_coalesced, bool); + _SET(raw_encrypted, std::string); + _SET(raw_decrypted, std::string); + _SET(stateless_reset_token, std::string); + _SET(trigger, Triggered); + _APPEND(supported_version, std::string); + +#undef _SET +#undef _APPEND + APPEND_FRAME_FUNC(PacketEvent) + + void encode(YAML::Node &) override; + + static const char * + trigger_name(Triggered triggered) + { + switch (triggered) { + case Triggered::retransmit_reordered: + return "retransmit_reordered"; + case Triggered::retransmit_timeout: + return "retransmit_timeout"; + case Triggered::pto_probe: + return "pto_probe"; + case Triggered::retransmit_crypto: + return "retransmit_crypto"; + case Triggered::cc_bandwidth_probe: + return "cc_bandwidth_probe"; + break; + case Triggered::keys_available: + return "keys_available"; + default: + return nullptr; + } + } + }; + + class PacketSent : public PacketEvent + { + public: + PacketSent(PacketType type, PacketHeader h, Triggered tr = Triggered::unknown) : PacketEvent(type, h, tr) {} + std::string + event() const override + { + return "packet_sent"; + } + }; + + class PacketReceived : public PacketEvent + { + public: + PacketReceived(PacketType type, PacketHeader h, Triggered tr = Triggered::unknown) : PacketEvent(type, h, tr) {} + std::string + event() const override + { + return "packet_received"; + } + }; + + class PacketDropped : public TransportEvent + { + public: + enum class Triggered : uint8_t { + unknown, + key_unavailable, + unknown_connection_id, + header_decrypt_error, + payload_decrypt_error, + protocol_violation, + dos_prevention, + unsupported_version, + unexpected_packet, + unexpected_source_connection_id, + unexpected_version, + }; + + PacketDropped(Triggered tr = Triggered::unknown) { set_trigger(tr); } + +#define _SET(a, b) SET_FUNC(PacketDropped, a, b) + _SET(packet_size, int); + _SET(raw, std::string); + _SET(trigger, Triggered); + _SET(packet_type, PacketType) +#undef _SET + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "packet_dropped"; + } + + static const char * + trigger_name(Triggered tr) + { + switch (tr) { + case Triggered::key_unavailable: + return "key_unavailable"; + case Triggered::unknown_connection_id: + return "unknown_connection_id"; + case Triggered::header_decrypt_error: + return "header_decrypt_error"; + case Triggered::payload_decrypt_error: + return "payload_decrypt_error"; + case Triggered::protocol_violation: + return "protocol_violation"; + case Triggered::dos_prevention: + return "dos_prevention"; + case Triggered::unsupported_version: + return "unsupported_version"; + case Triggered::unexpected_packet: + return "unexpected_packet"; + case Triggered::unexpected_source_connection_id: + return "unexpected_source_connection_id"; + case Triggered::unexpected_version: + return "unexpected_version"; + default: + return nullptr; + } + } + }; + + class PacketBuffered : public TransportEvent + { + public: + enum class Triggered : uint8_t { + unknown, + backpressure, + keys_unavailable, + }; + + PacketBuffered(Triggered tr = Triggered::unknown) { set_trigger(tr); } + +#define _SET(a, b) SET_FUNC(PacketBuffered, a, b) + _SET(trigger, Triggered); + _SET(packet_type, PacketType) + _SET(packet_number, std::string) +#undef _SET + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "packet_buffered"; + } + + static const char * + trigger_name(Triggered tr) + { + switch (tr) { + case Triggered::backpressure: + return "backpressure"; + case Triggered::keys_unavailable: + return "keys_unavailable"; + default: + return nullptr; + } + } + }; + + class DatagramsEvent : public TransportEvent + { + public: +#define _SET(a, b) SET_FUNC(DatagramsEvent, a, b) + _SET(count, int); + _SET(byte_length, int); +#undef _SET + void encode(YAML::Node &) override; + }; + + class DatagramsSent : public DatagramsEvent + { + public: + std::string + event() const override + { + return "datagrams_sent"; + } + }; + class DatagramReceived : public DatagramsEvent + { + public: + std::string + event() const override + { + return "datagrams_received"; + } + }; + + class DatagramsDropped : public TransportEvent + { + public: +#define _SET(a, b) SET_FUNC(DatagramsDropped, a, b) + _SET(byte_length, int); +#undef _SET + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "datagrams_dropped"; + } + }; + + class StreamStateUpdated : public TransportEvent + { + enum class StreamState { + // bidirectional stream states, draft-23 3.4. + idle, + open, + half_closed_local, + half_closed_remote, + closed, + + // sending-side stream states, draft-23 3.1. + ready, + send, + data_sent, + reset_sent, + reset_received, + + // receive-side stream states, draft-23 3.2. + receive, + size_known, + data_read, + reset_read, + + // both-side states + data_received, + + // qlog-defined + destroyed // memory actually freed + }; + + StreamStateUpdated(std::string stream_id, StreamState n) { set_new(n).set_stream_id(stream_id); } + + void encode(YAML::Node &) override; + +#define _SET(a, b) SET_FUNC(StreamStateUpdated, a, b) + _SET(new, StreamState); + _SET(old, StreamState); + _SET(stream_id, std::string); + _SET(bidi, bool); +#undef _SET + + std::string + event() const override + { + return "stream_state_updated"; + } + }; + + class FrameProcessed : public TransportEvent + { + public: + APPEND_FRAME_FUNC(FrameProcessed) + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "frame_processed"; + } + }; + +} // namespace Transport + +namespace Recovery +{ + class RecoveryEvent : public QLogEvent + { + public: + std::string + category() const override + { + return "recovery"; + } + }; + + class ParametersSet : public RecoveryEvent + { + public: +#define _SET(a, b) SET_FUNC(ParametersSet, a, b) + _SET(reordering_threshold, int); + _SET(time_threshold, int); + _SET(timer_granularity, int); + _SET(initial_rtt, int); + _SET(max_datagram_size, int); + _SET(initial_congestion_window, int); + _SET(minimum_congestion_window, int); + _SET(loss_reduction_factor, int); + _SET(persistent_congestion_threshold, int); +#undef _SET + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "parameters_set"; + } + }; + + class MetricsUpdated : public RecoveryEvent + { + public: +#define _SET(a, b) SET_FUNC(MetricsUpdated, a, b) + _SET(min_rtt, int); + _SET(smoothed_rtt, int); + _SET(latest_rtt, int); + _SET(rtt_variance, int); + _SET(max_ack_delay, int); + _SET(pto_count, int); + _SET(congestion_window, int); + _SET(bytes_in_flight, int); + _SET(ssthresh, int); + _SET(packets_in_flight, int); + _SET(in_recovery, int); + _SET(pacing_rate, int); +#undef _SET + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "metrics_updated"; + } + }; + + class CongestionStateUpdated : public RecoveryEvent + { + public: + enum class State : uint8_t { + slow_start, + congestion_avoidance, + application_limited, + recovery, + }; + + enum class Triggered : uint8_t { + unknown, + persistent_congestion, + ECN, + }; + + CongestionStateUpdated(State n, Triggered tr = Triggered::unknown) { set_trigger(tr).set_new(n); } + +#define _SET(a, b) SET_FUNC(CongestionStateUpdated, a, b) + _SET(trigger, Triggered) + _SET(new, State) + _SET(old, State) +#undef _SET + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "congestion_state_updated"; + } + + static const char * + trigger_name(Triggered tr) + { + switch (tr) { + case Triggered::persistent_congestion: + return "persistent_congestion"; + case Triggered::ECN: + return "ECN"; + default: + return nullptr; + } + } + + static const char * + state_to_string(State s) + { + switch (s) { + case State::slow_start: + return "slow_start"; + case State::congestion_avoidance: + return "congestion_avoidance"; + case State::application_limited: + return "application_limited"; + case State::recovery: + return "recovery"; + default: + break; + } + } + }; + + class LossTimerUpdated : public RecoveryEvent + { + public: + enum class EventType : uint8_t { + set, + expired, + cancelled, + }; + + void + set_timer_type(bool ack) + { + this->_timer_type_ack = ack; + } + + void encode(YAML::Node &) override; + +#define _SET(a, b) SET_FUNC(LossTimerUpdated, a, b) + _SET(event_type, EventType) + _SET(packet_number_space, int); + _SET(delta, int); +#undef _SET + + std::string + event() const override + { + return "loss_timer_updated"; + } + + static const char * + event_type_name(EventType et) + { + switch (et) { + case EventType::set: + return "set"; + case EventType::expired: + return "expired"; + case EventType::cancelled: + return "cancelled"; + } + } + + private: + bool _timer_type_ack = false; + }; + + class PacketLost : public RecoveryEvent + { + public: + enum class Triggered : uint8_t { + unknown, + reordering_threshold, + time_threshold, + pto_expired, + }; + + PacketLost(PacketType pt, uint64_t pn, Triggered tr = Triggered::unknown) + { + set_trigger(tr).set_packet_type(pt).set_packet_number(pn); + } + +#define _SET(a, b) SET_FUNC(PacketLost, a, b) + _SET(header, PacketHeader) + _SET(packet_number, uint64_t); + _SET(packet_type, PacketType); + _SET(trigger, Triggered) + APPEND_FRAME_FUNC(PacketLost) +#undef _SET + + void encode(YAML::Node &) override; + + std::string + event() const override + { + return "packet_lost"; + } + + static const char * + trigger_name(Triggered tr) + { + switch (tr) { + case Triggered::pto_expired: + return "pto_expired"; + case Triggered::reordering_threshold: + return "reordering_threshold"; + case Triggered::time_threshold: + return "time_threshold"; + default: + return nullptr; + } + } + }; + + class MarkedForRetransmit : public RecoveryEvent + { + public: + APPEND_FRAME_FUNC(MarkedForRetransmit) + void encode(YAML::Node &) override; + std::string + event() const override + { + return "marked_for_retransmit"; + } + }; + +} // namespace Recovery + +} // namespace QLog diff --git a/iocore/net/quic/QUICLogFrame.cc b/iocore/net/quic/QUICLogFrame.cc new file mode 100644 index 0000000..f72dc1e --- /dev/null +++ b/iocore/net/quic/QUICLogFrame.cc @@ -0,0 +1,258 @@ +#include "QUICLogFrame.h" + +namespace QLog +{ +template <typename Real> +Real & +Convert(QUICFrame &frame) +{ + auto tmp = &frame; +#if defined(DEBUG) + auto ref = dynamic_cast<Real *>(tmp); + ink_assert(ref != nullptr); + return *ref; +#endif + return *static_cast<Real *>(tmp); +} + +QLogFrameUPtr +QLogFrameFactory::create(QUICFrame &frame) +{ + switch (frame.type()) { + case QUICFrameType::ACK: + return std::make_unique<Frame::AckFrame>(Convert<QUICAckFrame>(frame)); + case QUICFrameType::PADDING: + return std::make_unique<Frame::PaddingFrame>(Convert<QUICPaddingFrame>(frame)); + case QUICFrameType::PING: + return std::make_unique<Frame::PingFrame>(Convert<QUICPingFrame>(frame)); + case QUICFrameType::RESET_STREAM: + return std::make_unique<Frame::RstStreamFrame>(Convert<QUICRstStreamFrame>(frame)); + case QUICFrameType::STOP_SENDING: + return std::make_unique<Frame::StopSendingFrame>(Convert<QUICStopSendingFrame>(frame)); + case QUICFrameType::CRYPTO: + return std::make_unique<Frame::CryptoFrame>(Convert<QUICCryptoFrame>(frame)); + case QUICFrameType::NEW_TOKEN: + return std::make_unique<Frame::NewTokenFrame>(Convert<QUICNewTokenFrame>(frame)); + case QUICFrameType::STREAM: + return std::make_unique<Frame::StreamFrame>(Convert<QUICStreamFrame>(frame)); + case QUICFrameType::MAX_DATA: + return std::make_unique<Frame::MaxDataFrame>(Convert<QUICMaxDataFrame>(frame)); + case QUICFrameType::MAX_STREAM_DATA: + return std::make_unique<Frame::MaxStreamDataFrame>(Convert<QUICMaxStreamDataFrame>(frame)); + case QUICFrameType::MAX_STREAMS: + return std::make_unique<Frame::MaxStreamsFrame>(Convert<QUICMaxStreamsFrame>(frame)); + case QUICFrameType::DATA_BLOCKED: + return std::make_unique<Frame::DataBlockedFrame>(Convert<QUICDataBlockedFrame>(frame)); + case QUICFrameType::STREAM_DATA_BLOCKED: + return std::make_unique<Frame::StreamDataBlockedFrame>(Convert<QUICStreamDataBlockedFrame>(frame)); + case QUICFrameType::STREAMS_BLOCKED: + return std::make_unique<Frame::StreamsBlockedFrame>(Convert<QUICStreamIdBlockedFrame>(frame)); + case QUICFrameType::NEW_CONNECTION_ID: + return std::make_unique<Frame::NewConnectionIDFrame>(Convert<QUICNewConnectionIdFrame>(frame)); + case QUICFrameType::RETIRE_CONNECTION_ID: + return std::make_unique<Frame::RetireConnectionIDFrame>(Convert<QUICRetireConnectionIdFrame>(frame)); + case QUICFrameType::PATH_CHALLENGE: + return std::make_unique<Frame::PathChallengeFrame>(Convert<QUICPathChallengeFrame>(frame)); + case QUICFrameType::PATH_RESPONSE: + return std::make_unique<Frame::PathResponseFrame>(Convert<QUICPathResponseFrame>(frame)); + case QUICFrameType::CONNECTION_CLOSE: + return std::make_unique<Frame::ConnectionCloseFrame>(Convert<QUICConnectionCloseFrame>(frame)); + case QUICFrameType::HANDSHAKE_DONE: + return std::make_unique<Frame::HandshakeDoneFrame>(Convert<QUICHandshakeDoneFrame>(frame)); + default: + ink_release_assert(0); + return nullptr; + } +} + +namespace Frame +{ + template <typename T> + std::string + convert_to_string(T a) + { + return std::to_string(static_cast<uint64_t>(a)); + } + + void + AckFrame::encode(YAML::Node &node) + { + node["frame_type"] = "ack"; + node["ack_delay"] = std::to_string(ack_delay); + for (auto &it : acked_range) { + YAML::Node sub; + sub.push_back(convert_to_string(it.first())); + sub.push_back(convert_to_string(it.last())); + node["acked_ranges"].push_back(sub); + } + + if (ect1) { + node["ect1"] = ect1; + } + + if (ect1) { + node["ect0"] = ect0; + } + + if (ce) { + node["ce"] = ce; + } + } + + void + StreamFrame::encode(YAML::Node &node) + { + node["frame_type"] = "stream"; + node["stream_id"] = stream_id; + node["offset"] = offset; + node["length"] = length; + node["fin"] = fin; + } + + void + PaddingFrame::encode(YAML::Node &node) + { + node["frame_type"] = "padding"; + } + + void + PingFrame::encode(YAML::Node &node) + { + node["frame_type"] = "ping"; + } + + void + RstStreamFrame::encode(YAML::Node &node) + { + node["frame_type"] = "reset_stream"; + node["stream_id"] = stream_id; + node["error_code"] = error_code; + node["final_size"] = final_size; + } + + void + StopSendingFrame::encode(YAML::Node &node) + { + node["frame_type"] = "stop_sending"; + node["stream_id"] = stream_id; + node["error_code"] = error_code; + } + + void + CryptoFrame::encode(YAML::Node &node) + { + node["frame_type"] = "crypto"; + node["offset"] = offset; + node["length"] = length; + } + + void + NewTokenFrame::encode(YAML::Node &node) + { + node["frame_type"] = "new_token"; + node["token"] = token; + node["length"] = length; + } + + void + MaxDataFrame::encode(YAML::Node &node) + { + node["frame_type"] = "max_data"; + node["maximum"] = maximum; + } + + void + MaxStreamDataFrame::encode(YAML::Node &node) + { + node["frame_type"] = "max_stream_data"; + node["maximum"] = maximum; + node["stream_id"] = stream_id; + } + + void + MaxStreamsFrame::encode(YAML::Node &node) + { + node["frame_type"] = "max_streams"; + node["maximum"] = maximum; + node["stream_type"] = stream_type; + } + + void + DataBlockedFrame::encode(YAML::Node &node) + { + node["frame_type"] = "data_blocked"; + node["limit"] = limit; + } + + void + StreamDataBlockedFrame::encode(YAML::Node &node) + { + node["frame_type"] = "stream_data_blocked"; + node["limit"] = limit; + node["stream_id"] = stream_id; + } + + void + StreamsBlockedFrame::encode(YAML::Node &node) + { + node["frame_type"] = "streams_blocked"; + node["stream_id"] = stream_id; + node["stream_type"] = stream_type; + } + + void + NewConnectionIDFrame::encode(YAML::Node &node) + { + node["frame_type"] = "new_connection_id"; + node["sequence_number"] = sequence_number; + node["retire_prior_to"] = retire_prior_to; + node["stateless_reset_token"] = stateless_reset_token; + node["length"] = length; + } + + void + RetireConnectionIDFrame::encode(YAML::Node &node) + { + node["frame_type"] = "retire_connection_id"; + node["sequence_number"] = sequence_number; + } + + void + PathChallengeFrame::encode(YAML::Node &node) + { + node["frame_type"] = "path_challenge"; + node["data"] = data; + } + + void + PathResponseFrame::encode(YAML::Node &node) + { + node["frame_type"] = "path_response"; + node["data"] = data; + } + + void + ConnectionCloseFrame::encode(YAML::Node &node) + { + node["frame_type"] = "connection_close"; + node["error_space"] = error_space; + node["error_code"] = error_code; + node["raw_error_code"] = raw_error_code; + node["reason"] = reason; + } + + void + HandshakeDoneFrame::encode(YAML::Node &node) + { + node["frame_type"] = "handshake_done"; + } + + void + UnknownFrame::encode(YAML::Node &node) + { + node["frame_type"] = "unknown"; + node["raw_frame_type"] = raw_frame_type; + } + +} // namespace Frame +} // namespace QLog diff --git a/iocore/net/quic/QUICLogFrame.h b/iocore/net/quic/QUICLogFrame.h new file mode 100644 index 0000000..dda4c90 --- /dev/null +++ b/iocore/net/quic/QUICLogFrame.h @@ -0,0 +1,286 @@ +#pragma once + +#include <memory> +#include <yaml-cpp/yaml.h> + +#include "QUICFrame.h" + +namespace QLog +{ +class QLogFrame +{ +public: + QLogFrame(QUICFrameType type) : _type(type) {} + virtual ~QLogFrame() {} + + QUICFrameType + type() const + { + return this->_type; + } + + // encode frame into YAML stype + virtual void encode(YAML::Node &node) = 0; + +protected: + QUICFrameType _type = QUICFrameType::UNKNOWN; +}; + +using QLogFrameUPtr = std::unique_ptr<QLogFrame>; + +// +// convert QUICFrame to QLogFrame +// +class QLogFrameFactory +{ +public: + // create QLogFrame + static QLogFrameUPtr create(QUICFrame &frame); +}; + +namespace Frame +{ + struct AckFrame : public QLogFrame { + AckFrame(QUICAckFrame &frame) : QLogFrame(frame.type()) + { + acked_range = frame.ranges(); + ack_delay = frame.ack_delay(); + if (frame.ecn_section()) { + ect0 = frame.ecn_section()->ect0_count(); + ect1 = frame.ecn_section()->ect1_count(); + ce = frame.ecn_section()->ecn_ce_count(); + } + } + + void encode(YAML::Node &) override; + + std::set<QUICAckFrame::PacketNumberRange> acked_range; + uint64_t ect1 = 0; + uint64_t ect0 = 0; + uint64_t ce = 0; + uint64_t ack_delay = 0; + }; + + struct StreamFrame : public QLogFrame { + StreamFrame(QUICStreamFrame &frame) : QLogFrame(frame.type()) + { + stream_id = std::to_string(static_cast<uint64_t>(frame.stream_id())); + offset = std::to_string(static_cast<uint64_t>(frame.offset())); + length = frame.data_length(); + fin = frame.has_fin_flag(); + } + + void encode(YAML::Node &) override; + std::string stream_id; + + // These two MUST always be set + // If not present in the Frame type, log their default values + std::string offset; + uint64_t length = 0; + + // this MAY be set any time, but MUST only be set if the value is "true" + // if absent, the value MUST be assumed to be "false" + bool fin = false; + + // FIXME raw + }; + + struct PaddingFrame : public QLogFrame { + PaddingFrame(QUICPaddingFrame &frame) : QLogFrame(frame.type()) {} + void encode(YAML::Node &) override; + }; + + struct PingFrame : public QLogFrame { + PingFrame(QUICPingFrame &frame) : QLogFrame(frame.type()) {} + void encode(YAML::Node &) override; + }; + + struct RstStreamFrame : public QLogFrame { + RstStreamFrame(QUICRstStreamFrame &frame) : QLogFrame(frame.type()) + { + stream_id = std::to_string(static_cast<uint64_t>(frame.stream_id())); + error_code = frame.error_code(); + final_size = std::to_string(frame.final_offset()); + } + + void encode(YAML::Node &) override; + std::string stream_id; + // FIXME ApplicationError + uint64_t error_code = 0; + std::string final_size; + }; + + struct StopSendingFrame : public QLogFrame { + StopSendingFrame(QUICStopSendingFrame &frame) : QLogFrame(frame.type()) + { + stream_id = std::to_string(static_cast<uint64_t>(frame.stream_id())); + error_code = frame.error_code(); + } + + void encode(YAML::Node &) override; + std::string stream_id; + // FIXME ApplicationError + uint64_t error_code = 0; + }; + + struct CryptoFrame : public QLogFrame { + CryptoFrame(QUICCryptoFrame &frame) : QLogFrame(frame.type()) + { + offset = std::to_string(static_cast<uint64_t>(frame.offset())); + length = frame.data_length(); + } + + void encode(YAML::Node &) override; + std::string offset; + uint64_t length = 0; + }; + + struct NewTokenFrame : public QLogFrame { + NewTokenFrame(QUICNewTokenFrame &frame) : QLogFrame(frame.type()) + { + token = QUICBase::to_hex(frame.token(), frame.token_length()); + length = frame.token_length(); + } + + void encode(YAML::Node &) override; + std::string token; + uint64_t length = 0; + }; + + struct MaxDataFrame : public QLogFrame { + MaxDataFrame(QUICMaxDataFrame &frame) : QLogFrame(frame.type()) { maximum = std::to_string(frame.maximum_data()); } + + void encode(YAML::Node &) override; + std::string maximum; + }; + + struct MaxStreamDataFrame : public QLogFrame { + MaxStreamDataFrame(QUICMaxStreamDataFrame &frame) : QLogFrame(frame.type()) + { + stream_id = std::to_string(static_cast<uint64_t>(frame.stream_id())); + maximum = std::to_string(frame.maximum_stream_data()); + } + + void encode(YAML::Node &) override; + std::string stream_id; + std::string maximum; + }; + + struct MaxStreamsFrame : public QLogFrame { + MaxStreamsFrame(QUICMaxStreamsFrame &frame) : QLogFrame(frame.type()) + { + maximum = std::to_string(frame.maximum_streams()); + // FIXME + stream_type = "bidirectional"; + } + + void encode(YAML::Node &) override; + std::string stream_type; + std::string maximum; + }; + + struct DataBlockedFrame : public QLogFrame { + DataBlockedFrame(QUICDataBlockedFrame &frame) : QLogFrame(frame.type()) + { + limit = std::to_string(static_cast<uint64_t>(frame.offset())); + } + void encode(YAML::Node &) override; + std::string limit; + }; + + struct StreamDataBlockedFrame : public QLogFrame { + StreamDataBlockedFrame(QUICStreamDataBlockedFrame &frame) : QLogFrame(frame.type()) + { + limit = std::to_string(static_cast<uint64_t>(frame.offset())); + stream_id = std::to_string(static_cast<uint64_t>(frame.stream_id())); + } + + void encode(YAML::Node &) override; + std::string stream_id, limit; + }; + + struct StreamsBlockedFrame : public QLogFrame { + StreamsBlockedFrame(QUICStreamIdBlockedFrame &frame) : QLogFrame(frame.type()) + { + stream_type = "bidirectional"; + stream_id = std::to_string(static_cast<uint64_t>(frame.stream_id())); + } + + void encode(YAML::Node &) override; + std::string stream_id, stream_type; + }; + + struct NewConnectionIDFrame : public QLogFrame { + NewConnectionIDFrame(QUICNewConnectionIdFrame &frame) : QLogFrame(frame.type()) + { + sequence_number = std::to_string(frame.sequence()); + retire_prior_to = std::to_string(frame.retire_prior_to()); + connection_id = frame.connection_id().hex(); + stateless_reset_token = QUICBase::to_hex(frame.stateless_reset_token().buf(), QUICStatelessResetToken::LEN); + length = frame.connection_id().length(); + } + + void encode(YAML::Node &) override; + std::string sequence_number, retire_prior_to, connection_id, stateless_reset_token; + uint8_t length = 0; + }; + + struct RetireConnectionIDFrame : public QLogFrame { + RetireConnectionIDFrame(QUICRetireConnectionIdFrame &frame) : QLogFrame(frame.type()) + { + sequence_number = std::to_string(frame.seq_num()); + } + void encode(YAML::Node &) override; + std::string sequence_number; + }; + + struct PathChallengeFrame : public QLogFrame { + PathChallengeFrame(QUICPathChallengeFrame &frame) : QLogFrame(frame.type()) + { + data = QUICBase::to_hex(frame.data(), QUICPathChallengeFrame::DATA_LEN); + } + void encode(YAML::Node &) override; + std::string data; + }; + + struct PathResponseFrame : public QLogFrame { + PathResponseFrame(QUICPathResponseFrame &frame) : QLogFrame(frame.type()) + { + data = QUICBase::to_hex(frame.data(), QUICPathChallengeFrame::DATA_LEN); + } + void encode(YAML::Node &) override; + std::string data; + }; + + struct ConnectionCloseFrame : public QLogFrame { + ConnectionCloseFrame(QUICConnectionCloseFrame &frame, bool app = false) : QLogFrame(frame.type()) + { + error_space = app ? "application" : "transport"; + error_code = frame.error_code(); + // FIXME + raw_error_code = error_code; + reason = frame.reason_phrase(); + } + + void encode(YAML::Node &) override; + std::string error_space, reason, trigger_frame_type; + uint64_t error_code, raw_error_code; + }; + + struct HandshakeDoneFrame : public QLogFrame { + HandshakeDoneFrame(QUICHandshakeDoneFrame &frame) : QLogFrame(frame.type()){}; + void encode(YAML::Node &) override; + }; + + struct UnknownFrame : public QLogFrame { + UnknownFrame(QUICUnknownFrame &frame) : QLogFrame(frame.type()) + { + // FIXME + raw_frame_type = static_cast<uint8_t>(frame.type()); + } + + void encode(YAML::Node &) override; + uint8_t raw_frame_type = 0; + }; +} // namespace Frame +} // namespace QLog diff --git a/iocore/net/quic/QUICLogUtils.h b/iocore/net/quic/QUICLogUtils.h new file mode 100644 index 0000000..727b0df --- /dev/null +++ b/iocore/net/quic/QUICLogUtils.h @@ -0,0 +1,40 @@ +#include "QUICLog.h" +#include "QUICPacket.h" + +namespace QLog +{ +inline static const char * +PacketTypeToName(QUICPacketType pt) +{ + switch (pt) { + case QUICPacketType::INITIAL: + return "initial"; + case QUICPacketType::HANDSHAKE: + return "handshake"; + case QUICPacketType::ZERO_RTT_PROTECTED: + return "0rtt"; + case QUICPacketType::PROTECTED: + return "1rtt"; + case QUICPacketType::RETRY: + return "retry"; + case QUICPacketType::VERSION_NEGOTIATION: + return "version_negotiation"; + case QUICPacketType::STATELESS_RESET: + return "stateless_reset"; + default: + return "unknown"; + } +} + +inline static QLog::PacketHeader +QUICPacketToLogPacket(const QUICPacket &packet) +{ + QLog::PacketHeader ph; + ph.dcid = packet.destination_cid().hex(); + ph.packet_number = std::to_string(packet.packet_number()); + ph.packet_size = packet.size(); + ph.payload_length = packet.payload_length(); + return ph; +} + +} // namespace QLog \ No newline at end of file diff --git a/iocore/net/quic/QUICLossDetector.cc b/iocore/net/quic/QUICLossDetector.cc index 9dae182..96e67bb 100644 --- a/iocore/net/quic/QUICLossDetector.cc +++ b/iocore/net/quic/QUICLossDetector.cc @@ -32,6 +32,7 @@ #include "QUICPinger.h" #include "QUICPadder.h" #include "QUICPacketProtectionKeyInfo.h" +#include "QUICLogUtils.h" #define QUICLDDebug(fmt, ...) \ Debug("quic_loss_detector", "[%s] " fmt, this->_context.connection_info()->cids().data(), ##__VA_ARGS__) @@ -444,6 +445,8 @@ QUICLossDetector::_detect_lost_packets(QUICPacketNumberSpace pn_space) if (!lost_packets.empty()) { this->_cc->on_packets_lost(lost_packets); for (auto lost_packet : lost_packets) { + this->_context.qlog_trace().push_event( + std::make_unique<QLog::Recovery::PacketLost>(QLog::PacketTypeToName(lost_packet.second->type), lost_packet.first)); // -- ADDITIONAL CODE -- // Not sure how we can get feedback from congestion control and when we should retransmit the lost packets but we need to send // them somewhere. diff --git a/iocore/net/quic/QUICTypes.cc b/iocore/net/quic/QUICTypes.cc index 756af7d..80a8379 100644 --- a/iocore/net/quic/QUICTypes.cc +++ b/iocore/net/quic/QUICTypes.cc @@ -297,6 +297,18 @@ QUICStatelessResetToken::_hashcode() const (static_cast<uint64_t>(this->_token[6]) << 8) + (static_cast<uint64_t>(this->_token[7])); } +std::string +QUICStatelessResetToken::hex() const +{ + std::stringstream stream; + stream << "0x"; + for (auto i = 0; i < QUICStatelessResetToken::LEN; i++) { + stream << std::setfill('0') << std::setw(2) << std::hex; + stream << std::hex << static_cast<int>(this->_token[i]); + } + return stream.str(); +} + QUICResumptionToken::QUICResumptionToken(const IpEndpoint &src, QUICConnectionId cid, ink_hrtime expire_time) { // TODO: read cookie secret from file like SSLTicketKeyConfig @@ -796,3 +808,18 @@ QUICInvariants::scid(QUICConnectionId &dst, const uint8_t *buf, uint64_t buf_len return true; } + +namespace QUICBase +{ +std::string +to_hex(const uint8_t *buf, size_t len) +{ + std::stringstream stream; + stream << "0x"; + for (size_t i = 0; i < len; i++) { + stream << std::setfill('0') << std::setw(2) << std::hex; + stream << std::hex << static_cast<int>(buf[i]); + } + return stream.str(); +} +} // namespace QUICBase diff --git a/iocore/net/quic/QUICTypes.h b/iocore/net/quic/QUICTypes.h index 016631b..5139b78 100644 --- a/iocore/net/quic/QUICTypes.h +++ b/iocore/net/quic/QUICTypes.h @@ -308,6 +308,8 @@ public: return _token; } + std::string hex() const; + private: uint8_t _token[LEN] = {0}; @@ -610,3 +612,9 @@ public: }; int to_hex_str(char *dst, size_t dst_len, const uint8_t *src, size_t src_len); + +namespace QUICBase +{ +std::string to_hex(const uint8_t *buf, size_t len); + +} // namespace QUICBase diff --git a/iocore/net/quic/test/test_QUICType.cc b/iocore/net/quic/test/test_QUICType.cc index fb45c44..79dce74 100644 --- a/iocore/net/quic/test/test_QUICType.cc +++ b/iocore/net/quic/test/test_QUICType.cc @@ -26,8 +26,11 @@ #include "quic/QUICTypes.h" #include "I_EventSystem.h" #include "tscore/ink_hrtime.h" +#include "QUICLog.h" #include <memory> +#include <yaml-cpp/yaml.h> +/* TEST_CASE("QUICType", "[quic]") { SECTION("QUICPath") @@ -144,3 +147,32 @@ TEST_CASE("QUICType", "[quic]") CHECK(token1.cid() == token2.cid()); } } +*/ + +TEST_CASE("YAML binary", "yaml") +{ + QLog::QUICLog log; + auto &trace = log.new_trace("0x12345"); + std::unique_ptr<QLog::Transport::FrameProcessed> de = std::make_unique<QLog::Transport::FrameProcessed>(); + + QUICPingFrame ping; + de->append_frames(QLog::QLogFrameFactory::create(ping)); + + trace.push_event(std::move(de)); + + log.dump(); + + YAML::Node root; + root.push_back("a"); + root.push_back("b"); + root.push_back("c"); + root.push_back("c"); + + YAML::Node node; + node["hello"] = "world"; + root.push_back(node); + + YAML::Emitter emitter(std::cout); + emitter << YAML::DoubleQuoted << YAML::Flow << root; + std::cout << "\n"; +} diff --git a/mgmt/Makefile.am b/mgmt/Makefile.am index a52678d..8e5f218 100644 --- a/mgmt/Makefile.am +++ b/mgmt/Makefile.am @@ -34,7 +34,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy \ -I$(abs_top_srcdir)/proxy/http \ -I$(abs_top_srcdir)/proxy/hdrs \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ libmgmt_c_la_SOURCES = \ RecordsConfig.cc \ diff --git a/proxy/hdrs/Makefile.am b/proxy/hdrs/Makefile.am index 7fcd248..2ccf231 100644 --- a/proxy/hdrs/Makefile.am +++ b/proxy/hdrs/Makefile.am @@ -22,7 +22,8 @@ AM_CPPFLAGS += \ $(iocore_include_dirs) \ -I$(abs_top_srcdir)/include \ -I$(abs_top_srcdir)/lib \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ noinst_LIBRARIES = libhdrs.a EXTRA_PROGRAMS = load_http_hdr diff --git a/proxy/http/Makefile.am b/proxy/http/Makefile.am index 31a06c1..edc10ff 100644 --- a/proxy/http/Makefile.am +++ b/proxy/http/Makefile.am @@ -33,7 +33,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy/logging \ -I$(abs_top_srcdir)/proxy/http2 \ -I$(abs_top_srcdir)/proxy/http3 \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ noinst_HEADERS = HttpProxyServerMain.h noinst_LIBRARIES = libhttp.a diff --git a/proxy/http2/Makefile.am b/proxy/http2/Makefile.am index d34de70..9cb322b 100644 --- a/proxy/http2/Makefile.am +++ b/proxy/http2/Makefile.am @@ -29,7 +29,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy/hdrs \ -I$(abs_top_srcdir)/proxy/shared \ -I$(abs_top_srcdir)/proxy/http/remap \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ noinst_LIBRARIES = libhttp2.a diff --git a/proxy/http3/Makefile.am b/proxy/http3/Makefile.am index f5d4de5..c066d3f 100644 --- a/proxy/http3/Makefile.am +++ b/proxy/http3/Makefile.am @@ -30,7 +30,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy/hdrs \ -I$(abs_top_srcdir)/proxy/shared \ -I$(abs_top_srcdir)/proxy/http/remap \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ noinst_LIBRARIES = libhttp3.a diff --git a/proxy/shared/Makefile.am b/proxy/shared/Makefile.am index 1d54d40..48a1109 100644 --- a/proxy/shared/Makefile.am +++ b/proxy/shared/Makefile.am @@ -35,7 +35,8 @@ AM_CPPFLAGS += \ -I$(abs_top_srcdir)/proxy/http \ -I$(abs_top_srcdir)/proxy/hdrs \ -I$(abs_top_srcdir)/proxy/logging \ - $(TS_INCLUDES) + $(TS_INCLUDES) \ + @YAMLCPP_INCLUDES@ libdiagsconfig_a_SOURCES = \ DiagsConfig.cc diff --git a/src/traffic_quic/Makefile.inc b/src/traffic_quic/Makefile.inc index 963576f..c241944 100644 --- a/src/traffic_quic/Makefile.inc +++ b/src/traffic_quic/Makefile.inc @@ -32,7 +32,8 @@ traffic_quic_traffic_quic_CPPFLAGS = \ -I$(abs_top_srcdir)/proxy/logging \ -I$(abs_top_srcdir)/proxy/shared \ $(TS_INCLUDES) \ - @OPENSSL_INCLUDES@ + @OPENSSL_INCLUDES@ \ + @YAMLCPP_INCLUDES@ traffic_quic_traffic_quic_LDFLAGS = \ $(AM_LDFLAGS) \ diff --git a/src/traffic_server/Makefile.inc b/src/traffic_server/Makefile.inc index d189bd7..4481969 100644 --- a/src/traffic_server/Makefile.inc +++ b/src/traffic_server/Makefile.inc @@ -35,7 +35,8 @@ traffic_server_traffic_server_CPPFLAGS = \ -I$(abs_top_srcdir)/mgmt \ -I$(abs_top_srcdir)/mgmt/utils \ $(TS_INCLUDES) \ - @OPENSSL_INCLUDES@ + @OPENSSL_INCLUDES@ \ + @YAMLCPP_INCLUDES@ traffic_server_traffic_server_LDFLAGS = \ $(AM_LDFLAGS) \