Include stream information in idle timeout connection close detail.
Protected by FLAGS_quic_reloadable_flag_quic_add_stream_info_to_idle_close_detail.
PiperOrigin-RevId: 330939479
Change-Id: I79754a0ae790df319b3ff0d1d41a35ebb505f207
diff --git a/quic/core/quic_connection.cc b/quic/core/quic_connection.cc
index 96b46d2..6be7633 100644
--- a/quic/core/quic_connection.cc
+++ b/quic/core/quic_connection.cc
@@ -4815,15 +4815,23 @@
const QuicTime::Delta duration =
clock_->ApproximateNow() -
idle_network_detector_.last_network_activity_time();
- const std::string error_details = quiche::QuicheStrCat(
+ std::string error_details = quiche::QuicheStrCat(
"No recent network activity after ", duration.ToDebuggingValue(),
". Timeout:",
idle_network_detector_.idle_network_timeout().ToDebuggingValue());
QUIC_DVLOG(1) << ENDPOINT << error_details;
- if ((sent_packet_manager_.GetConsecutiveTlpCount() > 0 ||
- sent_packet_manager_.GetConsecutiveRtoCount() > 0 ||
- sent_packet_manager_.GetConsecutivePtoCount() > 0 ||
- visitor_->ShouldKeepConnectionAlive())) {
+ const bool has_consecutive_pto =
+ sent_packet_manager_.GetConsecutiveTlpCount() > 0 ||
+ sent_packet_manager_.GetConsecutiveRtoCount() > 0 ||
+ sent_packet_manager_.GetConsecutivePtoCount() > 0;
+ if (has_consecutive_pto || visitor_->ShouldKeepConnectionAlive()) {
+ if (GetQuicReloadableFlag(quic_add_stream_info_to_idle_close_detail) &&
+ !has_consecutive_pto) {
+ // Include stream information in error detail if there are open streams.
+ QUIC_RELOADABLE_FLAG_COUNT(quic_add_stream_info_to_idle_close_detail);
+ error_details = quiche::QuicheStrCat(
+ error_details, ", ", visitor_->GetStreamsInfoForLogging());
+ }
CloseConnection(QUIC_NETWORK_IDLE_TIMEOUT, error_details,
ConnectionCloseBehavior::SEND_CONNECTION_CLOSE_PACKET);
return;
diff --git a/quic/core/quic_connection.h b/quic/core/quic_connection.h
index 5e4bf82..77b32dc 100644
--- a/quic/core/quic_connection.h
+++ b/quic/core/quic_connection.h
@@ -170,6 +170,9 @@
// transactions expecting a response.
virtual bool ShouldKeepConnectionAlive() const = 0;
+ // Called to retrieve streams information for logging purpose.
+ virtual std::string GetStreamsInfoForLogging() const = 0;
+
// Called when a self address change is observed. Returns true if self address
// change is allowed.
virtual bool AllowSelfAddressChange() const = 0;
diff --git a/quic/core/quic_connection_test.cc b/quic/core/quic_connection_test.cc
index 2662ab7..7de6702 100644
--- a/quic/core/quic_connection_test.cc
+++ b/quic/core/quic_connection_test.cc
@@ -5970,6 +5970,9 @@
// Indicate streams are still open.
EXPECT_CALL(visitor_, ShouldKeepConnectionAlive())
.WillRepeatedly(Return(true));
+ if (GetQuicReloadableFlag(quic_add_stream_info_to_idle_close_detail)) {
+ EXPECT_CALL(visitor_, GetStreamsInfoForLogging()).WillOnce(Return(""));
+ }
// This time, we should time out and send a connection close due to the TLP.
EXPECT_CALL(visitor_,
diff --git a/quic/core/quic_session.cc b/quic/core/quic_session.cc
index 4a2c49b..462e073 100644
--- a/quic/core/quic_session.cc
+++ b/quic/core/quic_session.cc
@@ -696,6 +696,34 @@
write_blocked_streams_.HasWriteBlockedDataStreams();
}
+std::string QuicSession::GetStreamsInfoForLogging() const {
+ std::string info = quiche::QuicheStrCat(
+ "num_active_streams: ", GetNumActiveStreams(),
+ ", num_pending_streams: ", pending_streams_size(),
+ ", num_outgoing_draining_streams: ", num_outgoing_draining_streams(),
+ " ");
+ // Log info for up to 5 streams.
+ size_t i = 5;
+ for (const auto& it : stream_map_) {
+ if (it.second->is_static()) {
+ continue;
+ }
+ // Calculate the stream creation delay.
+ const QuicTime::Delta delay =
+ connection_->clock()->ApproximateNow() - it.second->creation_time();
+ info = quiche::QuicheStrCat(
+ info, "{", it.second->id(), ":", delay.ToDebuggingValue(), ";",
+ it.second->stream_bytes_written(), ",", it.second->fin_sent(), ",",
+ it.second->HasBufferedData(), ",", it.second->fin_buffered(), ";",
+ it.second->stream_bytes_read(), ",", it.second->fin_received(), "}");
+ --i;
+ if (i == 0) {
+ break;
+ }
+ }
+ return info;
+}
+
bool QuicSession::HasPendingHandshake() const {
if (QuicVersionUsesCryptoFrames(transport_version())) {
return GetCryptoStream()->HasPendingCryptoRetransmission() ||
diff --git a/quic/core/quic_session.h b/quic/core/quic_session.h
index e8f3c46..14a46dd 100644
--- a/quic/core/quic_session.h
+++ b/quic/core/quic_session.h
@@ -123,6 +123,7 @@
void OnAckNeedsRetransmittableFrame() override;
void SendPing() override;
bool WillingAndAbleToWrite() const override;
+ std::string GetStreamsInfoForLogging() const override;
void OnPathDegrading() override;
void OnForwardProgressMadeAfterPathDegrading() override;
bool AllowSelfAddressChange() const override;
diff --git a/quic/core/quic_stream.cc b/quic/core/quic_stream.cc
index 5d64f3b..0271352 100644
--- a/quic/core/quic_stream.cc
+++ b/quic/core/quic_stream.cc
@@ -361,6 +361,7 @@
session->IsIncomingStream(id_),
session->version())
: type),
+ creation_time_(session->connection()->clock()->ApproximateNow()),
perspective_(session->perspective()) {
if (type_ == WRITE_UNIDIRECTIONAL) {
fin_received_ = true;
diff --git a/quic/core/quic_stream.h b/quic/core/quic_stream.h
index a5520bd..f0a5a71 100644
--- a/quic/core/quic_stream.h
+++ b/quic/core/quic_stream.h
@@ -354,6 +354,10 @@
static spdy::SpdyStreamPrecedence CalculateDefaultPriority(
const QuicSession* session);
+ QuicTime creation_time() const { return creation_time_; }
+
+ bool fin_buffered() const { return fin_buffered_; }
+
protected:
// Called when data of [offset, offset + data_length] is buffered in send
// buffer.
@@ -408,8 +412,6 @@
StreamDelegateInterface* stream_delegate() { return stream_delegate_; }
- bool fin_buffered() const { return fin_buffered_; }
-
const QuicSession* session() const { return session_; }
QuicSession* session() { return session_; }
@@ -545,6 +547,9 @@
// write unidirectional.
const StreamType type_;
+ // Creation time of this stream, as reported by the QuicClock.
+ const QuicTime creation_time_;
+
Perspective perspective_;
};
diff --git a/quic/test_tools/quic_test_utils.h b/quic/test_tools/quic_test_utils.h
index 854fc23..c37ee4c 100644
--- a/quic/test_tools/quic_test_utils.h
+++ b/quic/test_tools/quic_test_utils.h
@@ -529,6 +529,7 @@
MOCK_METHOD(void, OnForwardProgressMadeAfterPathDegrading, (), (override));
MOCK_METHOD(bool, WillingAndAbleToWrite, (), (const, override));
MOCK_METHOD(bool, ShouldKeepConnectionAlive, (), (const, override));
+ MOCK_METHOD(std::string, GetStreamsInfoForLogging, (), (const, override));
MOCK_METHOD(void,
OnSuccessfulVersionNegotiation,
(const ParsedQuicVersion& version),
diff --git a/quic/test_tools/simulator/quic_endpoint.h b/quic/test_tools/simulator/quic_endpoint.h
index cb3c386..ff9b680 100644
--- a/quic/test_tools/simulator/quic_endpoint.h
+++ b/quic/test_tools/simulator/quic_endpoint.h
@@ -59,6 +59,7 @@
bool WillingAndAbleToWrite() const override;
bool ShouldKeepConnectionAlive() const override;
+ std::string GetStreamsInfoForLogging() const override { return ""; }
void OnWindowUpdateFrame(const QuicWindowUpdateFrame& /*frame*/) override {}
void OnBlockedFrame(const QuicBlockedFrame& /*frame*/) override {}
void OnRstStream(const QuicRstStreamFrame& /*frame*/) override {}
