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 <string_view>
9 #include <utility>
10 #include <vector>
11
12 #include "base/metrics/histogram_macros.h"
13 #include "base/strings/strcat.h"
14 #include "base/strings/string_number_conversions.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(std::string_view name1,uint64_t value1,std::string_view name2,uint64_t value2)44 base::Value::Dict NetLogTwoIntParams(std::string_view name1,
45 uint64_t value1,
46 std::string_view name2,
47 uint64_t value2) {
48 return base::Value::Dict()
49 .Set(name1, NetLogNumberValue(value1))
50 .Set(name2, NetLogNumberValue(value2));
51 }
52
NetLogThreeIntParams(std::string_view name1,uint64_t value1,std::string_view name2,uint64_t value2,std::string_view name3,uint64_t value3)53 base::Value::Dict NetLogThreeIntParams(std::string_view name1,
54 uint64_t value1,
55 std::string_view name2,
56 uint64_t value2,
57 std::string_view 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 std::string_view key = header.first;
71 std::string_view 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 for (const auto& value : frame.values) {
151 if (value.first == quic::SETTINGS_QPACK_MAX_TABLE_CAPACITY) {
152 UMA_HISTOGRAM_COUNTS_1M(
153 "Net.QuicSession.ReceivedSettings.MaxTableCapacity2", value.second);
154 } else if (value.first == quic::SETTINGS_MAX_FIELD_SECTION_SIZE) {
155 UMA_HISTOGRAM_COUNTS_1M(
156 "Net.QuicSession.ReceivedSettings.MaxHeaderListSize2", value.second);
157 } else if (value.first == quic::SETTINGS_QPACK_BLOCKED_STREAMS) {
158 UMA_HISTOGRAM_COUNTS_1000(
159 "Net.QuicSession.ReceivedSettings.BlockedStreams", value.second);
160 } else if (value.first >= 0x21 && value.first % 0x1f == 2) {
161 // Reserved setting identifiers are defined at
162 // https://quicwg.org/base-drafts/draft-ietf-quic-http.html#name-defined-settings-parameters.
163 // These should not be treated specially on the receive side, because they
164 // are sent to exercise the requirement that unknown identifiers are
165 // ignored. Here an exception is made for logging only, to understand
166 // what kind of identifiers are received.
167 reserved_identifier_count++;
168 }
169 }
170 UMA_HISTOGRAM_CUSTOM_COUNTS(
171 "Net.QuicSession.ReceivedSettings.ReservedCountPlusOne",
172 reserved_identifier_count + 1, /* min = */ 1,
173 /* max = */ 5, /* buckets = */ 5);
174
175 if (!net_log_.IsCapturing())
176 return;
177 net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_RECEIVED,
178 [&frame] { return NetLogSettingsParams(frame); });
179 }
180
OnGoAwayFrameReceived(const quic::GoAwayFrame & frame)181 void QuicHttp3Logger::OnGoAwayFrameReceived(const quic::GoAwayFrame& frame) {
182 if (!net_log_.IsCapturing()) {
183 return;
184 }
185 net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_GOAWAY_RECEIVED,
186 "stream_id", frame.id);
187 }
188
OnPriorityUpdateFrameReceived(const quic::PriorityUpdateFrame & frame)189 void QuicHttp3Logger::OnPriorityUpdateFrameReceived(
190 const quic::PriorityUpdateFrame& frame) {
191 if (!net_log_.IsCapturing()) {
192 return;
193 }
194 net_log_.AddEvent(NetLogEventType::HTTP3_PRIORITY_UPDATE_RECEIVED,
195 [&frame] { return NetLogPriorityUpdateParams(frame); });
196 }
197
OnDataFrameReceived(quic::QuicStreamId stream_id,quic::QuicByteCount payload_length)198 void QuicHttp3Logger::OnDataFrameReceived(quic::QuicStreamId stream_id,
199 quic::QuicByteCount payload_length) {
200 if (!net_log_.IsCapturing()) {
201 return;
202 }
203 net_log_.AddEvent(
204 NetLogEventType::HTTP3_DATA_FRAME_RECEIVED, [stream_id, payload_length] {
205 return NetLogTwoIntParams("stream_id", stream_id, "payload_length",
206 payload_length);
207 });
208 }
209
OnHeadersFrameReceived(quic::QuicStreamId stream_id,quic::QuicByteCount compressed_headers_length)210 void QuicHttp3Logger::OnHeadersFrameReceived(
211 quic::QuicStreamId stream_id,
212 quic::QuicByteCount compressed_headers_length) {
213 if (!net_log_.IsCapturing()) {
214 return;
215 }
216 net_log_.AddEvent(NetLogEventType::HTTP3_HEADERS_RECEIVED,
217 [stream_id, compressed_headers_length] {
218 return NetLogTwoIntParams("stream_id", stream_id,
219 "compressed_headers_length",
220 compressed_headers_length);
221 });
222 }
223
OnHeadersDecoded(quic::QuicStreamId stream_id,quic::QuicHeaderList headers)224 void QuicHttp3Logger::OnHeadersDecoded(quic::QuicStreamId stream_id,
225 quic::QuicHeaderList headers) {
226 if (!net_log_.IsCapturing()) {
227 return;
228 }
229 net_log_.AddEvent(
230 NetLogEventType::HTTP3_HEADERS_DECODED,
231 [stream_id, &headers](NetLogCaptureMode capture_mode) {
232 return base::Value::Dict()
233 .Set("stream_id",
234 NetLogNumberValue(static_cast<uint64_t>(stream_id)))
235 .Set("headers",
236 ElideQuicHeaderListForNetLog(headers, capture_mode));
237 });
238 }
239
OnUnknownFrameReceived(quic::QuicStreamId stream_id,uint64_t frame_type,quic::QuicByteCount payload_length)240 void QuicHttp3Logger::OnUnknownFrameReceived(
241 quic::QuicStreamId stream_id,
242 uint64_t frame_type,
243 quic::QuicByteCount payload_length) {
244 if (!net_log_.IsCapturing()) {
245 return;
246 }
247 net_log_.AddEvent(NetLogEventType::HTTP3_UNKNOWN_FRAME_RECEIVED,
248 [stream_id, frame_type, payload_length] {
249 return NetLogThreeIntParams(
250 "stream_id", stream_id, "frame_type", frame_type,
251 "payload_length", payload_length);
252 });
253 }
254
OnSettingsFrameSent(const quic::SettingsFrame & frame)255 void QuicHttp3Logger::OnSettingsFrameSent(const quic::SettingsFrame& frame) {
256 if (!net_log_.IsCapturing())
257 return;
258 net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_SENT,
259 [&frame] { return NetLogSettingsParams(frame); });
260 }
261
OnSettingsFrameResumed(const quic::SettingsFrame & frame)262 void QuicHttp3Logger::OnSettingsFrameResumed(const quic::SettingsFrame& frame) {
263 if (!net_log_.IsCapturing())
264 return;
265 net_log_.AddEvent(NetLogEventType::HTTP3_SETTINGS_RESUMED,
266 [&frame] { return NetLogSettingsParams(frame); });
267 }
268
OnGoAwayFrameSent(quic::QuicStreamId stream_id)269 void QuicHttp3Logger::OnGoAwayFrameSent(quic::QuicStreamId stream_id) {
270 if (!net_log_.IsCapturing()) {
271 return;
272 }
273 net_log_.AddEventWithIntParams(NetLogEventType::HTTP3_GOAWAY_SENT,
274 "stream_id", stream_id);
275 }
276
OnPriorityUpdateFrameSent(const quic::PriorityUpdateFrame & frame)277 void QuicHttp3Logger::OnPriorityUpdateFrameSent(
278 const quic::PriorityUpdateFrame& frame) {
279 if (!net_log_.IsCapturing()) {
280 return;
281 }
282 net_log_.AddEvent(NetLogEventType::HTTP3_PRIORITY_UPDATE_SENT,
283 [&frame] { return NetLogPriorityUpdateParams(frame); });
284 }
285
OnDataFrameSent(quic::QuicStreamId stream_id,quic::QuicByteCount payload_length)286 void QuicHttp3Logger::OnDataFrameSent(quic::QuicStreamId stream_id,
287 quic::QuicByteCount payload_length) {
288 if (!net_log_.IsCapturing()) {
289 return;
290 }
291 net_log_.AddEvent(
292 NetLogEventType::HTTP3_DATA_SENT, [stream_id, payload_length] {
293 return NetLogTwoIntParams("stream_id", stream_id, "payload_length",
294 payload_length);
295 });
296 }
297
OnHeadersFrameSent(quic::QuicStreamId stream_id,const spdy::Http2HeaderBlock & header_block)298 void QuicHttp3Logger::OnHeadersFrameSent(
299 quic::QuicStreamId stream_id,
300 const spdy::Http2HeaderBlock& header_block) {
301 if (!net_log_.IsCapturing()) {
302 return;
303 }
304 net_log_.AddEvent(
305 NetLogEventType::HTTP3_HEADERS_SENT,
306 [stream_id, &header_block](NetLogCaptureMode capture_mode) {
307 return base::Value::Dict()
308 .Set("stream_id",
309 NetLogNumberValue(static_cast<uint64_t>(stream_id)))
310 .Set("headers",
311 ElideHttp2HeaderBlockForNetLog(header_block, capture_mode));
312 });
313 }
314
315 } // namespace net
316