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