Improve logging in MasqueH2Connection
PiperOrigin-RevId: 843816151
diff --git a/quiche/quic/masque/masque_h2_connection.cc b/quiche/quic/masque/masque_h2_connection.cc
index 11bdfb1..ac6b80c 100644
--- a/quiche/quic/masque/masque_h2_connection.cc
+++ b/quiche/quic/masque/masque_h2_connection.cc
@@ -27,6 +27,8 @@
#include "quiche/common/platform/api/quiche_logging.h"
#include "quiche/common/quiche_text_utils.h"
+#define ENDPOINT (is_server_ ? "Server: " : "Client: ")
+
using http2::adapter::Header;
using http2::adapter::Http2KnownSettingsId;
@@ -48,7 +50,7 @@
return;
}
aborted_ = true;
- QUICHE_LOG(ERROR) << "Aborting connection";
+ QUICHE_LOG(ERROR) << ENDPOINT << "Aborting connection";
visitor_->OnConnectionFinished(this);
}
@@ -86,7 +88,8 @@
} else {
int ssl_err = SSL_get_error(ssl_, ssl_handshake_ret);
if (ssl_err == SSL_ERROR_WANT_READ) {
- QUICHE_DVLOG(1) << "SSL_do_handshake will require another read";
+ QUICHE_DVLOG(1) << ENDPOINT
+ << "SSL_do_handshake will require another read";
return false;
}
PrintSSLError("Error while connecting", ssl_err, ssl_handshake_ret);
@@ -104,11 +107,11 @@
return false;
}
if (ssl_read_ret == 0) {
- QUICHE_LOG(INFO) << "TLS read closed";
+ QUICHE_LOG(INFO) << ENDPOINT << "TLS read closed";
return false;
}
- QUICHE_DVLOG(1) << "Read " << ssl_read_ret << " bytes from TLS";
- QUICHE_DVLOG(2) << "Read TLS bytes:" << std::endl
+ QUICHE_DVLOG(1) << ENDPOINT << "Read " << ssl_read_ret << " bytes from TLS";
+ QUICHE_DVLOG(2) << ENDPOINT << "Read TLS bytes:" << std::endl
<< quiche::QuicheTextUtils::HexDump(absl::string_view(
reinterpret_cast<const char*>(buffer), ssl_read_ret));
h2_adapter_->ProcessBytes(
@@ -117,7 +120,7 @@
}
int MasqueH2Connection::WriteDataToTls(absl::string_view data) {
- QUICHE_DVLOG(2) << "Writing " << data.size()
+ QUICHE_DVLOG(2) << ENDPOINT << "Writing " << data.size()
<< " app bytes to TLS:" << std::endl
<< quiche::QuicheTextUtils::HexDump(data);
int ssl_write_ret = SSL_write(ssl_, data.data(), data.size());
@@ -127,17 +130,17 @@
return -1;
} else {
if (ssl_write_ret == static_cast<int>(data.size())) {
- QUICHE_DVLOG(1) << "Wrote " << data.size() << " bytes to TLS";
+ QUICHE_DVLOG(1) << ENDPOINT << "Wrote " << data.size() << " bytes to TLS";
} else {
- QUICHE_DVLOG(1) << "Wrote " << ssl_write_ret << " / " << data.size()
- << "bytes to TLS";
+ QUICHE_DVLOG(1) << ENDPOINT << "Wrote " << ssl_write_ret << " / "
+ << data.size() << "bytes to TLS";
}
}
return ssl_write_ret;
}
int64_t MasqueH2Connection::OnReadyToSend(absl::string_view serialized) {
- QUICHE_DVLOG(1) << "Writing " << serialized.size()
+ QUICHE_DVLOG(1) << ENDPOINT << "Writing " << serialized.size()
<< " bytes of h2 data to TLS";
int write_res = WriteDataToTls(serialized);
if (write_res < 0) {
@@ -185,7 +188,7 @@
}
void MasqueH2Connection::OnConnectionError(ConnectionError error) {
- QUICHE_LOG(ERROR) << "OnConnectionError: "
+ QUICHE_LOG(ERROR) << ENDPOINT << "OnConnectionError: "
<< http2::adapter::ConnectionErrorToString(error);
Abort();
}
@@ -193,7 +196,7 @@
void MasqueH2Connection::OnSettingsStart() {}
void MasqueH2Connection::OnSetting(Http2Setting setting) {
- QUICHE_LOG(INFO) << "Received "
+ QUICHE_LOG(INFO) << ENDPOINT << "Received "
<< http2::adapter::Http2SettingsIdToString(setting.id)
<< " = " << setting.value;
}
@@ -202,14 +205,14 @@
void MasqueH2Connection::OnSettingsAck() {}
bool MasqueH2Connection::OnBeginHeadersForStream(Http2StreamId stream_id) {
- QUICHE_DVLOG(1) << "OnBeginHeadersForStream " << stream_id;
+ QUICHE_DVLOG(1) << ENDPOINT << "OnBeginHeadersForStream " << stream_id;
return true;
}
MasqueH2Connection::OnHeaderResult MasqueH2Connection::OnHeaderForStream(
Http2StreamId stream_id, absl::string_view key, absl::string_view value) {
- QUICHE_DVLOG(2) << "Stream " << stream_id << " received header " << key
- << " = " << value;
+ QUICHE_DVLOG(2) << ENDPOINT << "Stream " << stream_id << " received header "
+ << key << " = " << value;
GetOrCreateH2Stream(stream_id)->received_headers.AppendValueOrAddHeader(
key, value);
return OnHeaderResult::HEADER_OK;
@@ -217,12 +220,12 @@
bool MasqueH2Connection::AttemptToSend() {
if (!h2_adapter_) {
- QUICHE_LOG(ERROR) << "Connection is not ready to send yet";
+ QUICHE_LOG(ERROR) << ENDPOINT << "Connection is not ready to send yet";
return false;
}
int h2_send_result = h2_adapter_->Send();
if (h2_send_result != 0) {
- QUICHE_LOG(ERROR) << "h2 adapter failed to send";
+ QUICHE_LOG(ERROR) << ENDPOINT << "h2 adapter failed to send";
Abort();
return false;
}
@@ -231,7 +234,7 @@
bool MasqueH2Connection::OnEndHeadersForStream(Http2StreamId stream_id) {
MasqueH2Stream* stream = GetOrCreateH2Stream(stream_id);
- QUICHE_LOG(INFO) << "OnEndHeadersForStream " << stream_id
+ QUICHE_LOG(INFO) << ENDPOINT << "OnEndHeadersForStream " << stream_id
<< " headers: " << stream->received_headers.DebugString();
return true;
}
@@ -245,7 +248,8 @@
if (h2_adapter_->SubmitResponse(
stream_id, h2_headers,
/*end_stream=*/stream->body_to_send.empty()) != 0) {
- QUICHE_LOG(ERROR) << "Failed to submit response for stream " << stream_id;
+ QUICHE_LOG(ERROR) << ENDPOINT << "Failed to submit response for stream "
+ << stream_id;
Abort();
}
}
@@ -286,21 +290,21 @@
bool MasqueH2Connection::OnBeginDataForStream(Http2StreamId stream_id,
size_t payload_length) {
- QUICHE_DVLOG(1) << "OnBeginDataForStream " << stream_id
+ QUICHE_DVLOG(1) << ENDPOINT << "OnBeginDataForStream " << stream_id
<< " payload_length: " << payload_length;
return true;
}
bool MasqueH2Connection::OnDataPaddingLength(Http2StreamId stream_id,
size_t padding_length) {
- QUICHE_DVLOG(1) << "OnDataPaddingLength stream_id: " << stream_id
+ QUICHE_DVLOG(1) << ENDPOINT << "OnDataPaddingLength stream_id: " << stream_id
<< " padding_length: " << padding_length;
return true;
}
bool MasqueH2Connection::OnDataForStream(Http2StreamId stream_id,
absl::string_view data) {
- QUICHE_DVLOG(1) << "OnDataForStream " << stream_id
+ QUICHE_DVLOG(1) << ENDPOINT << "OnDataForStream " << stream_id
<< " data length: " << data.size();
GetOrCreateH2Stream(stream_id)->received_body.append(data);
return true;
@@ -308,10 +312,9 @@
bool MasqueH2Connection::OnEndStream(Http2StreamId stream_id) {
MasqueH2Stream* stream = GetOrCreateH2Stream(stream_id);
- QUICHE_LOG(INFO) << "Received END_STREAM for stream " << stream_id
- << " body length: " << stream->received_body.size()
- << std::endl
- << stream->received_body;
+ QUICHE_LOG(INFO) << ENDPOINT << "Received END_STREAM for stream " << stream_id
+ << " body length: " << stream->received_body.size();
+ QUICHE_DVLOG(2) << ENDPOINT << "Body: " << std::endl << stream->received_body;
if (is_server_) {
visitor_->OnRequest(this, stream_id, stream->received_headers,
stream->received_body);
@@ -324,13 +327,15 @@
void MasqueH2Connection::OnRstStream(Http2StreamId stream_id,
Http2ErrorCode error_code) {
- QUICHE_LOG(INFO) << "Stream " << stream_id << " reset with error code "
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
+ << " reset with error code "
<< Http2ErrorCodeToString(error_code);
}
bool MasqueH2Connection::OnCloseStream(Http2StreamId stream_id,
Http2ErrorCode error_code) {
- QUICHE_LOG(INFO) << "Stream " << stream_id << " closed with error code "
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
+ << " closed with error code "
<< Http2ErrorCodeToString(error_code);
h2_streams_.erase(stream_id);
return true;
@@ -339,18 +344,20 @@
void MasqueH2Connection::OnPriorityForStream(Http2StreamId stream_id,
Http2StreamId parent_stream_id,
int weight, bool exclusive) {
- QUICHE_LOG(INFO) << "Stream " << stream_id << " received priority " << weight
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
+ << " received priority " << weight
<< (exclusive ? " exclusive" : "") << " parent "
<< parent_stream_id;
}
void MasqueH2Connection::OnPing(Http2PingId ping_id, bool is_ack) {
- QUICHE_LOG(INFO) << "Received ping " << ping_id << (is_ack ? " ack" : "");
+ QUICHE_LOG(INFO) << ENDPOINT << "Received ping " << ping_id
+ << (is_ack ? " ack" : "");
}
void MasqueH2Connection::OnPushPromiseForStream(
Http2StreamId stream_id, Http2StreamId promised_stream_id) {
- QUICHE_LOG(INFO) << "Stream " << stream_id
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
<< " received push promise for stream "
<< promised_stream_id;
}
@@ -358,7 +365,8 @@
bool MasqueH2Connection::OnGoAway(Http2StreamId last_accepted_stream_id,
Http2ErrorCode error_code,
absl::string_view opaque_data) {
- QUICHE_LOG(INFO) << "Received GOAWAY frame with last_accepted_stream_id: "
+ QUICHE_LOG(INFO) << ENDPOINT
+ << "Received GOAWAY frame with last_accepted_stream_id: "
<< last_accepted_stream_id
<< " error_code: " << Http2ErrorCodeToString(error_code)
<< " opaque_data length: " << opaque_data.size();
@@ -367,14 +375,14 @@
void MasqueH2Connection::OnWindowUpdate(Http2StreamId stream_id,
int window_increment) {
- QUICHE_LOG(INFO) << "Stream " << stream_id << " received window update "
- << window_increment;
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
+ << " received window update " << window_increment;
}
int MasqueH2Connection::OnBeforeFrameSent(uint8_t frame_type,
Http2StreamId stream_id,
size_t length, uint8_t flags) {
- QUICHE_DVLOG(1) << "OnBeforeFrameSent frame_type: "
+ QUICHE_DVLOG(1) << ENDPOINT << "OnBeforeFrameSent frame_type: "
<< static_cast<int>(frame_type) << " stream_id: " << stream_id
<< " length: " << length
<< " flags: " << static_cast<int>(flags);
@@ -384,7 +392,8 @@
int MasqueH2Connection::OnFrameSent(uint8_t frame_type, Http2StreamId stream_id,
size_t length, uint8_t flags,
uint32_t error_code) {
- QUICHE_DVLOG(1) << "OnFrameSent frame_type: " << static_cast<int>(frame_type)
+ QUICHE_DVLOG(1) << ENDPOINT
+ << "OnFrameSent frame_type: " << static_cast<int>(frame_type)
<< " stream_id: " << stream_id << " length: " << length
<< " flags: " << static_cast<int>(flags)
<< " error_code: " << error_code;
@@ -393,31 +402,33 @@
bool MasqueH2Connection::OnInvalidFrame(Http2StreamId stream_id,
InvalidFrameError error) {
- QUICHE_LOG(INFO) << "Stream " << stream_id << " received invalid frame error "
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
+ << " received invalid frame error "
<< http2::adapter::InvalidFrameErrorToString(error);
return true;
}
void MasqueH2Connection::OnBeginMetadataForStream(Http2StreamId stream_id,
size_t payload_length) {
- QUICHE_LOG(INFO) << "Stream " << stream_id
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
<< " about to receive metadata of length " << payload_length;
}
bool MasqueH2Connection::OnMetadataForStream(Http2StreamId stream_id,
absl::string_view metadata) {
- QUICHE_LOG(INFO) << "Stream " << stream_id << " received metadata of length "
- << metadata.size();
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
+ << " received metadata of length " << metadata.size();
return true;
}
bool MasqueH2Connection::OnMetadataEndForStream(Http2StreamId stream_id) {
- QUICHE_LOG(INFO) << "Stream " << stream_id << " done receiving metadata";
+ QUICHE_LOG(INFO) << ENDPOINT << "Stream " << stream_id
+ << " done receiving metadata";
return true;
}
void MasqueH2Connection::OnErrorDebug(absl::string_view message) {
- QUICHE_LOG(ERROR) << "OnErrorDebug: " << message;
+ QUICHE_LOG(ERROR) << ENDPOINT << "OnErrorDebug: " << message;
}
MasqueH2Connection::MasqueH2Stream* MasqueH2Connection::GetOrCreateH2Stream(
@@ -455,3 +466,5 @@
}
} // namespace quic
+
+#undef ENDPOINT
