1 // Copyright 2019 The Chromium Authors
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 #include "net/quic/quic_http3_logger.h"
5
6 #include <algorithm>
7 #include <memory>
8 #include <utility>
9 #include <vector>
10
11 #include "base/metrics/histogram_macros.h"
12 #include "base/strings/strcat.h"
13 #include "base/strings/string_number_conversions.h"
14 #include "base/strings/string_piece.h"
15 #include "net/http/http_log_util.h"
16 #include "net/log/net_log_capture_mode.h"
17 #include "net/log/net_log_event_type.h"
18 #include "net/log/net_log_values.h"
19 #include "net/spdy/spdy_log_util.h"
20
21 namespace net {
22
23 namespace {
24
NetLogSettingsParams(const quic::SettingsFrame & frame)25 base::Value::Dict NetLogSettingsParams(const quic::SettingsFrame& frame) {
26 base::Value::Dict dict;
27 for (auto setting : frame.values) {
28 dict.Set(
29 quic::H3SettingsToString(
30 static_cast<quic::Http3AndQpackSettingsIdentifiers>(setting.first)),
31 static_cast<int>(setting.second));
32 }
33 return dict;
34 }
35
NetLogPriorityUpdateParams(const quic::PriorityUpdateFrame & frame)36 base::Value::Dict NetLogPriorityUpdateParams(
37 const quic::PriorityUpdateFrame& frame) {
38 base::Value::Dict dict;
39 dict.Set("prioritized_element_id",
40 NetLogNumberValue(frame.prioritized_element_id));
41 dict.Set("priority_field_value", frame.priority_field_value);
42 return dict;
43 }
44
NetLogTwoIntParams(base::StringPiece name1,uint64_t value1,base::StringPiece name2,uint64_t value2)45 base::Value::Dict NetLogTwoIntParams(base::StringPiece name1,
46 uint64_t value1,
47 base::StringPiece name2,
48 uint64_t value2) {
49 base::Value::Dict dict;
50 dict.Set(name1, NetLogNumberValue(value1));
51 dict.Set(name2, NetLogNumberValue(value2));
52 return dict;
53 }
54
NetLogThreeIntParams(base::StringPiece name1,uint64_t value1,base::StringPiece name2,uint64_t value2,base::StringPiece name3,uint64_t value3)55 base::Value::Dict NetLogThreeIntParams(base::StringPiece name1,
56 uint64_t value1,
57 base::StringPiece name2,
58 uint64_t value2,
59 base::StringPiece name3,
60 uint64_t value3) {
61 base::Value::Dict dict;
62 dict.Set(name1, NetLogNumberValue(value1));
63 dict.Set(name2, NetLogNumberValue(value2));
64 dict.Set(name3, NetLogNumberValue(value3));
65 return dict;
66 }
67
ElideQuicHeaderListForNetLog(const quic::QuicHeaderList & headers,NetLogCaptureMode capture_mode)68 base::Value::List ElideQuicHeaderListForNetLog(
69 const quic::QuicHeaderList& headers,
70 NetLogCaptureMode capture_mode) {
71 base::Value::List headers_list;
72 for (const auto& header : headers) {
73 base::StringPiece key = header.first;
74 base::StringPiece value = header.second;
75 headers_list.Append(NetLogStringValue(
76 base::StrCat({key, ": ",
77 ElideHeaderValueForNetLog(capture_mode, std::string(key),
78 std::string(value))})));
79 }
80 return headers_list;
81 }
82
83 } // namespace
84
QuicHttp3Logger(const NetLogWithSource & net_log)85 QuicHttp3Logger::QuicHttp3Logger(const NetLogWithSource& net_log)
86 : net_log_(net_log) {}
87
88 QuicHttp3Logger::~QuicHttp3Logger() = default;
89
OnControlStreamCreated(quic::QuicStreamId stream_id)90 void QuicHttp3Logger::OnControlStreamCreated(quic::QuicStreamId stream_id) {
91 if (!net_log_.IsCapturing()) {
92 return;
93 }
94 net_log_.AddEventWithIntParams(
95 NetLogEventType::HTTP3_LOCAL_CONTROL_STREAM_CREATED, "stream_id",
96 stream_id);
97 }
98
OnQpackEncoderStreamCreated(quic::QuicStreamId stream_id)99 void QuicHttp3Logger::OnQpackEncoderStreamCreated(
100 quic::QuicStreamId stream_id) {
101 if (!net_log_.IsCapturing()) {
102 return;
103 }
104 net_log_.AddEventWithIntParams(
105 NetLogEventType::HTTP3_LOCAL_QPACK_ENCODER_STREAM_CREATED, "stream_id",
106 stream_id);
107 }
108
OnQpackDecoderStreamCreated(quic::QuicStreamId stream_id)109 void QuicHttp3Logger::OnQpackDecoderStreamCreated(
110 quic::QuicStreamId stream_id) {
111 if (!net_log_.IsCapturing()) {
112 return;
113 }
114 net_log_.AddEventWithIntParams(
115 NetLogEventType::HTTP3_LOCAL_QPACK_DECODER_STREAM_CREATED, "stream_id",
116 stream_id);
117 }
118
OnPeerControlStreamCreated(quic::QuicStreamId stream_id)119 void QuicHttp3Logger::OnPeerControlStreamCreated(quic::QuicStreamId stream_id) {
120 if (!net_log_.IsCapturing())
121 return;
122 net_log_.AddEventWithIntParams(
123 NetLogEventType::HTTP3_PEER_CONTROL_STREAM_CREATED, "stream_id",
124 stream_id);
125 }
126
OnPeerQpackEncoderStreamCreated(quic::QuicStreamId stream_id)127 void QuicHttp3Logger::OnPeerQpackEncoderStreamCreated(
128 quic::QuicStreamId stream_id) {
129 if (!net_log_.IsCapturing())
130 return;
131 net_log_.AddEventWithIntParams(
132 NetLogEventType::HTTP3_PEER_QPACK_ENCODER_STREAM_CREATED, "stream_id",
133 stream_id);
134 }
135
OnPeerQpackDecoderStreamCreated(quic::QuicStreamId stream_id)136 void QuicHttp3Logger::OnPeerQpackDecoderStreamCreated(
137 quic::QuicStreamId stream_id) {
138 if (!net_log_.IsCapturing())
139 return;
140 net_log_.AddEventWithIntParams(
141 NetLogEventType::HTTP3_PEER_QPACK_DECODER_STREAM_CREATED, "stream_id",
142 stream_id);
143 }
144
OnSettingsFrameReceived(const quic::SettingsFrame & frame)145 void QuicHttp3Logger::OnSettingsFrameReceived(
146 const quic::SettingsFrame& frame) {
147 // Increment value by one because empty SETTINGS frames are allowed,
148 // but histograms do not support the value zero.
149 UMA_HISTOGRAM_CUSTOM_COUNTS("Net.QuicSession.ReceivedSettings.CountPlusOne",
150 frame.values.size() + 1, /* min = */ 1,
151 /* max = */ 10, /* buckets = */ 10);
152 int reserved_identifier_count = 0;
153 bool settings_extended_connect_enabled = false;
154 for (const auto& value : frame.values) {
155 if (value.first == quic::SETTINGS_QPACK_MAX_TABLE_CAPACITY) {
156 UMA_HISTOGRAM_COUNTS_1M(
157 "Net.QuicSession.ReceivedSettings.MaxTableCapacity2", value.second);
158 } else if (value.first == quic::SETTINGS_MAX_FIELD_SECTION_SIZE) {
159 UMA_HISTOGRAM_COUNTS_1M(
160 "Net.QuicSession.ReceivedSettings.MaxHeaderListSize2", value.second);
161 } else if (value.first == quic::SETTINGS_QPACK_BLOCKED_STREAMS) {
162 UMA_HISTOGRAM_COUNTS_1000(
163 "Net.QuicSession.ReceivedSettings.BlockedStreams", value.second);
164 } else if (value.first == quic::SETTINGS_ENABLE_CONNECT_PROTOCOL) {
165 settings_extended_connect_enabled = value.second == 1;
166 } else if (value.first >= 0x21 && value.first % 0x1f == 2) {
167 // Reserved setting identifiers are defined at
168 // https://quicwg.org/base-drafts/draft-ietf-quic-http.html#name-defined-settings-parameters.
169 // These should not be treated specially on the receive side, because they
170 // are sent to exercise the requirement that unknown identifiers are
171 // ignored. Here an exception is made for logging only, to understand
172 // what kind of identifiers are received.
173 reserved_identifier_count++;
174 }
175 }
176 UMA_HISTOGRAM_CUSTOM_COUNTS(
177 "Net.QuicSession.ReceivedSettings.ReservedCountPlusOne",
178 reserved_identifier_count + 1, /* min = */ 1,
179 /* max = */ 5, /* buckets = */ 5);
180 UMA_HISTOGRAM_BOOLEAN(
181 "Net.QuicSession.ReceivedSettings.EnableExtendedConnect",
182 settings_extended_connect_enabled);
183
184 if (!net_log_.IsCapturing())
185 return;
186 net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_RECEIVED,
187 [&frame] { return NetLogSettingsParams(frame); });
188 }
189
OnGoAwayFrameReceived(const quic::GoAwayFrame & frame)190 void QuicHttp3Logger::OnGoAwayFrameReceived(const quic::GoAwayFrame& frame) {
191 if (!net_log_.IsCapturing()) {
192 return;
193 }
194 net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_GOAWAY_RECEIVED,
195 "stream_id", frame.id);
196 }
197
OnPriorityUpdateFrameReceived(const quic::PriorityUpdateFrame & frame)198 void QuicHttp3Logger::OnPriorityUpdateFrameReceived(
199 const quic::PriorityUpdateFrame& frame) {
200 if (!net_log_.IsCapturing()) {
201 return;
202 }
203 net_log_.AddEvent(NetLogEventType::HTTP3_PRIORITY_UPDATE_RECEIVED,
204 [&frame] { return NetLogPriorityUpdateParams(frame); });
205 }
206
OnDataFrameReceived(quic::QuicStreamId stream_id,quic::QuicByteCount payload_length)207 void QuicHttp3Logger::OnDataFrameReceived(quic::QuicStreamId stream_id,
208 quic::QuicByteCount payload_length) {
209 if (!net_log_.IsCapturing()) {
210 return;
211 }
212 net_log_.AddEvent(
213 NetLogEventType::HTTP3_DATA_FRAME_RECEIVED, [stream_id, payload_length] {
214 return NetLogTwoIntParams("stream_id", stream_id, "payload_length",
215 payload_length);
216 });
217 }
218
OnHeadersFrameReceived(quic::QuicStreamId stream_id,quic::QuicByteCount compressed_headers_length)219 void QuicHttp3Logger::OnHeadersFrameReceived(
220 quic::QuicStreamId stream_id,
221 quic::QuicByteCount compressed_headers_length) {
222 if (!net_log_.IsCapturing()) {
223 return;
224 }
225 net_log_.AddEvent(NetLogEventType::HTTP3_HEADERS_RECEIVED,
226 [stream_id, compressed_headers_length] {
227 return NetLogTwoIntParams("stream_id", stream_id,
228 "compressed_headers_length",
229 compressed_headers_length);
230 });
231 }
232
OnHeadersDecoded(quic::QuicStreamId stream_id,quic::QuicHeaderList headers)233 void QuicHttp3Logger::OnHeadersDecoded(quic::QuicStreamId stream_id,
234 quic::QuicHeaderList headers) {
235 if (!net_log_.IsCapturing()) {
236 return;
237 }
238 net_log_.AddEvent(
239 NetLogEventType::HTTP3_HEADERS_DECODED,
240 [stream_id, &headers](NetLogCaptureMode capture_mode) {
241 base::Value::Dict dict;
242 dict.Set("stream_id",
243 NetLogNumberValue(static_cast<uint64_t>(stream_id)));
244 dict.Set("headers",
245 ElideQuicHeaderListForNetLog(headers, capture_mode));
246 return dict;
247 });
248 }
249
OnUnknownFrameReceived(quic::QuicStreamId stream_id,uint64_t frame_type,quic::QuicByteCount payload_length)250 void QuicHttp3Logger::OnUnknownFrameReceived(
251 quic::QuicStreamId stream_id,
252 uint64_t frame_type,
253 quic::QuicByteCount payload_length) {
254 if (!net_log_.IsCapturing()) {
255 return;
256 }
257 net_log_.AddEvent(NetLogEventType::HTTP3_UNKNOWN_FRAME_RECEIVED,
258 [stream_id, frame_type, payload_length] {
259 return NetLogThreeIntParams(
260 "stream_id", stream_id, "frame_type", frame_type,
261 "payload_length", payload_length);
262 });
263 }
264
OnSettingsFrameSent(const quic::SettingsFrame & frame)265 void QuicHttp3Logger::OnSettingsFrameSent(const quic::SettingsFrame& frame) {
266 if (!net_log_.IsCapturing())
267 return;
268 net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_SENT,
269 [&frame] { return NetLogSettingsParams(frame); });
270 }
271
OnSettingsFrameResumed(const quic::SettingsFrame & frame)272 void QuicHttp3Logger::OnSettingsFrameResumed(const quic::SettingsFrame& frame) {
273 if (!net_log_.IsCapturing())
274 return;
275 net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_RESUMED,
276 [&frame] { return NetLogSettingsParams(frame); });
277 }
278
OnGoAwayFrameSent(quic::QuicStreamId stream_id)279 void QuicHttp3Logger::OnGoAwayFrameSent(quic::QuicStreamId stream_id) {
280 if (!net_log_.IsCapturing()) {
281 return;
282 }
283 net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_GOAWAY_SENT,
284 "stream_id", stream_id);
285 }
286
OnPriorityUpdateFrameSent(const quic::PriorityUpdateFrame & frame)287 void QuicHttp3Logger::OnPriorityUpdateFrameSent(
288 const quic::PriorityUpdateFrame& frame) {
289 if (!net_log_.IsCapturing()) {
290 return;
291 }
292 net_log_.AddEvent(NetLogEventType::HTTP3_PRIORITY_UPDATE_SENT,
293 [&frame] { return NetLogPriorityUpdateParams(frame); });
294 }
295
OnDataFrameSent(quic::QuicStreamId stream_id,quic::QuicByteCount payload_length)296 void QuicHttp3Logger::OnDataFrameSent(quic::QuicStreamId stream_id,
297 quic::QuicByteCount payload_length) {
298 if (!net_log_.IsCapturing()) {
299 return;
300 }
301 net_log_.AddEvent(
302 NetLogEventType::HTTP3_DATA_SENT, [stream_id, payload_length] {
303 return NetLogTwoIntParams("stream_id", stream_id, "payload_length",
304 payload_length);
305 });
306 }
307
OnHeadersFrameSent(quic::QuicStreamId stream_id,const spdy::Http2HeaderBlock & header_block)308 void QuicHttp3Logger::OnHeadersFrameSent(
309 quic::QuicStreamId stream_id,
310 const spdy::Http2HeaderBlock& header_block) {
311 if (!net_log_.IsCapturing()) {
312 return;
313 }
314 net_log_.AddEvent(
315 NetLogEventType::HTTP3_HEADERS_SENT,
316 [stream_id, &header_block](NetLogCaptureMode capture_mode) {
317 base::Value::Dict dict;
318 dict.Set("stream_id",
319 NetLogNumberValue(static_cast<uint64_t>(stream_id)));
320 dict.Set("headers",
321 ElideHttp2HeaderBlockForNetLog(header_block, capture_mode));
322 return dict;
323 });
324 }
325
326 } // namespace net
327