Improve logging by adding more ToString methods and refactor
gfe-relnote: change debug-only logs, not flag-protected
PiperOrigin-RevId: 272905128
Change-Id: I501df69f6440adfe13dd92a4a7debd97d2534bd0
diff --git a/quic/core/frames/quic_frame.cc b/quic/core/frames/quic_frame.cc
index b23f9c0..5e85fc0 100644
--- a/quic/core/frames/quic_frame.cc
+++ b/quic/core/frames/quic_frame.cc
@@ -298,7 +298,7 @@
break;
}
case CRYPTO_FRAME: {
- os << "type { CRYPTO_FRAME } " << frame.crypto_frame;
+ os << "type { CRYPTO_FRAME } " << *(frame.crypto_frame);
break;
}
case MTU_DISCOVERY_FRAME: {
diff --git a/quic/core/quic_connection.cc b/quic/core/quic_connection.cc
index ce1e6c4..9cabfc5 100644
--- a/quic/core/quic_connection.cc
+++ b/quic/core/quic_connection.cc
@@ -1368,8 +1368,12 @@
++stats_.num_connectivity_probing_received;
}
- QUIC_DVLOG(1) << ENDPOINT << "Got packet " << last_header_.packet_number
- << " for "
+ QUIC_DVLOG(1) << ENDPOINT << "Got"
+ << (SupportsMultiplePacketNumberSpaces()
+ ? (" " + EncryptionLevelToString(
+ last_decrypted_packet_level_))
+ : "")
+ << " packet " << last_header_.packet_number << " for "
<< GetServerConnectionIdAsRecipient(last_header_, perspective_);
QUIC_DLOG_IF(INFO, current_packet_content_ == SECOND_FRAME_IS_PADDING)
@@ -1447,8 +1451,7 @@
clock_->ApproximateNow(), sent_packet_manager_.GetRttStats());
} else {
QUIC_DLOG(INFO) << ENDPOINT << "Not updating ACK timeout for "
- << QuicUtils::EncryptionLevelToString(
- last_decrypted_packet_level_)
+ << EncryptionLevelToString(last_decrypted_packet_level_)
<< " as we do not have the corresponding encrypter";
}
@@ -1483,12 +1486,12 @@
sent_packet_manager_.GetLeastUnacked() + max_tracked_packets_) {
CloseConnection(
QUIC_TOO_MANY_OUTSTANDING_SENT_PACKETS,
- QuicStrCat(
- "More than ", max_tracked_packets_, " outstanding, least_unacked: ",
- sent_packet_manager_.GetLeastUnacked().ToUint64(),
- ", packets_processed: ", stats_.packets_processed,
- ", last_decrypted_packet_level: ",
- QuicUtils::EncryptionLevelToString(last_decrypted_packet_level_)),
+ QuicStrCat("More than ", max_tracked_packets_,
+ " outstanding, least_unacked: ",
+ sent_packet_manager_.GetLeastUnacked().ToUint64(),
+ ", packets_processed: ", stats_.packets_processed,
+ ", last_decrypted_packet_level: ",
+ EncryptionLevelToString(last_decrypted_packet_level_)),
ConnectionCloseBehavior::SEND_CONNECTION_CLOSE_PACKET);
}
}
@@ -1621,7 +1624,7 @@
// handshake deadlock.
QUIC_DVLOG(1) << ENDPOINT << "Failed to send control frame: " << frame
<< " at encryption level: "
- << QuicUtils::EncryptionLevelToString(encryption_level_);
+ << EncryptionLevelToString(encryption_level_);
return false;
}
ScopedPacketFlusher flusher(this);
@@ -1713,9 +1716,9 @@
QUIC_DVLOG(1) << ENDPOINT << "Received undecryptable packet of length "
<< packet.length() << " with"
<< (has_decryption_key ? "" : "out") << " key at level "
- << QuicUtils::EncryptionLevelToString(decryption_level)
+ << EncryptionLevelToString(decryption_level)
<< " while connection is at encryption level "
- << QuicUtils::EncryptionLevelToString(encryption_level_);
+ << EncryptionLevelToString(encryption_level_);
DCHECK(GetQuicRestartFlag(quic_framer_uses_undecryptable_upcall));
QUIC_RESTART_FLAG_COUNT_N(quic_framer_uses_undecryptable_upcall, 1, 7);
DCHECK(EncryptionLevelIsValid(decryption_level));
@@ -2166,7 +2169,7 @@
QuicFrame updated_ack_frame = GetUpdatedAckFrame();
QUIC_BUG_IF(updated_ack_frame.ack_frame->packets.Empty())
<< ENDPOINT << "Attempted to opportunistically bundle an empty "
- << QuicUtils::EncryptionLevelToString(encryption_level_) << " ACK, "
+ << EncryptionLevelToString(encryption_level_) << " ACK, "
<< (has_pending_ack ? "" : "!") << "has_pending_ack, stop_waiting_count_ "
<< stop_waiting_count_;
frames.push_back(updated_ack_frame);
@@ -2276,7 +2279,7 @@
? "data bearing "
: " ack only ")
<< ", encryption level: "
- << QuicUtils::EncryptionLevelToString(packet->encryption_level)
+ << EncryptionLevelToString(packet->encryption_level)
<< ", encrypted length:" << encrypted_length;
QUIC_DVLOG(2) << ENDPOINT << "packet(" << packet_number << "): " << std::endl
<< QuicTextUtils::HexDump(QuicStringPiece(
@@ -2753,8 +2756,8 @@
void QuicConnection::SetDefaultEncryptionLevel(EncryptionLevel level) {
QUIC_DVLOG(1) << ENDPOINT << "Setting default encryption level from "
- << QuicUtils::EncryptionLevelToString(encryption_level_)
- << " to " << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(encryption_level_) << " to "
+ << EncryptionLevelToString(level);
if (level != encryption_level_ && packet_generator_.HasPendingFrames()) {
// Flush all queued frames when encryption level changes.
ScopedPacketFlusher flusher(this);
@@ -3810,7 +3813,7 @@
// A forward secure packet has been received.
QUIC_BUG_IF(encryption_level_ != ENCRYPTION_FORWARD_SECURE)
<< ENDPOINT << "Unexpected connection close encryption level "
- << QuicUtils::EncryptionLevelToString(encryption_level_);
+ << EncryptionLevelToString(encryption_level_);
return ENCRYPTION_FORWARD_SECURE;
}
if (framer_.HasEncrypterOfEncryptionLevel(ENCRYPTION_ZERO_RTT)) {
@@ -3842,12 +3845,13 @@
if (!framer_.HasEncrypterOfEncryptionLevel(
QuicUtils::GetEncryptionLevel(static_cast<PacketNumberSpace>(i)))) {
QUIC_BUG << ENDPOINT << "Cannot send ACKs for packet number space "
- << static_cast<uint32_t>(i)
+ << PacketNumberSpaceToString(static_cast<PacketNumberSpace>(i))
<< " without corresponding encrypter";
continue;
}
- QUIC_DVLOG(1) << ENDPOINT << "Sending ACK of packet number space: "
- << static_cast<uint32_t>(i);
+ QUIC_DVLOG(1) << ENDPOINT << "Sending ACK of packet number space "
+ << PacketNumberSpaceToString(
+ static_cast<PacketNumberSpace>(i));
// Switch to the appropriate encryption level.
SetDefaultEncryptionLevel(
QuicUtils::GetEncryptionLevel(static_cast<PacketNumberSpace>(i)));
diff --git a/quic/core/quic_framer.cc b/quic/core/quic_framer.cc
index e10270d..6b55cfc 100644
--- a/quic/core/quic_framer.cc
+++ b/quic/core/quic_framer.cc
@@ -4127,8 +4127,8 @@
DCHECK_GE(level, decrypter_level_);
DCHECK(!version_.KnowsWhichDecrypterToUse());
QUIC_DVLOG(1) << ENDPOINT << "Setting decrypter from level "
- << QuicUtils::EncryptionLevelToString(decrypter_level_)
- << " to " << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(decrypter_level_) << " to "
+ << EncryptionLevelToString(level);
decrypter_[decrypter_level_] = nullptr;
decrypter_[level] = std::move(decrypter);
decrypter_level_ = level;
@@ -4141,9 +4141,8 @@
DCHECK_NE(level, decrypter_level_);
DCHECK(!version_.KnowsWhichDecrypterToUse());
QUIC_DVLOG(1) << ENDPOINT << "Setting alternative decrypter from level "
- << QuicUtils::EncryptionLevelToString(
- alternative_decrypter_level_)
- << " to " << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(alternative_decrypter_level_)
+ << " to " << EncryptionLevelToString(level);
if (alternative_decrypter_level_ != NUM_ENCRYPTION_LEVELS) {
decrypter_[alternative_decrypter_level_] = nullptr;
}
@@ -4156,14 +4155,14 @@
std::unique_ptr<QuicDecrypter> decrypter) {
DCHECK(version_.KnowsWhichDecrypterToUse());
QUIC_DVLOG(1) << ENDPOINT << "Installing decrypter at level "
- << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(level);
decrypter_[level] = std::move(decrypter);
}
void QuicFramer::RemoveDecrypter(EncryptionLevel level) {
DCHECK(version_.KnowsWhichDecrypterToUse());
QUIC_DVLOG(1) << ENDPOINT << "Removing decrypter at level "
- << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(level);
decrypter_[level] = nullptr;
}
@@ -4188,7 +4187,7 @@
DCHECK_GE(level, 0);
DCHECK_LT(level, NUM_ENCRYPTION_LEVELS);
QUIC_DVLOG(1) << ENDPOINT << "Setting encrypter at level "
- << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(level);
encrypter_[level] = std::move(encrypter);
}
@@ -4210,7 +4209,7 @@
if (encrypter_[level] == nullptr) {
QUIC_BUG << ENDPOINT
<< "Attempted to encrypt in place without encrypter at level "
- << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(level);
RaiseError(QUIC_ENCRYPTION_FAILURE);
return 0;
}
@@ -4334,7 +4333,7 @@
QUIC_DVLOG(1)
<< ENDPOINT
<< "No decrypter available for removing header protection at level "
- << QuicUtils::EncryptionLevelToString(expected_decryption_level);
+ << EncryptionLevelToString(expected_decryption_level);
return false;
}
@@ -4455,7 +4454,7 @@
DCHECK(packet_number.IsInitialized());
if (encrypter_[level] == nullptr) {
QUIC_BUG << ENDPOINT << "Attempted to encrypt without encrypter at level "
- << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(level);
RaiseError(QUIC_ENCRYPTION_FAILURE);
return 0;
}
diff --git a/quic/core/quic_packet_creator.cc b/quic/core/quic_packet_creator.cc
index b717054..e7f5185 100644
--- a/quic/core/quic_packet_creator.cc
+++ b/quic/core/quic_packet_creator.cc
@@ -41,10 +41,10 @@
case ENCRYPTION_FORWARD_SECURE:
QUIC_BUG
<< "Try to derive long header type for packet with encryption level: "
- << QuicUtils::EncryptionLevelToString(level);
+ << EncryptionLevelToString(level);
return INVALID_PACKET_TYPE;
default:
- QUIC_BUG << QuicUtils::EncryptionLevelToString(level);
+ QUIC_BUG << EncryptionLevelToString(level);
return INVALID_PACKET_TYPE;
}
}
@@ -1267,15 +1267,15 @@
bool save_retransmittable_frames,
TransmissionType transmission_type) {
QUIC_DVLOG(1) << ENDPOINT << "Adding frame with transmission type "
- << transmission_type << ": " << frame;
+ << TransmissionTypeToString(transmission_type) << ": " << frame;
if (frame.type == STREAM_FRAME &&
!QuicUtils::IsCryptoStreamId(framer_->transport_version(),
frame.stream_frame.stream_id) &&
(packet_.encryption_level == ENCRYPTION_INITIAL ||
packet_.encryption_level == ENCRYPTION_HANDSHAKE)) {
- const std::string error_details = QuicStrCat(
- "Cannot send stream data with level: ",
- QuicUtils::EncryptionLevelToString(packet_.encryption_level));
+ const std::string error_details =
+ QuicStrCat("Cannot send stream data with level: ",
+ EncryptionLevelToString(packet_.encryption_level));
QUIC_BUG << error_details;
delegate_->OnUnrecoverableError(
QUIC_ATTEMPT_TO_SEND_UNENCRYPTED_STREAM_DATA, error_details);
@@ -1370,8 +1370,9 @@
bool success = AddFrame(QuicFrame(QuicPaddingFrame(padding_bytes)), false,
packet_.transmission_type);
- QUIC_BUG_IF(!success) << "Failed to add padding_bytes:" << padding_bytes
- << " transmission_type:" << packet_.transmission_type;
+ QUIC_BUG_IF(!success) << "Failed to add padding_bytes: " << padding_bytes
+ << " transmission_type: "
+ << TransmissionTypeToString(packet_.transmission_type);
}
bool QuicPacketCreator::IncludeNonceInPublicHeader() const {
@@ -1429,7 +1430,7 @@
if (!can_set_transmission_type()) {
QUIC_DVLOG_IF(1, type != packet_.transmission_type)
<< ENDPOINT << "Setting Transmission type to "
- << QuicUtils::TransmissionTypeToString(type);
+ << TransmissionTypeToString(type);
packet_.transmission_type = type;
}
diff --git a/quic/core/quic_sent_packet_manager.cc b/quic/core/quic_sent_packet_manager.cc
index 6baac98..a32a253 100644
--- a/quic/core/quic_sent_packet_manager.cc
+++ b/quic/core/quic_sent_packet_manager.cc
@@ -521,8 +521,7 @@
(!session_decides_what_to_write() ||
transmission_type != RTO_RETRANSMISSION)) &&
!unacked_packets_.HasRetransmittableFrames(*transmission_info))
- << "transmission_type: "
- << QuicUtils::TransmissionTypeToString(transmission_type);
+ << "transmission_type: " << TransmissionTypeToString(transmission_type);
// Handshake packets should never be sent as probing retransmissions.
DCHECK(pto_enabled_ || !transmission_info->has_crypto_handshake ||
transmission_type != PROBING_RETRANSMISSION);
@@ -690,8 +689,7 @@
// retransmission and no new data gets acked.
QUIC_DVLOG(1) << "Detect spurious retransmitted packet "
<< packet_number << " transmission type: "
- << QuicUtils::TransmissionTypeToString(
- info->transmission_type);
+ << TransmissionTypeToString(info->transmission_type);
RecordSpuriousRetransmissions(*info, packet_number);
}
}
@@ -1372,7 +1370,7 @@
<< ", packets_acked_: " << packets_acked_;
} else {
QUIC_PEER_BUG << "Received "
- << QuicUtils::EncryptionLevelToString(ack_decrypted_level)
+ << EncryptionLevelToString(ack_decrypted_level)
<< " ack for unackable packet: "
<< acked_packet.packet_number << " with state: "
<< QuicUtils::SentPacketStateToString(info->state);
@@ -1386,7 +1384,7 @@
continue;
}
QUIC_DVLOG(1) << ENDPOINT << "Got an "
- << QuicUtils::EncryptionLevelToString(ack_decrypted_level)
+ << EncryptionLevelToString(ack_decrypted_level)
<< " ack for packet " << acked_packet.packet_number
<< " , state: "
<< QuicUtils::SentPacketStateToString(info->state);
diff --git a/quic/core/quic_types.cc b/quic/core/quic_types.cc
index 46f809d..a8373c1 100644
--- a/quic/core/quic_types.cc
+++ b/quic/core/quic_types.cc
@@ -457,13 +457,56 @@
return os;
}
+std::string TransmissionTypeToString(TransmissionType transmission_type) {
+ switch (transmission_type) {
+ RETURN_STRING_LITERAL(NOT_RETRANSMISSION);
+ RETURN_STRING_LITERAL(HANDSHAKE_RETRANSMISSION);
+ RETURN_STRING_LITERAL(ALL_UNACKED_RETRANSMISSION);
+ RETURN_STRING_LITERAL(ALL_INITIAL_RETRANSMISSION);
+ RETURN_STRING_LITERAL(LOSS_RETRANSMISSION);
+ RETURN_STRING_LITERAL(RTO_RETRANSMISSION);
+ RETURN_STRING_LITERAL(TLP_RETRANSMISSION);
+ RETURN_STRING_LITERAL(PROBING_RETRANSMISSION);
+ default:
+ // Some varz rely on this behavior for statistic collection.
+ if (transmission_type == LAST_TRANSMISSION_TYPE + 1) {
+ return "INVALID_TRANSMISSION_TYPE";
+ }
+ return QuicStrCat("Unknown(", static_cast<int>(transmission_type), ")");
+ break;
+ }
+}
+
+std::string PacketNumberSpaceToString(PacketNumberSpace packet_number_space) {
+ switch (packet_number_space) {
+ RETURN_STRING_LITERAL(INITIAL_DATA);
+ RETURN_STRING_LITERAL(HANDSHAKE_DATA);
+ RETURN_STRING_LITERAL(APPLICATION_DATA);
+ default:
+ return QuicStrCat("Unknown(", static_cast<int>(packet_number_space), ")");
+ break;
+ }
+}
+
+std::string EncryptionLevelToString(EncryptionLevel level) {
+ switch (level) {
+ RETURN_STRING_LITERAL(ENCRYPTION_INITIAL);
+ RETURN_STRING_LITERAL(ENCRYPTION_HANDSHAKE);
+ RETURN_STRING_LITERAL(ENCRYPTION_ZERO_RTT);
+ RETURN_STRING_LITERAL(ENCRYPTION_FORWARD_SECURE);
+ default:
+ return QuicStrCat("Unknown(", static_cast<int>(level), ")");
+ break;
+ }
+}
+
std::string QuicConnectionCloseTypeString(QuicConnectionCloseType type) {
switch (type) {
RETURN_STRING_LITERAL(GOOGLE_QUIC_CONNECTION_CLOSE);
RETURN_STRING_LITERAL(IETF_QUIC_TRANSPORT_CONNECTION_CLOSE);
RETURN_STRING_LITERAL(IETF_QUIC_APPLICATION_CONNECTION_CLOSE);
default:
- return QuicStrCat("Unknown: ", static_cast<int>(type));
+ return QuicStrCat("Unknown(", static_cast<int>(type), ")");
break;
}
}
diff --git a/quic/core/quic_types.h b/quic/core/quic_types.h
index bd7ff55..e1c9c68 100644
--- a/quic/core/quic_types.h
+++ b/quic/core/quic_types.h
@@ -157,6 +157,9 @@
LAST_TRANSMISSION_TYPE = PROBING_RETRANSMISSION,
};
+QUIC_EXPORT_PRIVATE std::string TransmissionTypeToString(
+ TransmissionType transmission_type);
+
enum HasRetransmittableData : uint8_t {
NO_RETRANSMITTABLE_DATA,
HAS_RETRANSMITTABLE_DATA,
@@ -407,6 +410,8 @@
return ENCRYPTION_INITIAL <= level && level < NUM_ENCRYPTION_LEVELS;
}
+QUIC_EXPORT_PRIVATE std::string EncryptionLevelToString(EncryptionLevel level);
+
enum AddressChangeType : uint8_t {
// IP address and port remain unchanged.
NO_CHANGE,
@@ -630,6 +635,9 @@
NUM_PACKET_NUMBER_SPACES,
};
+QUIC_EXPORT_PRIVATE std::string PacketNumberSpaceToString(
+ PacketNumberSpace packet_number_space);
+
enum AckMode { TCP_ACKING, ACK_DECIMATION, ACK_DECIMATION_WITH_REORDERING };
// Used to return the result of processing a received ACK frame.
diff --git a/quic/core/quic_utils.cc b/quic/core/quic_utils.cc
index da2cb1a..07565ee 100644
--- a/quic/core/quic_utils.cc
+++ b/quic/core/quic_utils.cc
@@ -142,33 +142,6 @@
case x: \
return #x;
-// static
-const char* QuicUtils::EncryptionLevelToString(EncryptionLevel level) {
- switch (level) {
- RETURN_STRING_LITERAL(ENCRYPTION_INITIAL);
- RETURN_STRING_LITERAL(ENCRYPTION_HANDSHAKE);
- RETURN_STRING_LITERAL(ENCRYPTION_ZERO_RTT);
- RETURN_STRING_LITERAL(ENCRYPTION_FORWARD_SECURE);
- RETURN_STRING_LITERAL(NUM_ENCRYPTION_LEVELS);
- }
- return "INVALID_ENCRYPTION_LEVEL";
-}
-
-// static
-const char* QuicUtils::TransmissionTypeToString(TransmissionType type) {
- switch (type) {
- RETURN_STRING_LITERAL(NOT_RETRANSMISSION);
- RETURN_STRING_LITERAL(HANDSHAKE_RETRANSMISSION);
- RETURN_STRING_LITERAL(LOSS_RETRANSMISSION);
- RETURN_STRING_LITERAL(ALL_UNACKED_RETRANSMISSION);
- RETURN_STRING_LITERAL(ALL_INITIAL_RETRANSMISSION);
- RETURN_STRING_LITERAL(RTO_RETRANSMISSION);
- RETURN_STRING_LITERAL(TLP_RETRANSMISSION);
- RETURN_STRING_LITERAL(PROBING_RETRANSMISSION);
- }
- return "INVALID_TRANSMISSION_TYPE";
-}
-
std::string QuicUtils::AddressChangeTypeToString(AddressChangeType type) {
switch (type) {
RETURN_STRING_LITERAL(NO_CHANGE);
@@ -359,7 +332,7 @@
case PROBING_RETRANSMISSION:
return PROBE_RETRANSMITTED;
default:
- QUIC_BUG << QuicUtils::TransmissionTypeToString(retransmission_type)
+ QUIC_BUG << TransmissionTypeToString(retransmission_type)
<< " is not a retransmission_type";
return UNACKABLE;
}
diff --git a/quic/core/quic_utils.h b/quic/core/quic_utils.h
index de855a0..25ab7bb 100644
--- a/quic/core/quic_utils.h
+++ b/quic/core/quic_utils.h
@@ -50,12 +50,6 @@
// to |out|.
static void SerializeUint128Short(QuicUint128 v, uint8_t* out);
- // Returns the level of encryption as a char*
- static const char* EncryptionLevelToString(EncryptionLevel level);
-
- // Returns TransmissionType as a char*
- static const char* TransmissionTypeToString(TransmissionType type);
-
// Returns AddressChangeType as a string.
static std::string AddressChangeTypeToString(AddressChangeType type);
