Setup logging in Quic based on QLogger

Summary: Setup logging in Quic based on QLogger.

Reviewed By: mjoras

Differential Revision: D15818340

fbshipit-source-id: 553aaedc6043a7f079c597ef0647c5b91f3033df

quic/api/CMakeLists.txt

@@ -38,6 +38,7 @@ add_dependencies(
   mvfst_happyeyeballs
   mvfst_looper
   mvfst_loss
+  mvfst_qlogger
   mvfst_state_functions
   mvfst_state_machine
   mvfst_state_pacing_functions
@@ -61,6 +62,7 @@ target_link_libraries(
   mvfst_happyeyeballs
   mvfst_looper
   mvfst_loss
+  mvfst_qlogger
   mvfst_state_functions
   mvfst_state_machine
   mvfst_state_pacing_functions

quic/api/QuicTransportBase.h

@@ -435,6 +435,10 @@ class QuicTransportBase : public QuicSocket {
     conn_->logger = std::move(logger);
   }
 
+  void setQLogger(std::shared_ptr<QLogger> qLogger) {
+    conn_->qLogger = std::move(qLogger);
+  }
+
   virtual void cancelAllAppCallbacks(
       std::pair<QuicErrorCode, std::string> error) noexcept;
 

quic/api/QuicTransportFunctions.cpp

@@ -206,6 +206,9 @@ void updateConnection(
   VLOG(10) << nodeToString(conn.nodeType) << " sent packetNum=" << packetNum
            << " in space=" << packetNumberSpace << " size=" << encodedSize
            << " " << conn;
+  if (conn.qLogger) {
+    conn.qLogger->add(packet, encodedSize);
+  }
   for (const auto& frame : packet.frames) {
     folly::variant_match(
         frame,
@@ -603,13 +606,13 @@ uint64_t writeQuicDataExceptCryptoStreamToSocket(
   uint64_t written = 0;
   if (connection.pendingEvents.numProbePackets) {
     auto probeScheduler = std::move(FrameScheduler::Builder(
-                                      connection,
+                                        connection,
-                                      fizz::EncryptionLevel::AppTraffic,
+                                        fizz::EncryptionLevel::AppTraffic,
-                                      PacketNumberSpace::AppData,
+                                        PacketNumberSpace::AppData,
-                                      "ProbeWithoutCrypto")
+                                        "ProbeWithoutCrypto")
-                                      .streamFrames()
+                                        .streamFrames()
-                                      .streamRetransmissions())
+                                        .streamRetransmissions())
-                            .build();
+                              .build();
     written = writeProbingDataToSocket(
         socket,
         connection,
@@ -764,6 +767,9 @@ void writeCloseCommon(
   auto packetBuf = std::move(packet.header);
   packetBuf->prependChain(std::move(body));
   auto packetSize = packetBuf->computeChainDataLength();
+  if (connection.qLogger) {
+    connection.qLogger->add(packet.packet, packetSize);
+  }
   QUIC_TRACE(
       packet_sent,
       connection,

quic/api/test/QuicTransportFunctionsTest.cpp

@@ -12,6 +12,8 @@
 #include <quic/api/test/MockQuicStats.h>
 #include <quic/api/test/Mocks.h>
 #include <quic/common/test/TestUtils.h>
+#include <quic/logging/FileQLogger.h>
+#include <quic/logging/QLoggerConstants.h>
 #include <quic/server/state/ServerStateMachine.h>
 #include <quic/state/test/Mocks.h>
 
@@ -181,7 +183,7 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnection) {
   auto mockCongestionController = std::make_unique<MockCongestionController>();
   auto rawCongestionController = mockCongestionController.get();
   conn->congestionController = std::move(mockCongestionController);
-
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   // Builds a fake packet to test with.
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
 
@@ -210,6 +212,25 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnection) {
       .WillOnce(Return(true));
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint{}, getEncodedSize(packet));
+
+  // verify handshake packet is stored in QLogger
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+
+  EXPECT_EQ(qLogger->logs.size(), 1);
+  auto p1 = std::move(qLogger->logs[0]);
+  auto event1 = dynamic_cast<QLogPacketEvent*>(p1.get());
+  EXPECT_EQ(event1->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event1->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event1->eventType, QLogEventType::PacketSent);
+  EXPECT_EQ(event1->frames.size(), 2);
+  // verify contents of writeStreamFrame in QLogger
+  auto frame = static_cast<StreamFrameLog*>(event1->frames[0].get());
+  EXPECT_EQ(frame->streamId, stream1->id);
+  EXPECT_EQ(frame->offset, 0);
+  EXPECT_EQ(frame->len, 5);
+  EXPECT_EQ(frame->fin, false);
+
   EXPECT_EQ(
       conn->ackStates.initialAckState.nextPacketNum,
       currentNextInitialPacketNum);
@@ -302,10 +323,18 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnection) {
   EXPECT_TRUE(eq(*IOBuf::copyBuffer("ats up"), *rt6.data.front()));
   EXPECT_EQ(rt6.offset, 6);
   EXPECT_EQ(rt6.eof, 1);
+
+  // another handshake packet was sent
+  EXPECT_EQ(qLogger->logs.size(), 2);
+  auto p2 = std::move(qLogger->logs[1]);
+  auto event2 = dynamic_cast<QLogPacketEvent*>(p2.get());
+  EXPECT_EQ(event2->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event2->frames.size(), 3);
 }
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionPacketSorting) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   conn->ackStates.initialAckState.nextPacketNum = 0;
   conn->ackStates.handshakeAckState.nextPacketNum = 1;
   conn->ackStates.appDataAckState.nextPacketNum = 2;
@@ -331,21 +360,42 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionPacketSorting) {
       appDataPacket.packet,
       TimePoint{},
       getEncodedSize(appDataPacket));
+  // verify qLogger added correct logs
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+
+  EXPECT_EQ(3, qLogger->logs.size());
+  auto l1 = std::move(qLogger->logs[0]);
+  auto l2 = std::move(qLogger->logs[1]);
+  auto l3 = std::move(qLogger->logs[2]);
+  auto event1 = dynamic_cast<QLogPacketEvent*>(l1.get());
+  auto event2 = dynamic_cast<QLogPacketEvent*>(l2.get());
+  auto event3 = dynamic_cast<QLogPacketEvent*>(l3.get());
+
+  EXPECT_EQ(event1->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event2->packetType, toString(LongHeader::Types::Initial));
+  EXPECT_EQ(event3->packetType, toString(LongHeader::Types::ZeroRtt));
 
   EXPECT_EQ(3, conn->outstandingPackets.size());
   auto& firstHeader = conn->outstandingPackets.front().packet.header;
-  EXPECT_EQ(0, folly::variant_match(firstHeader, [](const auto& h) {
+  auto firstPacketNum = folly::variant_match(
-              return h.getPacketSequenceNum();
+      firstHeader, [](const auto& h) { return h.getPacketSequenceNum(); });
-            }));
+  EXPECT_EQ(0, firstPacketNum);
+  EXPECT_EQ(1, event1->packetNum);
+
   EXPECT_EQ(
       PacketNumberSpace::Initial,
       folly::variant_match(
           firstHeader, [](const auto& h) { return h.getPacketNumberSpace(); }));
 
   auto& lastHeader = conn->outstandingPackets.back().packet.header;
-  EXPECT_EQ(2, folly::variant_match(lastHeader, [](const auto& h) {
+
-              return h.getPacketSequenceNum();
+  auto lastPacketNum = folly::variant_match(
-            }));
+      lastHeader, [](const auto& h) { return h.getPacketSequenceNum(); });
+
+  EXPECT_EQ(2, lastPacketNum);
+  EXPECT_EQ(2, event3->packetNum);
+
   EXPECT_EQ(
       PacketNumberSpace::AppData,
       folly::variant_match(
@@ -354,6 +404,7 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionPacketSorting) {
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionFinOnly) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   auto stream1 = conn->streamManager->createNextBidirectionalStream().value();
 
@@ -362,6 +413,25 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionFinOnly) {
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
 
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event->frames.size(), 1);
+  auto frame = static_cast<StreamFrameLog*>(event->frames[0].get());
+  EXPECT_EQ(frame->streamId, stream1->id);
+  EXPECT_EQ(frame->offset, 0);
+  EXPECT_EQ(frame->len, 0);
+  EXPECT_EQ(frame->fin, true);
+
   EXPECT_EQ(stream1->retransmissionBuffer.size(), 1);
   auto& rt1 = stream1->retransmissionBuffer.front();
 
@@ -373,6 +443,7 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionFinOnly) {
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionAllBytesExceptFin) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
 
   auto stream1 = conn->streamManager->createNextUnidirectionalStream().value();
@@ -385,6 +456,24 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionAllBytesExceptFin) {
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
 
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event->frames.size(), 1);
+  auto frame = static_cast<StreamFrameLog*>(event->frames[0].get());
+  EXPECT_EQ(frame->streamId, stream1->id);
+  EXPECT_EQ(frame->offset, 0);
+  EXPECT_EQ(frame->len, buf->computeChainDataLength());
+  EXPECT_EQ(frame->fin, false);
+
   EXPECT_EQ(stream1->currentWriteOffset, buf->computeChainDataLength());
 
   EXPECT_EQ(stream1->retransmissionBuffer.size(), 1);
@@ -398,6 +487,7 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionAllBytesExceptFin) {
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionEmptyAckWriteResult) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   // None of the largestAckScheduled should be changed. But since
   // buildEmptyPacket() builds a Handshake packet, we use handshakeAckState to
@@ -406,6 +496,17 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionEmptyAckWriteResult) {
       conn->ackStates.handshakeAckState.largestAckScheduled;
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
+
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+
   EXPECT_EQ(
       currentPendingLargestAckScheduled,
       conn->ackStates.handshakeAckState.largestAckScheduled);
@@ -413,6 +514,7 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionEmptyAckWriteResult) {
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionPureAckCounter) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto stream = conn->streamManager->createNextBidirectionalStream().value();
   writeDataToQuicStream(*stream, nullptr, true);
   EXPECT_EQ(0, conn->outstandingHandshakePacketsCount);
@@ -429,6 +531,17 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionPureAckCounter) {
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
   EXPECT_EQ(1, conn->outstandingPureAckPacketsCount);
 
+  //  verify QLogger contains correct packet and frame information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+  EXPECT_EQ(event->frames.size(), 1);
+
   auto nonHandshake = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   packetEncodedSize =
       nonHandshake.header ? nonHandshake.header->computeChainDataLength() : 0;
@@ -446,11 +559,26 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionPureAckCounter) {
   updateConnection(
       *conn, folly::none, packet2.packet, TimePoint(), getEncodedSize(packet));
   EXPECT_EQ(1, conn->outstandingPureAckPacketsCount);
+
+  // verify QLogger contains correct packet information
+  EXPECT_EQ(2, qLogger->logs.size());
+  auto p2 = std::move(qLogger->logs[1]);
+  auto event2 = dynamic_cast<QLogPacketEvent*>(p2.get());
+  EXPECT_EQ(event2->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event2->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event2->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event2->frames.size(), 1);
+  auto frame = static_cast<RstStreamFrameLog*>(event2->frames[0].get());
+  EXPECT_EQ(frame->streamId, 1);
+  EXPECT_EQ(frame->errorCode, GenericApplicationErrorCode::UNKNOWN);
+  EXPECT_EQ(frame->offset, 0);
 }
 
 TEST_F(QuicTransportFunctionsTest, TestPaddingPureAckPacketIsStillPureAck) {
   auto conn = createConn();
-
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   auto packetEncodedSize =
       packet.header ? packet.header->computeChainDataLength() : 0;
@@ -463,10 +591,22 @@ TEST_F(QuicTransportFunctionsTest, TestPaddingPureAckPacketIsStillPureAck) {
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
   EXPECT_EQ(1, conn->outstandingPureAckPacketsCount);
+
+  // verify QLogger contains correct packet and frames information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+  EXPECT_EQ(event->frames.size(), 2);
 }
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionHandshakeCounter) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto stream = conn->streamManager->createNextBidirectionalStream().value();
   writeDataToQuicStream(*stream, nullptr, true);
   EXPECT_EQ(0, conn->outstandingHandshakePacketsCount);
@@ -481,6 +621,22 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionHandshakeCounter) {
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
   EXPECT_EQ(1, conn->outstandingHandshakePacketsCount);
 
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p1 = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p1.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, packetEncodedSize);
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event->frames.size(), 1);
+  auto frame = static_cast<CryptoFrameLog*>(event->frames[0].get());
+  EXPECT_EQ(frame->offset, 0);
+  EXPECT_EQ(frame->len, 0);
+
   auto nonHandshake = buildEmptyPacket(*conn, PacketNumberSpace::AppData);
   packetEncodedSize =
       nonHandshake.header ? nonHandshake.header->computeChainDataLength() : 0;
@@ -497,11 +653,27 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionHandshakeCounter) {
       nonHandshake.packet,
       TimePoint(),
       getEncodedSize(packet));
+  // verify QLogger contains correct packet information
+  EXPECT_EQ(2, qLogger->logs.size());
+  auto p2 = std::move(qLogger->logs[1]);
+  auto event2 = dynamic_cast<QLogPacketEvent*>(p2.get());
+  EXPECT_EQ(event2->packetType, toString(LongHeader::Types::ZeroRtt));
+  EXPECT_EQ(event2->packetSize, packetEncodedSize);
+  EXPECT_EQ(event2->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event2->frames.size(), 1);
+  auto gotStreamFrame = static_cast<StreamFrameLog*>(event2->frames[0].get());
+  EXPECT_EQ(gotStreamFrame->streamId, stream1->id);
+  EXPECT_EQ(gotStreamFrame->offset, 0);
+  EXPECT_EQ(gotStreamFrame->len, 0);
+  EXPECT_EQ(gotStreamFrame->fin, true);
   EXPECT_EQ(1, conn->outstandingHandshakePacketsCount);
 }
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionForOneRttCryptoData) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto stream = conn->streamManager->createNextBidirectionalStream().value();
   writeDataToQuicStream(*stream, nullptr, true);
   EXPECT_EQ(0, conn->outstandingHandshakePacketsCount);
@@ -515,6 +687,23 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionForOneRttCryptoData) {
   packet.packet.frames.push_back(WriteCryptoFrame(0, 0));
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
+
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, kShortHeaderPacketType);
+  EXPECT_EQ(event->packetSize, packetEncodedSize);
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event->frames.size(), 1);
+  auto frame = static_cast<CryptoFrameLog*>(event->frames[0].get());
+  EXPECT_EQ(frame->offset, 0);
+  EXPECT_EQ(frame->len, 0);
+
   EXPECT_EQ(0, conn->outstandingHandshakePacketsCount);
   EXPECT_EQ(1, conn->outstandingPackets.size());
 
@@ -534,12 +723,30 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionForOneRttCryptoData) {
       nonHandshake.packet,
       TimePoint(),
       getEncodedSize(packet));
+
+  // verify QLogger contains correct packet information
+  EXPECT_EQ(2, qLogger->logs.size());
+  auto p2 = std::move(qLogger->logs[1]);
+  auto event2 = dynamic_cast<QLogPacketEvent*>(p2.get());
+  EXPECT_EQ(event2->packetType, toString(LongHeader::Types::ZeroRtt));
+  EXPECT_EQ(event2->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event2->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event2->frames.size(), 1);
+  auto frame2 = static_cast<StreamFrameLog*>(event2->frames[0].get());
+  EXPECT_EQ(frame2->streamId, stream1->id);
+  EXPECT_EQ(frame2->offset, 0);
+  EXPECT_EQ(frame2->len, 0);
+  EXPECT_EQ(frame2->fin, true);
+
   EXPECT_EQ(0, conn->outstandingHandshakePacketsCount);
   EXPECT_EQ(2, conn->outstandingPackets.size());
 }
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithPureAck) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   auto mockCongestionController = std::make_unique<MockCongestionController>();
   auto rawController = mockCongestionController.get();
@@ -555,10 +762,24 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithPureAck) {
   EXPECT_TRUE(
       getFirstOutstandingPacket(*conn, PacketNumberSpace::Handshake)->pureAck);
   EXPECT_EQ(0, conn->lossState.totalBytesAcked);
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  // verify QLogger contains correct packet information
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(event->frames.size(), 1);
+  auto frame = static_cast<WriteAckFrameLog*>(event->frames[0].get());
+  EXPECT_EQ(frame->ackBlocks.size(), 1);
 }
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithBytesStats) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   conn->lossState.totalBytesSent = 13579;
   conn->lossState.totalBytesAcked = 8642;
@@ -568,6 +789,17 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithBytesStats) {
   conn->lossState.totalBytesSentAtLastAck = 10000;
   conn->lossState.totalBytesAckedAtLastAck = 5000;
   updateConnection(*conn, folly::none, packet.packet, TimePoint(), 555);
+
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto event = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(event->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(event->packetSize, 555);
+  EXPECT_EQ(event->eventType, QLogEventType::PacketSent);
+
   EXPECT_EQ(
       13579 + 555,
       getFirstOutstandingPacket(*conn, PacketNumberSpace::Handshake)
@@ -594,6 +826,7 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithBytesStats) {
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithCloneResult) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto mockCongestionController = std::make_unique<MockCongestionController>();
   auto rawCongestionController = mockCongestionController.get();
   conn->congestionController = std::move(mockCongestionController);
@@ -605,7 +838,8 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithCloneResult) {
   MockClock::mockNow = [=]() { return thisMoment; };
   RegularQuicWritePacket writePacket(std::move(shortHeader));
   // Add a dummy frame into the packet so we don't treat it as pureAck
-  MaxDataFrame maxDataFrame(1000 + conn->flowControlState.advertisedMaxOffset);
+  auto maxDataAmt = 1000 + conn->flowControlState.advertisedMaxOffset;
+  MaxDataFrame maxDataFrame(maxDataAmt);
   conn->pendingEvents.connWindowUpdate = true;
   writePacket.frames.push_back(std::move(maxDataFrame));
   PacketEvent event = 1;
@@ -615,6 +849,20 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithCloneResult) {
   EXPECT_CALL(*rawCongestionController, onPacketSent(_)).Times(1);
   updateConnection(
       *conn, event, std::move(writePacket), MockClock::now(), 1500);
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto qLogEvent = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(qLogEvent->packetType, kShortHeaderPacketType);
+  EXPECT_EQ(qLogEvent->packetSize, 1500);
+  EXPECT_EQ(qLogEvent->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(qLogEvent->frames.size(), 1);
+  auto frame = static_cast<MaxDataFrameLog*>(qLogEvent->frames[0].get());
+  EXPECT_EQ(frame->maximumData, maxDataAmt);
   EXPECT_EQ(
       futureMoment,
       getLastOutstandingPacket(*conn, PacketNumberSpace::AppData)->time);
@@ -630,6 +878,7 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionWithCloneResult) {
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionStreamWindowUpdate) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   auto packetNum = folly::variant_match(
       packet.packet.header,
@@ -640,12 +889,30 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionStreamWindowUpdate) {
   packet.packet.frames.push_back(std::move(streamWindowUpdate));
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
+
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto qLogEvent = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(qLogEvent->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(qLogEvent->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(qLogEvent->eventType, QLogEventType::PacketSent);
+
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(qLogEvent->frames.size(), 1);
+  auto frame = static_cast<MaxStreamDataFrameLog*>(qLogEvent->frames[0].get());
+  EXPECT_EQ(frame->streamId, stream->id);
+  EXPECT_EQ(frame->maximumData, 0);
+
   EXPECT_EQ(packetNum, *stream->latestMaxStreamDataPacket);
   EXPECT_FALSE(conn->latestMaxDataPacket.hasValue());
 }
 
 TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionConnWindowUpdate) {
   auto conn = createConn();
+  conn->qLogger = std::make_shared<quic::FileQLogger>();
   auto packet = buildEmptyPacket(*conn, PacketNumberSpace::Handshake);
   auto packetNum = folly::variant_match(
       packet.packet.header,
@@ -656,6 +923,21 @@ TEST_F(QuicTransportFunctionsTest, TestUpdateConnectionConnWindowUpdate) {
   packet.packet.frames.push_back(std::move(connWindowUpdate));
   updateConnection(
       *conn, folly::none, packet.packet, TimePoint(), getEncodedSize(packet));
+
+  // verify QLogger contains correct packet information
+  std::shared_ptr<quic::FileQLogger> qLogger =
+      std::dynamic_pointer_cast<quic::FileQLogger>(conn->qLogger);
+  EXPECT_EQ(1, qLogger->logs.size());
+  auto p = std::move(qLogger->logs[0]);
+  auto qLogEvent = dynamic_cast<QLogPacketEvent*>(p.get());
+  EXPECT_EQ(qLogEvent->packetType, toString(LongHeader::Types::Handshake));
+  EXPECT_EQ(qLogEvent->packetSize, getEncodedSize(packet));
+  EXPECT_EQ(qLogEvent->eventType, QLogEventType::PacketSent);
+  // verify QLogger contains correct frame information
+  EXPECT_EQ(qLogEvent->frames.size(), 1);
+  auto frame = static_cast<MaxDataFrameLog*>(qLogEvent->frames[0].get());
+  EXPECT_EQ(frame->maximumData, conn->flowControlState.advertisedMaxOffset);
+
   EXPECT_FALSE(stream->latestMaxStreamDataPacket.hasValue());
   EXPECT_EQ(packetNum, *conn->latestMaxDataPacket);
 }

quic/client/CMakeLists.txt

@@ -27,6 +27,7 @@ add_dependencies(
   mvfst_flowcontrol
   mvfst_happyeyeballs
   mvfst_loss
+  mvfst_qlogger
   mvfst_state_ack_handler
   mvfst_state_pacing_functions
   mvfst_transport
@@ -38,6 +39,7 @@ target_link_libraries(
   mvfst_flowcontrol
   mvfst_happyeyeballs
   mvfst_loss
+  mvfst_qlogger
   mvfst_state_ack_handler
   mvfst_state_pacing_functions
   mvfst_transport

quic/client/QuicClientTransport.cpp

@@ -214,6 +214,9 @@ void QuicClientTransport::processPacketData(
       protectionLevel == ProtectionType::KeyPhaseOne;
 
   auto& regularPacket = *regularOptional;
+  if (conn_->qLogger) {
+    conn_->qLogger->add(regularPacket, packetSize);
+  }
   if (!isProtectedPacket) {
     for (auto& quicFrame : regularPacket.frames) {
       auto isPadding = boost::get<PaddingFrame>(&quicFrame);
@@ -227,7 +230,6 @@ void QuicClientTransport::processPacketData(
       }
     }
   }
-
   QUIC_TRACE(packet_recvd, *conn_, toString(pnSpace), packetNum, packetSize);
 
   // We got a packet that was not the version negotiation packet, that means

quic/logging/CMakeLists.txt

@@ -3,6 +3,38 @@
 # This source code is licensed under the MIT license found in the
 # LICENSE file in the root directory of this source tree.
 
+add_library(
+  mvfst_qlogger STATIC
+  QLogger.cpp
+  QLoggerTypes.cpp
+  FileQLogger.cpp
+)
+
+target_include_directories(
+  mvfst_qlogger PUBLIC
+  $<BUILD_INTERFACE:${QUIC_FBCODE_ROOT}>
+  $<INSTALL_INTERFACE:include/>
+)
+
+target_compile_options(
+  mvfst_qlogger
+  PRIVATE
+  ${_QUIC_COMMON_COMPILE_OPTIONS}
+)
+
+add_dependencies(
+  mvfst_qlogger
+  mvfst_codec_types
+  mvfst_state_machine
+)
+
+target_link_libraries(
+  mvfst_qlogger PUBLIC
+  Folly::folly
+  ${LIBFIZZ_LIBRARY}
+  mvfst_codec_types
+)
+
 file(
   GLOB_RECURSE QUIC_API_HEADERS_TOINSTALL
   RELATIVE ${CMAKE_CURRENT_SOURCE_DIR}
@@ -14,4 +46,10 @@ foreach(header ${QUIC_API_HEADERS_TOINSTALL})
   install(FILES ${header} DESTINATION include/quic/logging/${header_dir})
 endforeach()
 
+install(
+  TARGETS mvfst_qlogger
+  EXPORT mvfst-exports
+  DESTINATION lib
+)
+
 add_subdirectory(test)

quic/logging/QLogger.cpp

@@ -22,7 +22,7 @@ std::unique_ptr<QLogPacketEvent> createPacketEvent(
       regularPacket.header,
       [](const auto& h) { return h.getPacketSequenceNum(); });
   event->packetSize = packetSize;
-  event->eventType = EventType::PacketReceived;
+  event->eventType = QLogEventType::PacketReceived;
   event->packetType = folly::variant_match(
       regularPacket.header,
       [](const LongHeader& header) { return toString(header.getHeaderType()); },
@@ -143,7 +143,7 @@ std::unique_ptr<QLogPacketEvent> createPacketEvent(
       writePacket.header,
       [](const auto& h) { return h.getPacketSequenceNum(); });
   event->packetSize = packetSize;
-  event->eventType = EventType::PacketSent;
+  event->eventType = QLogEventType::PacketSent;
   event->packetType = folly::variant_match(
       writePacket.header,
       [](const LongHeader& header) { return toString(header.getHeaderType()); },
@@ -262,7 +262,7 @@ std::unique_ptr<QLogVersionNegotiationEvent> createPacketEvent(
   auto event = std::make_unique<QLogVersionNegotiationEvent>();
   event->packetSize = packetSize;
   event->eventType =
-      isPacketRecvd ? EventType::PacketReceived : EventType::PacketSent;
+      isPacketRecvd ? QLogEventType::PacketReceived : QLogEventType::PacketSent;
   event->packetType = kVersionNegotiationPacketType.str();
   event->versionLog = std::make_unique<VersionNegotiationLog>(
       VersionNegotiationLog(versionPacket.versions));

quic/logging/QLoggerTypes.cpp

@@ -248,11 +248,11 @@ folly::dynamic QLogVersionNegotiationEvent::toDynamic() const {
   return d;
 }
 
-std::string toString(EventType type) {
+std::string toString(QLogEventType type) {
   switch (type) {
-    case EventType::PacketSent:
+    case QLogEventType::PacketSent:
       return "PACKET_SENT";
-    case EventType::PacketReceived:
+    case QLogEventType::PacketReceived:
       return "PACKET_RECEIVED";
   }
   LOG(WARNING) << "toString has unhandled QLog event type";

quic/logging/QLoggerTypes.h

@@ -292,12 +292,12 @@ class VersionNegotiationLog {
   folly::dynamic toDynamic() const;
 };
 
-enum class EventType : uint32_t {
+enum class QLogEventType : uint32_t {
   PacketReceived,
   PacketSent,
 };
 
-std::string toString(EventType type);
+std::string toString(QLogEventType type);
 
 class QLogEvent {
  public:
@@ -314,7 +314,7 @@ class QLogPacketEvent : public QLogEvent {
   std::string packetType;
   PacketNum packetNum{0};
   uint64_t packetSize{0};
-  EventType eventType;
+  QLogEventType eventType;
 
   folly::dynamic toDynamic() const override;
 };
@@ -326,11 +326,11 @@ class QLogVersionNegotiationEvent : public QLogEvent {
   std::unique_ptr<VersionNegotiationLog> versionLog;
   std::string packetType;
   uint64_t packetSize{0};
-  EventType eventType;
+  QLogEventType eventType;
 
   folly::dynamic toDynamic() const override;
 };
 
-std::string toString(EventType type);
+std::string toString(QLogEventType type);
 
 } // namespace quic

quic/logging/test/QLoggerTest.cpp

@@ -41,24 +41,17 @@ TEST_F(QLoggerTest, TestRegularWritePacket) {
   EXPECT_EQ(gotObject.streamId, streamId);
   EXPECT_EQ(gotObject.offset, offset);
   EXPECT_EQ(gotObject.fin, fin);
+  EXPECT_EQ(gotEvent->eventType, QLogEventType::PacketSent);
 }
 
 TEST_F(QLoggerTest, TestRegularPacket) {
-  auto expected = folly::IOBuf::copyBuffer("hello");
+  auto headerIn =
-  auto packet = createStreamPacket(
+      ShortHeader(ProtectionType::KeyPhaseZero, getTestConnectionId(1), 1);
-      getTestConnectionId(0),
+  RegularQuicPacket regularQuicPacket(headerIn);
-      getTestConnectionId(1),
+  ReadStreamFrame frame(streamId, offset, fin);
-      1,
+
-      streamId,
+  regularQuicPacket.frames.emplace_back(std::move(frame));
-      *expected,
-      0 /* cipherOverhead */,
-      0 /* largestAcked */,
-      folly::none /* longHeaderOverride */,
-      fin,
-      folly::none /* shortHeaderOverride */,
-      offset);
 
-  auto regularQuicPacket = packet.packet;
   FileQLogger q;
   q.add(regularQuicPacket, 10);
 
@@ -69,6 +62,7 @@ TEST_F(QLoggerTest, TestRegularPacket) {
   EXPECT_EQ(gotObject.streamId, streamId);
   EXPECT_EQ(gotObject.offset, offset);
   EXPECT_EQ(gotObject.fin, fin);
+  EXPECT_EQ(gotEvent->eventType, QLogEventType::PacketReceived);
 }
 
 TEST_F(QLoggerTest, TestVersionNegotiationPacket) {
@@ -85,6 +79,57 @@ TEST_F(QLoggerTest, TestVersionNegotiationPacket) {
 }
 
 TEST_F(QLoggerTest, RegularPacketFollyDynamic) {
+  folly::dynamic expected = folly::parseJson(
+      R"({
+        "traces": [
+          {"event_fields":[
+              "CATEGORY",
+              "EVENT_TYPE",
+              "TRIGGER",
+              "DATA"
+            ],
+            "events":[
+               [
+                "TRANSPORT",
+                "PACKET_RECEIVED",
+                "DEFAULT",
+                {
+                  "packet_type": "1RTT",
+                  "header":{
+                    "packet_number":1,
+                    "packet_size":10
+                },
+                  "frames":[
+                    {"frame_type":"STREAM",
+                    "id":10,
+                    "fin":true,
+                    "length":0,
+                    "offset":0
+                    }
+                  ]
+                }
+              ]
+            ]
+          }
+        ]
+      })");
+
+  auto headerIn =
+      ShortHeader(ProtectionType::KeyPhaseZero, getTestConnectionId(1), 1);
+  RegularQuicPacket regularQuicPacket(headerIn);
+  ReadStreamFrame frame(streamId, offset, fin);
+
+  regularQuicPacket.frames.emplace_back(std::move(frame));
+
+  FileQLogger q;
+  q.add(regularQuicPacket, 10);
+
+  folly::dynamic gotDynamic = q.toDynamic();
+
+  EXPECT_EQ(expected, gotDynamic);
+}
+
+TEST_F(QLoggerTest, RegularWritePacketFollyDynamic) {
   folly::dynamic expected = folly::parseJson(
       R"({
         "traces": [
@@ -103,7 +148,8 @@ TEST_F(QLoggerTest, RegularPacketFollyDynamic) {
                   "packet_type": "INITIAL",
                   "header":{
                     "packet_number":10,
-                    "packet_size":10},
+                    "packet_size":10
+                },
                   "frames":[
                     {"frame_type":"STREAM",
                     "id":10,

quic/server/CMakeLists.txt

@@ -35,6 +35,7 @@ add_dependencies(
   mvfst_codec
   mvfst_codec_types
   mvfst_handshake
+  mvfst_qlogger
   mvfst_transport
 )
 
@@ -46,6 +47,7 @@ target_link_libraries(
   mvfst_codec
   mvfst_codec_types
   mvfst_handshake
+  mvfst_qlogger
   mvfst_transport
 )
 

quic/server/state/ServerStateMachine.cpp

@@ -624,6 +624,9 @@ void onServerReadDataFromOpen(
       conn.serverConnIdParams->clientConnId = *conn.clientConnectionId;
       conn.readCodec->setServerConnectionId(*conn.serverConnectionId);
     }
+    if (conn.qLogger) {
+      conn.qLogger->add(regularPacket, packetSize);
+    }
     QUIC_TRACE(packet_recvd, conn, packetNum, packetSize);
     // We assume that the higher layer takes care of validating that the version
     // is supported.
@@ -988,7 +991,9 @@ void onServerReadDataFromClosed(
   auto pnSpace = folly::variant_match(
       regularOptional->header,
       [](const auto& h) { return h.getPacketNumberSpace(); });
-
+  if (conn.qLogger) {
+    conn.qLogger->add(regularPacket, packetSize);
+  }
   QUIC_TRACE(packet_recvd, conn, packetNum, packetSize);
 
   bool isProtectedPacket = protectionLevel == ProtectionType::ZeroRtt ||

quic/state/StateData.h

@@ -19,6 +19,7 @@
 #include <quic/codec/QuicWriteCodec.h>
 #include <quic/codec/Types.h>
 #include <quic/handshake/HandshakeLayer.h>
+#include <quic/logging/QLogger.h>
 #include <quic/state/AckStates.h>
 #include <quic/state/QuicStreamManager.h>
 #include <quic/state/QuicTransportStatsCallback.h>
@@ -573,6 +574,9 @@ struct QuicConnectionStateBase {
   // Logger for this connection.
   std::shared_ptr<Logger> logger;
 
+  // QLogger for this connection
+  std::shared_ptr<QLogger> qLogger;
+
   // Track stats for various server events
   QuicTransportStatsCallback* infoCallback{nullptr};