Record HTTP/3 events in NetLog.

Bug: 1062700
Change-Id: I3b25b0e49f07c40a72eeb170d2f9d218aa56ba3e
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2117316Reviewed-by: Renjie Tang <renjietang@chromium.org>
Commit-Queue: Bence Béky <bnc@chromium.org>
Cr-Commit-Position: refs/heads/master@{#755985}

net/log/net_log_event_type_list.h

@@ -3572,24 +3572,169 @@ EVENT_TYPE(COOKIE_INCLUSION_STATUS)
 // HTTP/3 events.
 // -----------------------------------------------------------------------------
 
-// Event emitted when peer created control stream type is received.
-// "stream_id": <The stream id of peer created control stream>
+// Event emitted when locally-initiated HTTP/3 control stream is created.
+//  {
+//    "stream_id": <The stream id of locally created control stream>
+//  }
+EVENT_TYPE(HTTP3_LOCAL_CONTROL_STREAM_CREATED)
+
+// Event emitted when locally-initiated QPACK encoder stream is created.
+//  {
+//    "stream_id": <The stream id of locally created QPACK encoder stream>
+//  }
+EVENT_TYPE(HTTP3_LOCAL_QPACK_ENCODER_STREAM_CREATED)
+
+// Event emitted when locally-initiated QPACK decoder stream is created.
+//  {
+//    "stream_id": <The stream id of locally created QPACK decoder stream>
+//  }
+EVENT_TYPE(HTTP3_LOCAL_QPACK_DECODER_STREAM_CREATED)
+
+// Event emitted when peer created HTTP/3 control stream type is received.
+//  {
+//    "stream_id": <The stream id of peer created control stream>
+//  }
 EVENT_TYPE(HTTP3_PEER_CONTROL_STREAM_CREATED)
 
 // Event emitted when peer created QPACK encoder stream type is received.
-// "stream_id": <The stream id of the peer created QPACK encoder stream>
+//  {
+//    "stream_id": <The stream id of the peer created QPACK encoder stream>
+//  }
 EVENT_TYPE(HTTP3_PEER_QPACK_ENCODER_STREAM_CREATED)
 
 // Event emitted when peer created QPACK decoder stream type is received.
-// "stream_id": <The stream id of the peer created QPACK decoder stream>
+//  {
+//    "stream_id": <The stream id of the peer created QPACK decoder stream>
+//  }
 EVENT_TYPE(HTTP3_PEER_QPACK_DECODER_STREAM_CREATED)
 
+// Event emitted when an HTTP/3 CANCEL_PUSH frame is received.
+//  {
+//    "push_id": <The push_id field of the CANCEL_PUSH frame>
+//  }
+EVENT_TYPE(HTTP3_CANCEL_PUSH_RECEIVED)
+
 // Event emitted when SETTINGS frame is received.
 // A list of settings will be logged by
 // <setting identifier>: <setting value>
 EVENT_TYPE(HTTP3_SETTINGS_RECEIVED)
 
-// EVENT emitted when SETTINGS frame is sent.
+// Event emitted when an HTTP/3 GOAWAY frame is received.
+//  {
+//    "stream_id": <The stream_id field of the GOAWAY frame>
+//  }
+EVENT_TYPE(HTTP3_GOAWAY_RECEIVED)
+
+// Event emitted when an HTTP/3 MAX_PUSH_ID frame is received.
+//  {
+//    "push_id": <The push_id field of the MAX_PUSH_ID frame>
+//  }
+EVENT_TYPE(HTTP3_MAX_PUSH_ID_RECEIVED)
+
+// Event emitted when an HTTP/3 PRIORITY_UPDATE frame is received.
+//  {
+//    "type": <The prioritized element type field of the PRIORITY_UPDATE frame>
+//    "prioritized_element_id": <The prioritized_element_id field of the
+//                               PRIORITY_UPDATE frame>
+//    "priority_field_value": <The priority_field_value field of the
+//                             PRIORITY_UPDATE frame>
+//  }
+EVENT_TYPE(HTTP3_PRIORITY_UPDATE_RECEIVED)
+
+// Event emitted when an HTTP/3 DATA frame header is received.
+//  {
+//    "stream_id": <The ID of the stream on which the DATA frame is received>
+//    "payload_length": <The length of DATA frame payload>
+//  }
+EVENT_TYPE(HTTP3_DATA_FRAME_RECEIVED)
+
+// Event emitted when the receipt of an HTTP/3 HEADERS frame is complete.
+//  {
+//    "stream_id": <The ID of the stream on which the HEADERS frame is received>
+//    "payload_length": <The total number of payload bytes received>
+//  }
+EVENT_TYPE(HTTP3_HEADERS_RECEIVED)
+
+// Event emitted when headers received in an HTTP/3 HEADERS frame are decoded.
+//  {
+//    "stream_id": <The ID of the stream on which the HEADERS frame had been
+//                  received>
+//    "headers": <A dictionary of the decoded headers>
+//  }
+EVENT_TYPE(HTTP3_HEADERS_DECODED)
+
+// Event emitted when the receipt of an HTTP/3 PUSH_PROMISE frame is complete.
+//  {
+//    "stream_id": <The ID of the stream on which the PUSH_PROMISE frame is
+//                  received>
+//    "push_id": <The push_id field of the PUSH_PROMISE frame>
+//  }
+EVENT_TYPE(HTTP3_PUSH_PROMISE_RECEIVED)
+
+// Event emitted when headers received in an HTTP/3 PUSH_PROMISE frame are
+// decoded.
+//  {
+//    "stream_id": <The ID of the stream on which the PUSH_PROMISE frame had
+//                  been received>
+//    "push_id": <The push_id field of the PUSH_PROMISE frame>
+//    "headers": <A dictionary of the decoded headers>
+//  }
+EVENT_TYPE(HTTP3_PUSH_PROMISE_DECODED)
+
+// Event emitted when the frame header of an HTTP/3 frame of unknown type is
+// received.
+//  {
+//    "stream_id": <The ID of the stream on which the frame is received>
+//    "frame_type": <The frame type>
+//    "payload_length": <The length of the frame payload>
+//  }
+EVENT_TYPE(HTTP3_UNKNOWN_FRAME_RECEIVED)
+
+// Event emitted when an HTTP/3 SETTINGS frame is sent.
 // A list of settings will be logged by
 // <setting identifier>: <setting value>
 EVENT_TYPE(HTTP3_SETTINGS_SENT)
+
+// Event emitted when an HTTP/3 GOAWAY frame is sent.
+//  {
+//    "stream_id": <The stream_id field of the GOAWAY frame>
+//  }
+EVENT_TYPE(HTTP3_GOAWAY_SENT)
+
+// Event emitted when an HTTP/3 MAX_PUSH_ID frame is sent.
+//  {
+//    "push_id": <The push_id field of the MAX_PUSH_ID frame>
+//  }
+EVENT_TYPE(HTTP3_MAX_PUSH_ID_SENT)
+
+// Event emitted when an HTTP/3 PRIORITY_UPDATE frame is sent.
+//  {
+//    "type": <The prioritized element type field of the PRIORITY_UPDATE frame>
+//    "prioritized_element_id": <The prioritized_element_id field of the
+//                               PRIORITY_UPDATE frame>
+//    "priority_field_value": <The priority_field_value field of the
+//                             PRIORITY_UPDATE frame>
+//  }
+EVENT_TYPE(HTTP3_PRIORITY_UPDATE_SENT)
+
+// Event emitted when an HTTP/3 DATA frame is sent.
+//  {
+//    "stream_id": <The ID of the stream on which the frame is sent>
+//    "payload_length": <The total payload length of the frame>
+//  }
+EVENT_TYPE(HTTP3_DATA_SENT)
+
+// Event emitted when an HTTP/3 HEADERS frame is sent.
+//  {
+//    "stream_id": <The ID of the stream on which the frame is sent>
+//    "headers": <A dictionary of the headers sent>
+//  }
+EVENT_TYPE(HTTP3_HEADERS_SENT)
+
+// Event emitted when an HTTP/3 PUSH_PROMISE frame is sent.
+//  {
+//    "stream_id": <The ID of the stream on which the frame is sent>
+//    "push_id": <The push_id field of the PUSH_PROMISE frame>
+//    "headers": <A dictionary of the headers sent>
+//  }
+EVENT_TYPE(HTTP3_PUSH_PROMISE_SENT)

net/quic/quic_http3_logger.cc

@@ -29,6 +29,57 @@ base::Value NetLogSettingsParams(const quic::SettingsFrame& frame) {
   return dict;
 }
 
+base::Value NetLogPriorityUpdateParams(const quic::PriorityUpdateFrame& frame) {
+  base::Value dict(base::Value::Type::DICTIONARY);
+  dict.SetStringKey("type", frame.prioritized_element_type ==
+                                    quic::PrioritizedElementType::REQUEST_STREAM
+                                ? "request_stream"
+                                : "push_stream");
+  dict.SetKey("prioritized_element_id",
+              NetLogNumberValue(frame.prioritized_element_id));
+  dict.SetStringKey("priority_field_value", frame.priority_field_value);
+  return dict;
+}
+
+base::Value NetLogTwoIntParams(base::StringPiece name1,
+                               uint64_t value1,
+                               base::StringPiece name2,
+                               uint64_t value2) {
+  base::Value dict(base::Value::Type::DICTIONARY);
+  dict.SetKey(name1, NetLogNumberValue(value1));
+  dict.SetKey(name2, NetLogNumberValue(value2));
+  return dict;
+}
+
+base::Value NetLogThreeIntParams(base::StringPiece name1,
+                                 uint64_t value1,
+                                 base::StringPiece name2,
+                                 uint64_t value2,
+                                 base::StringPiece name3,
+                                 uint64_t value3) {
+  base::Value dict(base::Value::Type::DICTIONARY);
+  dict.SetKey(name1, NetLogNumberValue(value1));
+  dict.SetKey(name2, NetLogNumberValue(value2));
+  dict.SetKey(name3, NetLogNumberValue(value3));
+  return dict;
+}
+
+base::Value NetLogHeadersToDict(const quic::QuicHeaderList& headers) {
+  base::Value dict(base::Value::Type::DICTIONARY);
+  for (auto header : headers) {
+    dict.SetStringKey(header.first, header.second);
+  }
+  return dict;
+}
+
+base::Value NetLogHeadersToDict(const spdy::SpdyHeaderBlock& headers) {
+  base::Value dict(base::Value::Type::DICTIONARY);
+  for (auto header : headers) {
+    dict.SetStringKey(header.first, header.second);
+  }
+  return dict;
+}
+
 }  // namespace
 
 QuicHttp3Logger::QuicHttp3Logger(const NetLogWithSource& net_log)
@@ -36,6 +87,35 @@ QuicHttp3Logger::QuicHttp3Logger(const NetLogWithSource& net_log)
 
 QuicHttp3Logger::~QuicHttp3Logger() {}
 
+void QuicHttp3Logger::OnControlStreamCreated(quic::QuicStreamId stream_id) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(
+      NetLogEventType::HTTP3_LOCAL_CONTROL_STREAM_CREATED, "stream_id",
+      stream_id);
+}
+
+void QuicHttp3Logger::OnQpackEncoderStreamCreated(
+    quic::QuicStreamId stream_id) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(
+      NetLogEventType::HTTP3_LOCAL_QPACK_ENCODER_STREAM_CREATED, "stream_id",
+      stream_id);
+}
+
+void QuicHttp3Logger::OnQpackDecoderStreamCreated(
+    quic::QuicStreamId stream_id) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(
+      NetLogEventType::HTTP3_LOCAL_QPACK_DECODER_STREAM_CREATED, "stream_id",
+      stream_id);
+}
+
 void QuicHttp3Logger::OnPeerControlStreamCreated(quic::QuicStreamId stream_id) {
   if (!net_log_.IsCapturing())
     return;
@@ -62,6 +142,15 @@ void QuicHttp3Logger::OnPeerQpackDecoderStreamCreated(
       stream_id);
 }
 
+void QuicHttp3Logger::OnCancelPushFrameReceived(
+    const quic::CancelPushFrame& frame) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_CANCEL_PUSH_RECEIVED,
+                                 "push_id", frame.push_id);
+}
+
 void QuicHttp3Logger::OnSettingsFrameReceived(
     const quic::SettingsFrame& frame) {
   // Increment value by one because empty SETTINGS frames are allowed,
@@ -85,14 +174,202 @@ void QuicHttp3Logger::OnSettingsFrameReceived(
   if (!net_log_.IsCapturing())
     return;
   net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_RECEIVED,
-                    [&] { return NetLogSettingsParams(frame); });
+                    [&frame] { return NetLogSettingsParams(frame); });
+}
+
+void QuicHttp3Logger::OnGoAwayFrameReceived(const quic::GoAwayFrame& frame) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_GOAWAY_RECEIVED,
+                                 "stream_id", frame.stream_id);
+}
+
+void QuicHttp3Logger::OnMaxPushIdFrameReceived(
+    const quic::MaxPushIdFrame& frame) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_MAX_PUSH_ID_RECEIVED,
+                                 "push_id", frame.push_id);
+}
+
+void QuicHttp3Logger::OnPriorityUpdateFrameReceived(
+    const quic::PriorityUpdateFrame& frame) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(NetLogEventType::HTTP3_PRIORITY_UPDATE_RECEIVED,
+                    [&frame] { return NetLogPriorityUpdateParams(frame); });
+}
+
+void QuicHttp3Logger::OnDataFrameReceived(quic::QuicStreamId stream_id,
+                                          quic::QuicByteCount payload_length) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(
+      NetLogEventType::HTTP3_DATA_FRAME_RECEIVED, [stream_id, payload_length] {
+        return NetLogTwoIntParams("stream_id", stream_id, "payload_length",
+                                  payload_length);
+      });
+}
+
+void QuicHttp3Logger::OnHeadersFrameReceived(
+    quic::QuicStreamId stream_id,
+    quic::QuicByteCount compressed_headers_length) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(NetLogEventType::HTTP3_HEADERS_RECEIVED,
+                    [stream_id, compressed_headers_length] {
+                      return NetLogTwoIntParams("stream_id", stream_id,
+                                                "compressed_headers_length",
+                                                compressed_headers_length);
+                    });
+}
+
+void QuicHttp3Logger::OnHeadersDecoded(quic::QuicStreamId stream_id,
+                                       quic::QuicHeaderList headers) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(
+      NetLogEventType::HTTP3_HEADERS_DECODED, [stream_id, &headers] {
+        base::Value dict(base::Value::Type::DICTIONARY);
+        dict.SetKey("stream_id",
+                    NetLogNumberValue(static_cast<uint64_t>(stream_id)));
+        dict.SetKey("headers", NetLogHeadersToDict(headers));
+        return dict;
+      });
+}
+
+void QuicHttp3Logger::OnPushPromiseFrameReceived(
+    quic::QuicStreamId stream_id,
+    quic::QuicStreamId push_id,
+    quic::QuicByteCount compressed_headers_length) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(NetLogEventType::HTTP3_PUSH_PROMISE_RECEIVED,
+                    [stream_id, push_id, compressed_headers_length] {
+                      return NetLogThreeIntParams("stream_id", stream_id,
+                                                  "push_id", push_id,
+                                                  "compressed_headers_length",
+                                                  compressed_headers_length);
+                    });
+}
+
+void QuicHttp3Logger::OnPushPromiseDecoded(quic::QuicStreamId stream_id,
+                                           quic::QuicStreamId push_id,
+                                           quic::QuicHeaderList headers) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(NetLogEventType::HTTP3_PUSH_PROMISE_DECODED, [stream_id,
+                                                                  push_id,
+                                                                  &headers] {
+    base::Value dict(base::Value::Type::DICTIONARY);
+    dict.SetKey("stream_id",
+                NetLogNumberValue(static_cast<uint64_t>(stream_id)));
+    dict.SetKey("push_id", NetLogNumberValue(static_cast<uint64_t>(push_id)));
+    dict.SetKey("headers", NetLogHeadersToDict(headers));
+    return dict;
+  });
+}
+
+void QuicHttp3Logger::OnUnknownFrameReceived(
+    quic::QuicStreamId stream_id,
+    uint64_t frame_type,
+    quic::QuicByteCount payload_length) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(NetLogEventType::HTTP3_UNKNOWN_FRAME_RECEIVED,
+                    [stream_id, frame_type, payload_length] {
+                      return NetLogThreeIntParams(
+                          "stream_id", stream_id, "frame_type", frame_type,
+                          "payload_length", payload_length);
+                    });
 }
 
 void QuicHttp3Logger::OnSettingsFrameSent(const quic::SettingsFrame& frame) {
   if (!net_log_.IsCapturing())
     return;
   net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_SENT,
-                    [&] { return NetLogSettingsParams(frame); });
+                    [&frame] { return NetLogSettingsParams(frame); });
+}
+
+void QuicHttp3Logger::OnGoAwayFrameSent(quic::QuicStreamId stream_id) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_GOAWAY_SENT,
+                                 "stream_id", stream_id);
+}
+
+void QuicHttp3Logger::OnMaxPushIdFrameSent(const quic::MaxPushIdFrame& frame) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_MAX_PUSH_ID_SENT,
+                                 "push_id", frame.push_id);
+}
+
+void QuicHttp3Logger::OnPriorityUpdateFrameSent(
+    const quic::PriorityUpdateFrame& frame) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(NetLogEventType::HTTP3_PRIORITY_UPDATE_SENT,
+                    [&frame] { return NetLogPriorityUpdateParams(frame); });
+}
+
+void QuicHttp3Logger::OnDataFrameSent(quic::QuicStreamId stream_id,
+                                      quic::QuicByteCount payload_length) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(
+      NetLogEventType::HTTP3_DATA_SENT, [stream_id, payload_length] {
+        return NetLogTwoIntParams("stream_id", stream_id, "payload_length",
+                                  payload_length);
+      });
+}
+
+void QuicHttp3Logger::OnHeadersFrameSent(
+    quic::QuicStreamId stream_id,
+    const spdy::SpdyHeaderBlock& header_block) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(
+      NetLogEventType::HTTP3_HEADERS_SENT, [stream_id, &header_block] {
+        base::Value dict(base::Value::Type::DICTIONARY);
+        dict.SetKey("stream_id",
+                    NetLogNumberValue(static_cast<uint64_t>(stream_id)));
+        dict.SetKey("headers", NetLogHeadersToDict(header_block));
+        return dict;
+      });
+}
+
+void QuicHttp3Logger::OnPushPromiseFrameSent(
+    quic::QuicStreamId stream_id,
+    quic::QuicStreamId push_id,
+    const spdy::SpdyHeaderBlock& header_block) {
+  if (!net_log_.IsCapturing()) {
+    return;
+  }
+  net_log_.AddEvent(NetLogEventType::HTTP3_PUSH_PROMISE_SENT, [stream_id,
+                                                               push_id,
+                                                               &header_block] {
+    base::Value dict(base::Value::Type::DICTIONARY);
+    dict.SetKey("stream_id",
+                NetLogNumberValue(static_cast<uint64_t>(stream_id)));
+    dict.SetKey("push_id", NetLogNumberValue(static_cast<uint64_t>(push_id)));
+    dict.SetKey("headers", NetLogHeadersToDict(header_block));
+    return dict;
+  });
 }
 
 }  // namespace net

net/quic/quic_http3_logger.h

@@ -26,11 +26,53 @@ class NET_EXPORT_PRIVATE QuicHttp3Logger : public quic::Http3DebugVisitor {
   ~QuicHttp3Logger() override;
 
   // Implementation of Http3DebugVisitor.
+  void OnControlStreamCreated(quic::QuicStreamId stream_id) override;
+  void OnQpackEncoderStreamCreated(quic::QuicStreamId stream_id) override;
+  void OnQpackDecoderStreamCreated(quic::QuicStreamId stream_id) override;
   void OnPeerControlStreamCreated(quic::QuicStreamId stream_id) override;
   void OnPeerQpackEncoderStreamCreated(quic::QuicStreamId stream_id) override;
   void OnPeerQpackDecoderStreamCreated(quic::QuicStreamId stream_id) override;
+
+  void OnCancelPushFrameReceived(const quic::CancelPushFrame& frame) override;
   void OnSettingsFrameReceived(const quic::SettingsFrame& frame) override;
+  void OnGoAwayFrameReceived(const quic::GoAwayFrame& frame) override;
+  void OnMaxPushIdFrameReceived(const quic::MaxPushIdFrame& frame) override;
+  void OnPriorityUpdateFrameReceived(
+      const quic::PriorityUpdateFrame& frame) override;
+
+  void OnDataFrameReceived(quic::QuicStreamId stream_id,
+                           quic::QuicByteCount payload_length) override;
+  void OnHeadersFrameReceived(
+      quic::QuicStreamId stream_id,
+      quic::QuicByteCount compressed_headers_length) override;
+  void OnHeadersDecoded(quic::QuicStreamId stream_id,
+                        quic::QuicHeaderList headers) override;
+  void OnPushPromiseFrameReceived(
+      quic::QuicStreamId stream_id,
+      quic::QuicStreamId push_id,
+      quic::QuicByteCount compressed_headers_length) override;
+  void OnPushPromiseDecoded(quic::QuicStreamId stream_id,
+                            quic::QuicStreamId push_id,
+                            quic::QuicHeaderList headers) override;
+
+  void OnUnknownFrameReceived(quic::QuicStreamId stream_id,
+                              uint64_t frame_type,
+                              quic::QuicByteCount payload_length) override;
+
   void OnSettingsFrameSent(const quic::SettingsFrame& frame) override;
+  void OnGoAwayFrameSent(quic::QuicStreamId stream_id) override;
+  void OnMaxPushIdFrameSent(const quic::MaxPushIdFrame& frame) override;
+  void OnPriorityUpdateFrameSent(
+      const quic::PriorityUpdateFrame& frame) override;
+
+  void OnDataFrameSent(quic::QuicStreamId stream_id,
+                       quic::QuicByteCount payload_length) override;
+  void OnHeadersFrameSent(quic::QuicStreamId stream_id,
+                          const spdy::SpdyHeaderBlock& header_block) override;
+  void OnPushPromiseFrameSent(
+      quic::QuicStreamId stream_id,
+      quic::QuicStreamId push_id,
+      const spdy::SpdyHeaderBlock& header_block) override;
 
  private:
   NetLogWithSource net_log_;