Fix packet number length computation
This bug was found when debugging a flake in our end to end test that can occur with high packet loss. The issue is that the current code can lead to the client and server falling out of sync, and all packets failing to decrypt forever. If the client uses a packet number length that is too small, and the server misinterprets the packet number when decompressing it, decryption fails. The issue is that we were previously only tacking the unacked packets into account when computing the packet number length. Except, when we declare sent packets as lost, we no longer treat them as unacked for the purpose of packet number length computation. In the failing test, I saw that the client was sending ENCRYPTION_FORWARD_SECURE packet numbers in the range [256,512) with a packet number length of 1, and the server had never decrypted a single packet (from that packet number space) so it would decompress them in the range [0, 256). The fix is to take the min packet number between what we had and what the peer acknowledged. This ensures that, even if many packets are lost, we don't compress information without a positive signal from the peer. I've confirmed that the fix prevents the e2e test flake.
This CL also adds some additional debug logs that were instrumental to finding this bug.
Fix sent packet number computation, protected by gfe2_reloadable_flag_quic_fix_packet_number_length
PiperOrigin-RevId: 319904609
Change-Id: Ib05b295323043ae0645b4580f8252e9015d42ce1
diff --git a/quic/core/http/quic_spdy_session_test.cc b/quic/core/http/quic_spdy_session_test.cc
index dd7068f..fea8541 100644
--- a/quic/core/http/quic_spdy_session_test.cc
+++ b/quic/core/http/quic_spdy_session_test.cc
@@ -54,12 +54,13 @@
using spdy::SpdyPriority;
using spdy::SpdyPriorityIR;
using spdy::SpdySerializedFrame;
-using testing::_;
-using testing::AtLeast;
-using testing::InSequence;
-using testing::Invoke;
-using testing::Return;
-using testing::StrictMock;
+using ::testing::_;
+using ::testing::AnyNumber;
+using ::testing::AtLeast;
+using ::testing::InSequence;
+using ::testing::Invoke;
+using ::testing::Return;
+using ::testing::StrictMock;
namespace quic {
namespace test {
@@ -865,6 +866,7 @@
EXPECT_CALL(*stream2, OnCanWrite()).WillOnce(Invoke([this, stream2]() {
session_.SendStreamData(stream2);
}));
+ EXPECT_CALL(*send_algorithm, GetCongestionWindow()).Times(AnyNumber());
EXPECT_CALL(*send_algorithm, CanSend(_)).WillOnce(Return(true));
EXPECT_CALL(*stream6, OnCanWrite()).WillOnce(Invoke([this, stream6]() {
session_.SendStreamData(stream6);
diff --git a/quic/core/quic_connection.cc b/quic/core/quic_connection.cc
index 939e12b..2fff73a 100644
--- a/quic/core/quic_connection.cc
+++ b/quic/core/quic_connection.cc
@@ -2771,7 +2771,7 @@
// The packet number length must be updated after OnPacketSent, because it
// may change the packet number length in packet.
packet_creator_.UpdatePacketNumberLength(
- sent_packet_manager_.GetLeastUnacked(),
+ sent_packet_manager_.GetLeastPacketAwaitedByPeer(encryption_level_),
sent_packet_manager_.EstimateMaxPacketsInFlight(max_packet_length()));
stats_.bytes_sent += result.bytes_written;
@@ -3039,7 +3039,8 @@
// immediate ACK.
const QuicPacketCount num_packet_numbers_to_skip = 1;
packet_creator_.SkipNPacketNumbers(
- num_packet_numbers_to_skip, sent_packet_manager_.GetLeastUnacked(),
+ num_packet_numbers_to_skip,
+ sent_packet_manager_.GetLeastPacketAwaitedByPeer(encryption_level_),
sent_packet_manager_.EstimateMaxPacketsInFlight(max_packet_length()));
previous_created_packet_number += num_packet_numbers_to_skip;
if (debug_visitor_ != nullptr) {
@@ -3130,13 +3131,28 @@
void QuicConnection::SetDefaultEncryptionLevel(EncryptionLevel level) {
QUIC_DVLOG(1) << ENDPOINT << "Setting default encryption level from "
<< encryption_level_ << " to " << level;
- if (level != encryption_level_ && packet_creator_.HasPendingFrames()) {
+ const bool changing_level = level != encryption_level_;
+ if (changing_level && packet_creator_.HasPendingFrames()) {
// Flush all queued frames when encryption level changes.
ScopedPacketFlusher flusher(this);
packet_creator_.FlushCurrentPacket();
}
encryption_level_ = level;
packet_creator_.set_encryption_level(level);
+
+ if (!sent_packet_manager_.fix_packet_number_length()) {
+ return;
+ }
+ QUIC_RELOADABLE_FLAG_COUNT_N(quic_fix_packet_number_length, 2, 2);
+
+ if (!changing_level) {
+ return;
+ }
+ // The least packet awaited by the peer depends on the encryption level so
+ // we recalculate it here.
+ packet_creator_.UpdatePacketNumberLength(
+ sent_packet_manager_.GetLeastPacketAwaitedByPeer(encryption_level_),
+ sent_packet_manager_.EstimateMaxPacketsInFlight(max_packet_length()));
}
void QuicConnection::SetDecrypter(EncryptionLevel level,
diff --git a/quic/core/quic_framer.cc b/quic/core/quic_framer.cc
index 1398965..0ad2e91 100644
--- a/quic/core/quic_framer.cc
+++ b/quic/core/quic_framer.cc
@@ -1712,6 +1712,7 @@
quiche::QuicheStringPiece associated_data;
std::vector<char> ad_storage;
+ QuicPacketNumber base_packet_number;
if (header->form == IETF_QUIC_SHORT_HEADER_PACKET ||
header->long_packet_type != VERSION_NEGOTIATION) {
DCHECK(header->form == IETF_QUIC_SHORT_HEADER_PACKET ||
@@ -1719,7 +1720,6 @@
header->long_packet_type == HANDSHAKE ||
header->long_packet_type == ZERO_RTT_PROTECTED);
// Process packet number.
- QuicPacketNumber base_packet_number;
if (supports_multiple_packet_number_spaces_) {
PacketNumberSpace pn_space = GetPacketNumberSpace(*header);
if (pn_space == NUM_PACKET_NUMBER_SPACES) {
@@ -1832,7 +1832,9 @@
has_decryption_key);
set_detailed_error(quiche::QuicheStrCat(
"Unable to decrypt ", EncryptionLevelToString(decryption_level),
- " payload",
+ " payload with reconstructed packet number ",
+ header->packet_number.ToString(), " (largest decrypted was ",
+ base_packet_number.ToString(), ")",
has_decryption_key || !version_.KnowsWhichDecrypterToUse()
? ""
: " (missing key)",
diff --git a/quic/core/quic_packet_creator.cc b/quic/core/quic_packet_creator.cc
index cf5540e..2a9d92c 100644
--- a/quic/core/quic_packet_creator.cc
+++ b/quic/core/quic_packet_creator.cc
@@ -243,12 +243,24 @@
return;
}
- DCHECK_LE(least_packet_awaited_by_peer, packet_.packet_number + 1);
+ const QuicPacketNumber next_packet_number = NextSendingPacketNumber();
+ DCHECK_LE(least_packet_awaited_by_peer, next_packet_number);
const uint64_t current_delta =
- packet_.packet_number + 1 - least_packet_awaited_by_peer;
+ next_packet_number - least_packet_awaited_by_peer;
const uint64_t delta = std::max(current_delta, max_packets_in_flight);
- packet_.packet_number_length =
+ const QuicPacketNumberLength packet_number_length =
QuicFramer::GetMinPacketNumberLength(QuicPacketNumber(delta * 4));
+ if (packet_.packet_number_length == packet_number_length) {
+ return;
+ }
+ QUIC_DLOG(INFO) << ENDPOINT << "Updating packet number length from "
+ << static_cast<int>(packet_.packet_number_length) << " to "
+ << static_cast<int>(packet_number_length)
+ << ", least_packet_awaited_by_peer: "
+ << least_packet_awaited_by_peer
+ << " max_packets_in_flight: " << max_packets_in_flight
+ << " next_packet_number: " << next_packet_number;
+ packet_.packet_number_length = packet_number_length;
}
void QuicPacketCreator::SkipNPacketNumbers(
diff --git a/quic/core/quic_packet_number.cc b/quic/core/quic_packet_number.cc
index 6e6804b..d25b34d 100644
--- a/quic/core/quic_packet_number.cc
+++ b/quic/core/quic_packet_number.cc
@@ -5,6 +5,7 @@
#include <algorithm>
#include "net/third_party/quiche/src/quic/core/quic_packet_number.h"
+#include "net/third_party/quiche/src/common/platform/api/quiche_text_utils.h"
namespace quic {
@@ -93,12 +94,15 @@
return *this;
}
-std::ostream& operator<<(std::ostream& os, const QuicPacketNumber& p) {
- if (p.IsInitialized()) {
- os << p.packet_number_;
- } else {
- os << "uninitialized";
+std::string QuicPacketNumber::ToString() const {
+ if (!IsInitialized()) {
+ return "uninitialized";
}
+ return quiche::QuicheTextUtils::Uint64ToString(ToUint64());
+}
+
+std::ostream& operator<<(std::ostream& os, const QuicPacketNumber& p) {
+ os << p.ToString();
return os;
}
diff --git a/quic/core/quic_packet_number.h b/quic/core/quic_packet_number.h
index 18e78bb..e977feb 100644
--- a/quic/core/quic_packet_number.h
+++ b/quic/core/quic_packet_number.h
@@ -67,6 +67,9 @@
// REQUIRES: IsInitialized() == true && ToUint64() >= |delta|.
QuicPacketNumber& operator-=(uint64_t delta);
+ // Human-readable representation suitable for logging.
+ std::string ToString() const;
+
QUIC_EXPORT_PRIVATE friend std::ostream& operator<<(
std::ostream& os,
const QuicPacketNumber& p);
diff --git a/quic/core/quic_sent_packet_manager.cc b/quic/core/quic_sent_packet_manager.cc
index fd083eb..11f65cf 100644
--- a/quic/core/quic_sent_packet_manager.cc
+++ b/quic/core/quic_sent_packet_manager.cc
@@ -1493,6 +1493,31 @@
QuicUtils::GetPacketNumberSpace(decrypted_packet_level));
}
+QuicPacketNumber QuicSentPacketManager::GetLeastPacketAwaitedByPeer(
+ EncryptionLevel encryption_level) const {
+ if (!fix_packet_number_length_) {
+ return GetLeastUnacked();
+ }
+ QUIC_RELOADABLE_FLAG_COUNT_N(quic_fix_packet_number_length, 1, 2);
+ QuicPacketNumber largest_acked;
+ if (supports_multiple_packet_number_spaces()) {
+ largest_acked = GetLargestAckedPacket(encryption_level);
+ } else {
+ largest_acked = GetLargestObserved();
+ }
+ if (!largest_acked.IsInitialized()) {
+ // If no packets have been acked, return the first sent packet to ensure
+ // we use a large enough packet number length.
+ return FirstSendingPacketNumber();
+ }
+ QuicPacketNumber least_awaited = largest_acked + 1;
+ QuicPacketNumber least_unacked = GetLeastUnacked();
+ if (least_unacked.IsInitialized() && least_unacked < least_awaited) {
+ least_awaited = least_unacked;
+ }
+ return least_awaited;
+}
+
QuicPacketNumber QuicSentPacketManager::GetLargestPacketPeerKnowsIsAcked(
EncryptionLevel decrypted_packet_level) const {
DCHECK(supports_multiple_packet_number_spaces());
diff --git a/quic/core/quic_sent_packet_manager.h b/quic/core/quic_sent_packet_manager.h
index b69bf5c..508286a 100644
--- a/quic/core/quic_sent_packet_manager.h
+++ b/quic/core/quic_sent_packet_manager.h
@@ -311,6 +311,12 @@
return unacked_packets_.largest_sent_packet();
}
+ // Returns the lowest of the largest acknowledged packet and the least
+ // unacked packet. This is designed to be used when computing the packet
+ // number length to send.
+ QuicPacketNumber GetLeastPacketAwaitedByPeer(
+ EncryptionLevel encryption_level) const;
+
QuicPacketNumber GetLargestPacketPeerKnowsIsAcked(
EncryptionLevel decrypted_packet_level) const;
@@ -413,6 +419,8 @@
void OnUserAgentIdKnown() { loss_algorithm_->OnUserAgentIdKnown(); }
+ bool fix_packet_number_length() const { return fix_packet_number_length_; }
+
private:
friend class test::QuicConnectionPeer;
friend class test::QuicSentPacketManagerPeer;
@@ -664,6 +672,8 @@
float pto_multiplier_without_rtt_samples_;
const bool fix_pto_timeout_ = GetQuicReloadableFlag(quic_fix_pto_timeout);
+ const bool fix_packet_number_length_ =
+ GetQuicReloadableFlag(quic_fix_packet_number_length);
};
} // namespace quic
diff --git a/quic/core/quic_session.cc b/quic/core/quic_session.cc
index 79ef9bd..a1ba52b 100644
--- a/quic/core/quic_session.cc
+++ b/quic/core/quic_session.cc
@@ -1582,7 +1582,7 @@
}
void QuicSession::DiscardOldEncryptionKey(EncryptionLevel level) {
- QUIC_DVLOG(1) << ENDPOINT << "Discard keys of " << level;
+ QUIC_DLOG(INFO) << ENDPOINT << "Discarding " << level << " keys";
if (connection()->version().handshake_protocol == PROTOCOL_TLS1_3) {
connection()->RemoveEncrypter(level);
}
@@ -1596,10 +1596,11 @@
case ENCRYPTION_ZERO_RTT:
break;
case ENCRYPTION_FORWARD_SECURE:
- QUIC_BUG << "Tries to drop 1-RTT keys";
+ QUIC_BUG << ENDPOINT << "Discarding 1-RTT keys is not allowed";
break;
default:
- QUIC_BUG << "Unknown encryption level: " << level;
+ QUIC_BUG << ENDPOINT
+ << "Cannot discard keys for unknown encryption level: " << level;
}
}
diff --git a/quic/core/quic_session_test.cc b/quic/core/quic_session_test.cc
index 15eaf50..8459269 100644
--- a/quic/core/quic_session_test.cc
+++ b/quic/core/quic_session_test.cc
@@ -44,14 +44,15 @@
using spdy::kV3HighestPriority;
using spdy::SpdyPriority;
-using testing::_;
-using testing::AtLeast;
-using testing::InSequence;
-using testing::Invoke;
-using testing::NiceMock;
-using testing::Return;
-using testing::StrictMock;
-using testing::WithArg;
+using ::testing::_;
+using ::testing::AnyNumber;
+using ::testing::AtLeast;
+using ::testing::InSequence;
+using ::testing::Invoke;
+using ::testing::NiceMock;
+using ::testing::Return;
+using ::testing::StrictMock;
+using ::testing::WithArg;
namespace quic {
namespace test {
@@ -1202,6 +1203,7 @@
EXPECT_CALL(*stream2, OnCanWrite()).WillOnce(Invoke([this, stream2]() {
session_.SendStreamData(stream2);
}));
+ EXPECT_CALL(*send_algorithm, GetCongestionWindow()).Times(AnyNumber());
EXPECT_CALL(*send_algorithm, CanSend(_)).WillOnce(Return(true));
EXPECT_CALL(*stream6, OnCanWrite()).WillOnce(Invoke([this, stream6]() {
session_.SendStreamData(stream6);
diff --git a/quic/core/quic_types.cc b/quic/core/quic_types.cc
index a52571e..fb2e9c8 100644
--- a/quic/core/quic_types.cc
+++ b/quic/core/quic_types.cc
@@ -128,6 +128,41 @@
case x: \
return #x;
+std::string QuicFrameTypeToString(QuicFrameType t) {
+ switch (t) {
+ RETURN_STRING_LITERAL(PADDING_FRAME)
+ RETURN_STRING_LITERAL(RST_STREAM_FRAME)
+ RETURN_STRING_LITERAL(CONNECTION_CLOSE_FRAME)
+ RETURN_STRING_LITERAL(GOAWAY_FRAME)
+ RETURN_STRING_LITERAL(WINDOW_UPDATE_FRAME)
+ RETURN_STRING_LITERAL(BLOCKED_FRAME)
+ RETURN_STRING_LITERAL(STOP_WAITING_FRAME)
+ RETURN_STRING_LITERAL(PING_FRAME)
+ RETURN_STRING_LITERAL(CRYPTO_FRAME)
+ RETURN_STRING_LITERAL(HANDSHAKE_DONE_FRAME)
+ RETURN_STRING_LITERAL(STREAM_FRAME)
+ RETURN_STRING_LITERAL(ACK_FRAME)
+ RETURN_STRING_LITERAL(MTU_DISCOVERY_FRAME)
+ RETURN_STRING_LITERAL(NEW_CONNECTION_ID_FRAME)
+ RETURN_STRING_LITERAL(MAX_STREAMS_FRAME)
+ RETURN_STRING_LITERAL(STREAMS_BLOCKED_FRAME)
+ RETURN_STRING_LITERAL(PATH_RESPONSE_FRAME)
+ RETURN_STRING_LITERAL(PATH_CHALLENGE_FRAME)
+ RETURN_STRING_LITERAL(STOP_SENDING_FRAME)
+ RETURN_STRING_LITERAL(MESSAGE_FRAME)
+ RETURN_STRING_LITERAL(NEW_TOKEN_FRAME)
+ RETURN_STRING_LITERAL(RETIRE_CONNECTION_ID_FRAME)
+ RETURN_STRING_LITERAL(ACK_FREQUENCY_FRAME)
+ RETURN_STRING_LITERAL(NUM_FRAME_TYPES)
+ }
+ return quiche::QuicheStrCat("Unknown(", static_cast<int>(t), ")");
+}
+
+std::ostream& operator<<(std::ostream& os, const QuicFrameType& t) {
+ os << QuicFrameTypeToString(t);
+ return os;
+}
+
std::string QuicIetfFrameTypeString(QuicIetfFrameType t) {
if (IS_IETF_STREAM_FRAME(t)) {
return "IETF_STREAM";
diff --git a/quic/core/quic_types.h b/quic/core/quic_types.h
index 57d0d7e..7d5edb9 100644
--- a/quic/core/quic_types.h
+++ b/quic/core/quic_types.h
@@ -260,6 +260,11 @@
NUM_FRAME_TYPES
};
+// Human-readable string suitable for logging.
+QUIC_EXPORT_PRIVATE std::string QuicFrameTypeToString(QuicFrameType t);
+QUIC_EXPORT_PRIVATE std::ostream& operator<<(std::ostream& os,
+ const QuicFrameType& t);
+
// Ietf frame types. These are defined in the IETF QUIC Specification.
// Explicit values are given in the enum so that we can be sure that
// the symbol will map to the correct stream type.
