1 // Copyright (c) 2013 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #include "net/quic/quic_connection_logger.h"
6 
7 #include <algorithm>
8 #include <limits>
9 #include <memory>
10 #include <utility>
11 #include <vector>
12 
13 #include "base/metrics/histogram_base.h"
14 #include "base/metrics/histogram_functions.h"
15 #include "base/metrics/histogram_macros.h"
16 #include "base/values.h"
17 #include "net/base/ip_address.h"
18 #include "net/cert/x509_certificate.h"
19 #include "net/log/net_log_capture_mode.h"
20 #include "net/log/net_log_event_type.h"
21 #include "net/log/net_log_values.h"
22 #include "net/quic/address_utils.h"
23 #include "net/quic/quic_address_mismatch.h"
24 #include "net/third_party/quiche/src/common/platform/api/quiche_string_piece.h"
25 #include "net/third_party/quiche/src/quic/core/crypto/crypto_handshake_message.h"
26 #include "net/third_party/quiche/src/quic/core/crypto/crypto_protocol.h"
27 #include "net/third_party/quiche/src/quic/core/quic_connection_id.h"
28 #include "net/third_party/quiche/src/quic/core/quic_packets.h"
29 #include "net/third_party/quiche/src/quic/core/quic_socket_address_coder.h"
30 #include "net/third_party/quiche/src/quic/core/quic_time.h"
31 #include "net/third_party/quiche/src/quic/core/quic_utils.h"
32 
33 using quic::kMaxOutgoingPacketSize;
34 using std::string;
35 
36 namespace net {
37 
38 namespace {
39 
NetLogQuicPacketParams(const quic::QuicSocketAddress & self_address,const quic::QuicSocketAddress & peer_address,size_t packet_size)40 base::Value NetLogQuicPacketParams(const quic::QuicSocketAddress& self_address,
41                                    const quic::QuicSocketAddress& peer_address,
42                                    size_t packet_size) {
43   base::Value dict(base::Value::Type::DICTIONARY);
44   dict.SetStringKey("self_address", self_address.ToString());
45   dict.SetStringKey("peer_address", peer_address.ToString());
46   dict.SetIntKey("size", packet_size);
47   return dict;
48 }
49 
NetLogQuicPacketSentParams(const quic::SerializedPacket & serialized_packet,quic::TransmissionType transmission_type,quic::QuicTime sent_time)50 base::Value NetLogQuicPacketSentParams(
51     const quic::SerializedPacket& serialized_packet,
52     quic::TransmissionType transmission_type,
53     quic::QuicTime sent_time) {
54   base::Value dict(base::Value::Type::DICTIONARY);
55   dict.SetStringKey("transmission_type",
56                     quic::TransmissionTypeToString(transmission_type));
57   dict.SetKey("packet_number",
58               NetLogNumberValue(serialized_packet.packet_number.ToUint64()));
59   dict.SetIntKey("size", serialized_packet.encrypted_length);
60   dict.SetKey("sent_time_us", NetLogNumberValue(sent_time.ToDebuggingValue()));
61   dict.SetStringKey(
62       "encryption_level",
63       quic::EncryptionLevelToString(serialized_packet.encryption_level));
64   return dict;
65 }
66 
NetLogQuicPacketLostParams(quic::QuicPacketNumber packet_number,quic::TransmissionType transmission_type,quic::QuicTime detection_time)67 base::Value NetLogQuicPacketLostParams(quic::QuicPacketNumber packet_number,
68                                        quic::TransmissionType transmission_type,
69                                        quic::QuicTime detection_time) {
70   base::Value dict(base::Value::Type::DICTIONARY);
71   dict.SetStringKey("transmission_type",
72                     quic::TransmissionTypeToString(transmission_type));
73   dict.SetKey("packet_number", NetLogNumberValue(packet_number.ToUint64()));
74   dict.SetKey("detection_time_us",
75               NetLogNumberValue(detection_time.ToDebuggingValue()));
76   return dict;
77 }
78 
NetLogQuicDuplicatePacketParams(quic::QuicPacketNumber packet_number)79 base::Value NetLogQuicDuplicatePacketParams(
80     quic::QuicPacketNumber packet_number) {
81   base::Value dict(base::Value::Type::DICTIONARY);
82   dict.SetKey("packet_number", NetLogNumberValue(packet_number.ToUint64()));
83   return dict;
84 }
85 
NetLogQuicPacketHeaderParams(const quic::QuicPacketHeader * header,bool is_ietf_quic)86 base::Value NetLogQuicPacketHeaderParams(const quic::QuicPacketHeader* header,
87                                          bool is_ietf_quic) {
88   base::Value dict(base::Value::Type::DICTIONARY);
89   dict.SetStringKey("connection_id",
90                     header->destination_connection_id.ToString());
91   dict.SetKey("packet_number",
92               NetLogNumberValue(header->packet_number.ToUint64()));
93   dict.SetStringKey("header_format",
94                     quic::PacketHeaderFormatToString(header->form));
95   if (header->form == quic::IETF_QUIC_LONG_HEADER_PACKET) {
96     dict.SetStringKey("long_header_type", quic::QuicLongHeaderTypeToString(
97                                               header->long_packet_type));
98   }
99   if (!is_ietf_quic) {
100     dict.SetIntKey("reset_flag", header->reset_flag);
101     dict.SetIntKey("version_flag", header->version_flag);
102   }
103   return dict;
104 }
105 
NetLogQuicStreamFrameParams(const quic::QuicStreamFrame & frame)106 base::Value NetLogQuicStreamFrameParams(const quic::QuicStreamFrame& frame) {
107   base::Value dict(base::Value::Type::DICTIONARY);
108   dict.SetIntKey("stream_id", frame.stream_id);
109   dict.SetBoolKey("fin", frame.fin);
110   dict.SetKey("offset", NetLogNumberValue(frame.offset));
111   dict.SetIntKey("length", frame.data_length);
112   return dict;
113 }
114 
NetLogQuicAckFrameParams(const quic::QuicAckFrame * frame)115 base::Value NetLogQuicAckFrameParams(const quic::QuicAckFrame* frame) {
116   base::Value dict(base::Value::Type::DICTIONARY);
117   dict.SetKey("largest_observed",
118               NetLogNumberValue(frame->largest_acked.ToUint64()));
119   dict.SetKey("delta_time_largest_observed_us",
120               NetLogNumberValue(frame->ack_delay_time.ToMicroseconds()));
121 
122   base::Value missing(base::Value::Type::LIST);
123   if (!frame->packets.Empty()) {
124     // V34 and above express acked packets, but only print
125     // missing packets, because it's typically a shorter list.
126     for (quic::QuicPacketNumber packet = frame->packets.Min();
127          packet < frame->largest_acked; ++packet) {
128       if (!frame->packets.Contains(packet)) {
129         missing.Append(NetLogNumberValue(packet.ToUint64()));
130       }
131     }
132   }
133   dict.SetKey("missing_packets", std::move(missing));
134 
135   base::Value received(base::Value::Type::LIST);
136   const quic::PacketTimeVector& received_times = frame->received_packet_times;
137   for (auto it = received_times.begin(); it != received_times.end(); ++it) {
138     base::Value info(base::Value::Type::DICTIONARY);
139     info.SetKey("packet_number", NetLogNumberValue(it->first.ToUint64()));
140     info.SetKey("received", NetLogNumberValue(it->second.ToDebuggingValue()));
141     received.Append(std::move(info));
142   }
143   dict.SetKey("received_packet_times", std::move(received));
144 
145   return dict;
146 }
147 
NetLogQuicRstStreamFrameParams(const quic::QuicRstStreamFrame * frame)148 base::Value NetLogQuicRstStreamFrameParams(
149     const quic::QuicRstStreamFrame* frame) {
150   base::Value dict(base::Value::Type::DICTIONARY);
151   dict.SetIntKey("stream_id", frame->stream_id);
152   dict.SetIntKey("quic_rst_stream_error", frame->error_code);
153   dict.SetKey("offset", NetLogNumberValue(frame->byte_offset));
154   return dict;
155 }
156 
NetLogQuicConnectionCloseFrameParams(const quic::QuicConnectionCloseFrame * frame)157 base::Value NetLogQuicConnectionCloseFrameParams(
158     const quic::QuicConnectionCloseFrame* frame) {
159   base::Value dict(base::Value::Type::DICTIONARY);
160   dict.SetIntKey("quic_error", frame->quic_error_code);
161   dict.SetStringKey("details", frame->error_details);
162   return dict;
163 }
164 
NetLogQuicWindowUpdateFrameParams(const quic::QuicWindowUpdateFrame * frame)165 base::Value NetLogQuicWindowUpdateFrameParams(
166     const quic::QuicWindowUpdateFrame* frame) {
167   base::Value dict(base::Value::Type::DICTIONARY);
168   dict.SetIntKey("stream_id", frame->stream_id);
169   dict.SetKey("byte_offset", NetLogNumberValue(frame->max_data));
170   return dict;
171 }
172 
NetLogQuicBlockedFrameParams(const quic::QuicBlockedFrame * frame)173 base::Value NetLogQuicBlockedFrameParams(const quic::QuicBlockedFrame* frame) {
174   base::Value dict(base::Value::Type::DICTIONARY);
175   dict.SetIntKey("stream_id", frame->stream_id);
176   return dict;
177 }
178 
NetLogQuicGoAwayFrameParams(const quic::QuicGoAwayFrame * frame)179 base::Value NetLogQuicGoAwayFrameParams(const quic::QuicGoAwayFrame* frame) {
180   base::Value dict(base::Value::Type::DICTIONARY);
181   dict.SetIntKey("quic_error", frame->error_code);
182   dict.SetIntKey("last_good_stream_id", frame->last_good_stream_id);
183   dict.SetStringKey("reason_phrase", frame->reason_phrase);
184   return dict;
185 }
186 
NetLogQuicStopWaitingFrameParams(const quic::QuicStopWaitingFrame * frame)187 base::Value NetLogQuicStopWaitingFrameParams(
188     const quic::QuicStopWaitingFrame* frame) {
189   base::Value dict(base::Value::Type::DICTIONARY);
190   dict.SetKey("least_unacked",
191               NetLogNumberValue(frame->least_unacked.ToUint64()));
192   return dict;
193 }
194 
NetLogQuicVersionNegotiationPacketParams(const quic::QuicVersionNegotiationPacket * packet)195 base::Value NetLogQuicVersionNegotiationPacketParams(
196     const quic::QuicVersionNegotiationPacket* packet) {
197   base::Value dict(base::Value::Type::DICTIONARY);
198   base::Value versions(base::Value::Type::LIST);
199   for (auto it = packet->versions.begin(); it != packet->versions.end(); ++it) {
200     versions.Append(ParsedQuicVersionToString(*it));
201   }
202   dict.SetKey("versions", std::move(versions));
203   return dict;
204 }
205 
NetLogQuicPublicResetPacketParams(const IPEndPoint & server_hello_address,const quic::QuicSocketAddress & public_reset_address)206 base::Value NetLogQuicPublicResetPacketParams(
207     const IPEndPoint& server_hello_address,
208     const quic::QuicSocketAddress& public_reset_address) {
209   base::Value dict(base::Value::Type::DICTIONARY);
210   dict.SetStringKey("server_hello_address", server_hello_address.ToString());
211   dict.SetStringKey("public_reset_address", public_reset_address.ToString());
212   return dict;
213 }
214 
NetLogQuicPathData(const quic::QuicPathFrameBuffer & buffer)215 base::Value NetLogQuicPathData(const quic::QuicPathFrameBuffer& buffer) {
216   base::Value dict(base::Value::Type::DICTIONARY);
217   dict.SetKey("data",
218               NetLogBinaryValue(reinterpret_cast<const char*>(buffer.data()),
219                                 buffer.size()));
220   return dict;
221 }
222 
NetLogQuicCryptoHandshakeMessageParams(const quic::CryptoHandshakeMessage * message)223 base::Value NetLogQuicCryptoHandshakeMessageParams(
224     const quic::CryptoHandshakeMessage* message) {
225   base::Value dict(base::Value::Type::DICTIONARY);
226   dict.SetStringKey("quic_crypto_handshake_message", message->DebugString());
227   return dict;
228 }
229 
NetLogQuicOnConnectionClosedParams(quic::QuicErrorCode error,string error_details,quic::ConnectionCloseSource source)230 base::Value NetLogQuicOnConnectionClosedParams(
231     quic::QuicErrorCode error,
232     string error_details,
233     quic::ConnectionCloseSource source) {
234   base::Value dict(base::Value::Type::DICTIONARY);
235   dict.SetIntKey("quic_error", error);
236   dict.SetStringKey("details", error_details);
237   dict.SetBoolKey("from_peer", source == quic::ConnectionCloseSource::FROM_PEER
238                                    ? true
239                                    : false);
240   return dict;
241 }
242 
NetLogQuicCertificateVerifiedParams(scoped_refptr<X509Certificate> cert)243 base::Value NetLogQuicCertificateVerifiedParams(
244     scoped_refptr<X509Certificate> cert) {
245   // Only the subjects are logged so that we can investigate connection pooling.
246   // More fields could be logged in the future.
247   std::vector<std::string> dns_names;
248   cert->GetSubjectAltName(&dns_names, nullptr);
249   base::Value dict(base::Value::Type::DICTIONARY);
250   base::Value subjects(base::Value::Type::LIST);
251   for (auto& dns_name : dns_names) {
252     subjects.Append(std::move(dns_name));
253   }
254   dict.SetKey("subjects", std::move(subjects));
255   return dict;
256 }
257 
NetLogQuicCryptoFrameParams(const quic::QuicCryptoFrame * frame,bool has_buffer)258 base::Value NetLogQuicCryptoFrameParams(const quic::QuicCryptoFrame* frame,
259                                         bool has_buffer) {
260   base::Value dict(base::Value::Type::DICTIONARY);
261   dict.SetStringKey("encryption_level",
262                     quic::EncryptionLevelToString(frame->level));
263   dict.SetIntKey("data_length", frame->data_length);
264   dict.SetKey("offset", NetLogNumberValue(frame->offset));
265   if (has_buffer) {
266     dict.SetKey("bytes", NetLogBinaryValue(
267                              reinterpret_cast<const void*>(frame->data_buffer),
268                              frame->data_length));
269   }
270   return dict;
271 }
272 
NetLogQuicStopSendingFrameParams(const quic::QuicStopSendingFrame * frame)273 base::Value NetLogQuicStopSendingFrameParams(
274     const quic::QuicStopSendingFrame* frame) {
275   base::Value dict(base::Value::Type::DICTIONARY);
276   dict.SetIntKey("stream_id", frame->stream_id);
277   dict.SetIntKey("application_error_code", frame->application_error_code);
278   return dict;
279 }
280 
NetLogQuicStreamsBlockedFrameParams(const quic::QuicStreamsBlockedFrame & frame)281 base::Value NetLogQuicStreamsBlockedFrameParams(
282     const quic::QuicStreamsBlockedFrame& frame) {
283   base::Value dict(base::Value::Type::DICTIONARY);
284   dict.SetIntKey("stream_count", frame.stream_count);
285   dict.SetBoolKey("is_unidirectional", frame.unidirectional);
286   return dict;
287 }
288 
NetLogQuicMaxStreamsFrameParams(const quic::QuicMaxStreamsFrame & frame)289 base::Value NetLogQuicMaxStreamsFrameParams(
290     const quic::QuicMaxStreamsFrame& frame) {
291   base::Value dict(base::Value::Type::DICTIONARY);
292   dict.SetIntKey("stream_count", frame.stream_count);
293   dict.SetBoolKey("is_unidirectional", frame.unidirectional);
294   return dict;
295 }
296 
NetLogQuicNewConnectionIdFrameParams(const quic::QuicNewConnectionIdFrame * frame)297 base::Value NetLogQuicNewConnectionIdFrameParams(
298     const quic::QuicNewConnectionIdFrame* frame) {
299   base::Value dict(base::Value::Type::DICTIONARY);
300   dict.SetStringKey("connection_id", frame->connection_id.ToString());
301   dict.SetKey("sequence_number", NetLogNumberValue(frame->sequence_number));
302   dict.SetKey("retire_prior_to", NetLogNumberValue(frame->retire_prior_to));
303   return dict;
304 }
305 
NetLogQuicRetireConnectionIdFrameParams(const quic::QuicRetireConnectionIdFrame * frame)306 base::Value NetLogQuicRetireConnectionIdFrameParams(
307     const quic::QuicRetireConnectionIdFrame* frame) {
308   base::Value dict(base::Value::Type::DICTIONARY);
309   dict.SetKey("sequence_number", NetLogNumberValue(frame->sequence_number));
310   return dict;
311 }
312 
NetLogQuicNewTokenFrameParams(const quic::QuicNewTokenFrame * frame)313 base::Value NetLogQuicNewTokenFrameParams(
314     const quic::QuicNewTokenFrame* frame) {
315   base::Value dict(base::Value::Type::DICTIONARY);
316   dict.SetKey("token", NetLogBinaryValue(
317                            reinterpret_cast<const void*>(frame->token.data()),
318                            frame->token.length()));
319   return dict;
320 }
321 
UpdatePublicResetAddressMismatchHistogram(const IPEndPoint & server_hello_address,const IPEndPoint & public_reset_address)322 void UpdatePublicResetAddressMismatchHistogram(
323     const IPEndPoint& server_hello_address,
324     const IPEndPoint& public_reset_address) {
325   int sample = GetAddressMismatch(server_hello_address, public_reset_address);
326   // We are seemingly talking to an older server that does not support the
327   // feature, so we can't report the results in the histogram.
328   if (sample < 0) {
329     return;
330   }
331   UMA_HISTOGRAM_ENUMERATION("Net.QuicSession.PublicResetAddressMismatch2",
332                             static_cast<QuicAddressMismatch>(sample),
333                             QUIC_ADDRESS_MISMATCH_MAX);
334 }
335 
336 // If |address| is an IPv4-mapped IPv6 address, returns ADDRESS_FAMILY_IPV4
337 // instead of ADDRESS_FAMILY_IPV6. Othewise, behaves like GetAddressFamily().
GetRealAddressFamily(const IPAddress & address)338 AddressFamily GetRealAddressFamily(const IPAddress& address) {
339   return address.IsIPv4MappedIPv6() ? ADDRESS_FAMILY_IPV4
340                                     : GetAddressFamily(address);
341 }
342 
343 }  // namespace
344 
QuicConnectionLogger(quic::QuicSpdySession * session,const char * const connection_description,std::unique_ptr<SocketPerformanceWatcher> socket_performance_watcher,const NetLogWithSource & net_log)345 QuicConnectionLogger::QuicConnectionLogger(
346     quic::QuicSpdySession* session,
347     const char* const connection_description,
348     std::unique_ptr<SocketPerformanceWatcher> socket_performance_watcher,
349     const NetLogWithSource& net_log)
350     : net_log_(net_log),
351       session_(session),
352       last_received_packet_size_(0),
353       no_packet_received_after_ping_(false),
354       previous_received_packet_size_(0),
355       num_out_of_order_received_packets_(0),
356       num_out_of_order_large_received_packets_(0),
357       num_packets_received_(0),
358       num_frames_received_(0),
359       num_duplicate_frames_received_(0),
360       num_incorrect_connection_ids_(0),
361       num_undecryptable_packets_(0),
362       num_duplicate_packets_(0),
363       num_blocked_frames_received_(0),
364       num_blocked_frames_sent_(0),
365       connection_description_(connection_description),
366       socket_performance_watcher_(std::move(socket_performance_watcher)) {}
367 
~QuicConnectionLogger()368 QuicConnectionLogger::~QuicConnectionLogger() {
369   UMA_HISTOGRAM_COUNTS_1M("Net.QuicSession.OutOfOrderPacketsReceived",
370                           num_out_of_order_received_packets_);
371   UMA_HISTOGRAM_COUNTS_1M("Net.QuicSession.OutOfOrderLargePacketsReceived",
372                           num_out_of_order_large_received_packets_);
373   UMA_HISTOGRAM_COUNTS_1M("Net.QuicSession.IncorrectConnectionIDsReceived",
374                           num_incorrect_connection_ids_);
375   UMA_HISTOGRAM_COUNTS_1M("Net.QuicSession.UndecryptablePacketsReceived",
376                           num_undecryptable_packets_);
377   UMA_HISTOGRAM_COUNTS_1M("Net.QuicSession.DuplicatePacketsReceived",
378                           num_duplicate_packets_);
379   UMA_HISTOGRAM_COUNTS_1M("Net.QuicSession.BlockedFrames.Received",
380                           num_blocked_frames_received_);
381   UMA_HISTOGRAM_COUNTS_1M("Net.QuicSession.BlockedFrames.Sent",
382                           num_blocked_frames_sent_);
383 
384   const quic::QuicConnectionStats& stats = session_->connection()->GetStats();
385   UMA_HISTOGRAM_TIMES("Net.QuicSession.MinRTT",
386                       base::TimeDelta::FromMicroseconds(stats.min_rtt_us));
387   UMA_HISTOGRAM_TIMES("Net.QuicSession.SmoothedRTT",
388                       base::TimeDelta::FromMicroseconds(stats.srtt_us));
389 
390   if (num_frames_received_ > 0) {
391     int duplicate_stream_frame_per_thousand =
392         num_duplicate_frames_received_ * 1000 / num_frames_received_;
393     if (num_packets_received_ < 100) {
394       UMA_HISTOGRAM_CUSTOM_COUNTS(
395           "Net.QuicSession.StreamFrameDuplicatedShortConnection",
396           duplicate_stream_frame_per_thousand, 1, 1000, 75);
397     } else {
398       UMA_HISTOGRAM_CUSTOM_COUNTS(
399           "Net.QuicSession.StreamFrameDuplicatedLongConnection",
400           duplicate_stream_frame_per_thousand, 1, 1000, 75);
401     }
402   }
403 
404   RecordAggregatePacketLossRate();
405 }
406 
OnFrameAddedToPacket(const quic::QuicFrame & frame)407 void QuicConnectionLogger::OnFrameAddedToPacket(const quic::QuicFrame& frame) {
408   switch (frame.type) {
409     case quic::PADDING_FRAME:
410       break;
411     case quic::STREAM_FRAME:
412       break;
413     case quic::ACK_FRAME: {
414       break;
415     }
416     case quic::RST_STREAM_FRAME:
417       base::UmaHistogramSparse("Net.QuicSession.RstStreamErrorCodeClient",
418                                frame.rst_stream_frame->error_code);
419       break;
420     case quic::CONNECTION_CLOSE_FRAME:
421       break;
422     case quic::GOAWAY_FRAME:
423       break;
424     case quic::WINDOW_UPDATE_FRAME:
425       break;
426     case quic::BLOCKED_FRAME:
427       ++num_blocked_frames_sent_;
428       break;
429     case quic::STOP_WAITING_FRAME:
430       break;
431     case quic::PING_FRAME:
432       UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.ConnectionFlowControlBlocked",
433                             session_->IsConnectionFlowControlBlocked());
434       UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.StreamFlowControlBlocked",
435                             session_->IsStreamFlowControlBlocked());
436       break;
437     case quic::MTU_DISCOVERY_FRAME:
438       break;
439     case quic::NEW_CONNECTION_ID_FRAME:
440       break;
441     case quic::MAX_STREAMS_FRAME:
442       break;
443     case quic::STREAMS_BLOCKED_FRAME:
444       break;
445     case quic::PATH_RESPONSE_FRAME:
446       break;
447     case quic::PATH_CHALLENGE_FRAME:
448       break;
449     case quic::STOP_SENDING_FRAME:
450       break;
451     case quic::MESSAGE_FRAME:
452       break;
453     case quic::CRYPTO_FRAME:
454       break;
455     case quic::NEW_TOKEN_FRAME:
456       break;
457     case quic::RETIRE_CONNECTION_ID_FRAME:
458       break;
459     default:
460       DCHECK(false) << "Illegal frame type: " << frame.type;
461   }
462   if (!net_log_.IsCapturing())
463     return;
464   switch (frame.type) {
465     case quic::PADDING_FRAME:
466       net_log_.AddEventWithIntParams(
467           NetLogEventType::QUIC_SESSION_PADDING_FRAME_SENT, "num_padding_bytes",
468           frame.padding_frame.num_padding_bytes);
469       break;
470     case quic::STREAM_FRAME:
471       net_log_.AddEvent(NetLogEventType::QUIC_SESSION_STREAM_FRAME_SENT, [&] {
472         return NetLogQuicStreamFrameParams(frame.stream_frame);
473       });
474       break;
475     case quic::ACK_FRAME: {
476       net_log_.AddEvent(NetLogEventType::QUIC_SESSION_ACK_FRAME_SENT, [&] {
477         return NetLogQuicAckFrameParams(frame.ack_frame);
478       });
479       break;
480     }
481     case quic::RST_STREAM_FRAME:
482       base::UmaHistogramSparse("Net.QuicSession.RstStreamErrorCodeClient",
483                                frame.rst_stream_frame->error_code);
484       net_log_.AddEvent(
485           NetLogEventType::QUIC_SESSION_RST_STREAM_FRAME_SENT, [&] {
486             return NetLogQuicRstStreamFrameParams(frame.rst_stream_frame);
487           });
488       break;
489     case quic::CONNECTION_CLOSE_FRAME:
490       net_log_.AddEvent(
491           NetLogEventType::QUIC_SESSION_CONNECTION_CLOSE_FRAME_SENT, [&] {
492             return NetLogQuicConnectionCloseFrameParams(
493                 frame.connection_close_frame);
494           });
495       break;
496     case quic::GOAWAY_FRAME:
497       net_log_.AddEvent(NetLogEventType::QUIC_SESSION_GOAWAY_FRAME_SENT, [&] {
498         return NetLogQuicGoAwayFrameParams(frame.goaway_frame);
499       });
500       break;
501     case quic::WINDOW_UPDATE_FRAME:
502       net_log_.AddEvent(
503           NetLogEventType::QUIC_SESSION_WINDOW_UPDATE_FRAME_SENT, [&] {
504             return NetLogQuicWindowUpdateFrameParams(frame.window_update_frame);
505           });
506       break;
507     case quic::BLOCKED_FRAME:
508       net_log_.AddEvent(NetLogEventType::QUIC_SESSION_BLOCKED_FRAME_SENT, [&] {
509         return NetLogQuicBlockedFrameParams(frame.blocked_frame);
510       });
511       break;
512     case quic::STOP_WAITING_FRAME:
513       net_log_.AddEvent(
514           NetLogEventType::QUIC_SESSION_STOP_WAITING_FRAME_SENT, [&] {
515             return NetLogQuicStopWaitingFrameParams(&frame.stop_waiting_frame);
516           });
517       break;
518     case quic::PING_FRAME:
519       UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.ConnectionFlowControlBlocked",
520                             session_->IsConnectionFlowControlBlocked());
521       UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.StreamFlowControlBlocked",
522                             session_->IsStreamFlowControlBlocked());
523       // PingFrame has no contents to log, so just record that it was sent.
524       net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PING_FRAME_SENT);
525       break;
526     case quic::MTU_DISCOVERY_FRAME:
527       // MtuDiscoveryFrame is PingFrame on wire, it does not have any payload.
528       net_log_.AddEvent(NetLogEventType::QUIC_SESSION_MTU_DISCOVERY_FRAME_SENT);
529       break;
530     case quic::NEW_CONNECTION_ID_FRAME:
531       net_log_.AddEvent(
532           NetLogEventType::QUIC_SESSION_NEW_CONNECTION_ID_FRAME_SENT, [&] {
533             return NetLogQuicNewConnectionIdFrameParams(
534                 frame.new_connection_id_frame);
535           });
536       break;
537     case quic::MAX_STREAMS_FRAME:
538       net_log_.AddEvent(
539           NetLogEventType::QUIC_SESSION_MAX_STREAMS_FRAME_SENT, [&] {
540             return NetLogQuicMaxStreamsFrameParams(frame.max_streams_frame);
541           });
542       break;
543     case quic::STREAMS_BLOCKED_FRAME:
544       net_log_.AddEvent(
545           NetLogEventType::QUIC_SESSION_STREAMS_BLOCKED_FRAME_SENT, [&] {
546             return NetLogQuicStreamsBlockedFrameParams(
547                 frame.streams_blocked_frame);
548           });
549       break;
550     case quic::PATH_RESPONSE_FRAME:
551       net_log_.AddEvent(
552           NetLogEventType::QUIC_SESSION_PATH_RESPONSE_FRAME_SENT, [&] {
553             return NetLogQuicPathData(frame.path_response_frame->data_buffer);
554           });
555       break;
556     case quic::PATH_CHALLENGE_FRAME:
557       net_log_.AddEvent(
558           NetLogEventType::QUIC_SESSION_PATH_CHALLENGE_FRAME_SENT, [&] {
559             return NetLogQuicPathData(frame.path_challenge_frame->data_buffer);
560           });
561       break;
562     case quic::STOP_SENDING_FRAME:
563       net_log_.AddEvent(
564           NetLogEventType::QUIC_SESSION_STOP_SENDING_FRAME_SENT, [&] {
565             return NetLogQuicStopSendingFrameParams(frame.stop_sending_frame);
566           });
567       break;
568     case quic::MESSAGE_FRAME:
569       net_log_.AddEventWithIntParams(
570           NetLogEventType::QUIC_SESSION_MESSAGE_FRAME_SENT, "message_length",
571           frame.message_frame->message_length);
572       break;
573     case quic::CRYPTO_FRAME:
574       net_log_.AddEvent(NetLogEventType::QUIC_SESSION_CRYPTO_FRAME_SENT, [&] {
575         return NetLogQuicCryptoFrameParams(frame.crypto_frame,
576                                            /*has_buffer = */ false);
577       });
578       break;
579     case quic::NEW_TOKEN_FRAME:
580       net_log_.AddEvent(
581           NetLogEventType::QUIC_SESSION_NEW_TOKEN_FRAME_SENT,
582           [&] { return NetLogQuicNewTokenFrameParams(frame.new_token_frame); });
583       break;
584     case quic::RETIRE_CONNECTION_ID_FRAME:
585       net_log_.AddEvent(
586           NetLogEventType::QUIC_SESSION_RETIRE_CONNECTION_ID_FRAME_SENT, [&] {
587             return NetLogQuicRetireConnectionIdFrameParams(
588                 frame.retire_connection_id_frame);
589           });
590       break;
591     default:
592       DCHECK(false) << "Illegal frame type: " << frame.type;
593   }
594 }
595 
OnStreamFrameCoalesced(const quic::QuicStreamFrame & frame)596 void QuicConnectionLogger::OnStreamFrameCoalesced(
597     const quic::QuicStreamFrame& frame) {
598   if (!net_log_.IsCapturing())
599     return;
600   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_STREAM_FRAME_COALESCED,
601                     [&] { return NetLogQuicStreamFrameParams(frame); });
602 }
603 
OnPacketSent(const quic::SerializedPacket & serialized_packet,quic::TransmissionType transmission_type,quic::QuicTime sent_time)604 void QuicConnectionLogger::OnPacketSent(
605     const quic::SerializedPacket& serialized_packet,
606     quic::TransmissionType transmission_type,
607     quic::QuicTime sent_time) {
608   // 4.4.1.4.  Minimum Packet Size
609   // The payload of a UDP datagram carrying the Initial packet MUST be
610   // expanded to at least 1200 octets
611   const quic::QuicPacketLength kMinClientInitialPacketLength = 1200;
612   const quic::QuicPacketLength encrypted_length =
613       serialized_packet.encrypted_length;
614   switch (serialized_packet.encryption_level) {
615     case quic::ENCRYPTION_INITIAL:
616       UMA_HISTOGRAM_CUSTOM_COUNTS("Net.QuicSession.SendPacketSize.Initial",
617                                   encrypted_length, 1, kMaxOutgoingPacketSize,
618                                   50);
619       if (encrypted_length < kMinClientInitialPacketLength) {
620         UMA_HISTOGRAM_CUSTOM_COUNTS(
621             "Net.QuicSession.TooSmallInitialSentPacket",
622             kMinClientInitialPacketLength - encrypted_length, 1,
623             kMinClientInitialPacketLength, 50);
624       }
625       break;
626     case quic::ENCRYPTION_HANDSHAKE:
627       UMA_HISTOGRAM_CUSTOM_COUNTS("Net.QuicSession.SendPacketSize.Hanshake",
628                                   encrypted_length, 1, kMaxOutgoingPacketSize,
629                                   50);
630       break;
631     case quic::ENCRYPTION_ZERO_RTT:
632       UMA_HISTOGRAM_CUSTOM_COUNTS("Net.QuicSession.SendPacketSize.0RTT",
633                                   encrypted_length, 1, kMaxOutgoingPacketSize,
634                                   50);
635       break;
636     case quic::ENCRYPTION_FORWARD_SECURE:
637       UMA_HISTOGRAM_CUSTOM_COUNTS(
638           "Net.QuicSession.SendPacketSize.ForwardSecure", encrypted_length, 1,
639           kMaxOutgoingPacketSize, 50);
640       break;
641     case quic::NUM_ENCRYPTION_LEVELS:
642       NOTREACHED();
643       break;
644   }
645 
646   if (!net_log_.IsCapturing())
647     return;
648   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PACKET_SENT, [&] {
649     return NetLogQuicPacketSentParams(serialized_packet, transmission_type,
650                                       sent_time);
651   });
652 }
653 
OnPacketLoss(quic::QuicPacketNumber lost_packet_number,quic::EncryptionLevel,quic::TransmissionType transmission_type,quic::QuicTime detection_time)654 void QuicConnectionLogger::OnPacketLoss(
655     quic::QuicPacketNumber lost_packet_number,
656     quic::EncryptionLevel /*encryption_level*/,
657     quic::TransmissionType transmission_type,
658     quic::QuicTime detection_time) {
659   if (!net_log_.IsCapturing())
660     return;
661   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PACKET_LOST, [&] {
662     return NetLogQuicPacketLostParams(lost_packet_number, transmission_type,
663                                       detection_time);
664   });
665 }
666 
OnPingSent()667 void QuicConnectionLogger::OnPingSent() {
668   no_packet_received_after_ping_ = true;
669 }
670 
OnPacketReceived(const quic::QuicSocketAddress & self_address,const quic::QuicSocketAddress & peer_address,const quic::QuicEncryptedPacket & packet)671 void QuicConnectionLogger::OnPacketReceived(
672     const quic::QuicSocketAddress& self_address,
673     const quic::QuicSocketAddress& peer_address,
674     const quic::QuicEncryptedPacket& packet) {
675   if (local_address_from_self_.GetFamily() == ADDRESS_FAMILY_UNSPECIFIED) {
676     local_address_from_self_ = ToIPEndPoint(self_address);
677     UMA_HISTOGRAM_ENUMERATION(
678         "Net.QuicSession.ConnectionTypeFromSelf",
679         GetRealAddressFamily(ToIPEndPoint(self_address).address()),
680         ADDRESS_FAMILY_LAST);
681   }
682 
683   previous_received_packet_size_ = last_received_packet_size_;
684   last_received_packet_size_ = packet.length();
685   if (!net_log_.IsCapturing())
686     return;
687   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PACKET_RECEIVED, [&] {
688     return NetLogQuicPacketParams(self_address, peer_address, packet.length());
689   });
690 }
691 
OnUnauthenticatedHeader(const quic::QuicPacketHeader & header)692 void QuicConnectionLogger::OnUnauthenticatedHeader(
693     const quic::QuicPacketHeader& header) {
694   if (!net_log_.IsCapturing())
695     return;
696   net_log_.AddEvent(
697       NetLogEventType::QUIC_SESSION_UNAUTHENTICATED_PACKET_HEADER_RECEIVED,
698       [&] {
699         return NetLogQuicPacketHeaderParams(
700             &header,
701             quic::VersionHasIetfQuicFrames(session_->transport_version()));
702       });
703 }
704 
OnIncorrectConnectionId(quic::QuicConnectionId connection_id)705 void QuicConnectionLogger::OnIncorrectConnectionId(
706     quic::QuicConnectionId connection_id) {
707   ++num_incorrect_connection_ids_;
708 }
709 
OnUndecryptablePacket()710 void QuicConnectionLogger::OnUndecryptablePacket() {
711   ++num_undecryptable_packets_;
712 }
713 
OnDuplicatePacket(quic::QuicPacketNumber packet_number)714 void QuicConnectionLogger::OnDuplicatePacket(
715     quic::QuicPacketNumber packet_number) {
716   ++num_duplicate_packets_;
717   if (!net_log_.IsCapturing())
718     return;
719   net_log_.AddEvent(
720       NetLogEventType::QUIC_SESSION_DUPLICATE_PACKET_RECEIVED,
721       [&] { return NetLogQuicDuplicatePacketParams(packet_number); });
722 }
723 
OnProtocolVersionMismatch(quic::ParsedQuicVersion received_version)724 void QuicConnectionLogger::OnProtocolVersionMismatch(
725     quic::ParsedQuicVersion received_version) {
726   // TODO(rtenneti): Add logging.
727 }
728 
OnPacketHeader(const quic::QuicPacketHeader & header)729 void QuicConnectionLogger::OnPacketHeader(
730     const quic::QuicPacketHeader& header) {
731   if (!first_received_packet_number_.IsInitialized()) {
732     first_received_packet_number_ = header.packet_number;
733   } else if (header.packet_number < first_received_packet_number_) {
734     // Ignore packets with packet numbers less than
735     // first_received_packet_number_.
736     return;
737   }
738   ++num_packets_received_;
739   if (!largest_received_packet_number_.IsInitialized()) {
740     largest_received_packet_number_ = header.packet_number;
741   } else if (largest_received_packet_number_ < header.packet_number) {
742     uint64_t delta = header.packet_number - largest_received_packet_number_;
743     if (delta > 1) {
744       // There is a gap between the largest packet previously received and
745       // the current packet.  This indicates either loss, or out-of-order
746       // delivery.
747       UMA_HISTOGRAM_COUNTS_1M(
748           "Net.QuicSession.PacketGapReceived",
749           static_cast<base::HistogramBase::Sample>(delta - 1));
750     }
751     largest_received_packet_number_ = header.packet_number;
752   }
753   if (header.packet_number - first_received_packet_number_ <
754       received_packets_.size()) {
755     received_packets_[header.packet_number - first_received_packet_number_] =
756         true;
757   }
758   if (last_received_packet_number_.IsInitialized() &&
759       header.packet_number < last_received_packet_number_) {
760     ++num_out_of_order_received_packets_;
761     if (previous_received_packet_size_ < last_received_packet_size_)
762       ++num_out_of_order_large_received_packets_;
763     UMA_HISTOGRAM_COUNTS_1M(
764         "Net.QuicSession.OutOfOrderGapReceived",
765         static_cast<base::HistogramBase::Sample>(last_received_packet_number_ -
766                                                  header.packet_number));
767   } else if (no_packet_received_after_ping_) {
768     if (last_received_packet_number_.IsInitialized()) {
769       UMA_HISTOGRAM_COUNTS_1M(
770           "Net.QuicSession.PacketGapReceivedNearPing",
771           static_cast<base::HistogramBase::Sample>(
772               header.packet_number - last_received_packet_number_));
773     }
774     no_packet_received_after_ping_ = false;
775   }
776   last_received_packet_number_ = header.packet_number;
777   if (!net_log_.IsCapturing())
778     return;
779   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PACKET_AUTHENTICATED);
780 }
781 
OnStreamFrame(const quic::QuicStreamFrame & frame)782 void QuicConnectionLogger::OnStreamFrame(const quic::QuicStreamFrame& frame) {
783   if (!net_log_.IsCapturing())
784     return;
785   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_STREAM_FRAME_RECEIVED,
786                     [&] { return NetLogQuicStreamFrameParams(frame); });
787 }
788 
OnPathChallengeFrame(const quic::QuicPathChallengeFrame & frame)789 void QuicConnectionLogger::OnPathChallengeFrame(
790     const quic::QuicPathChallengeFrame& frame) {
791   if (!net_log_.IsCapturing())
792     return;
793   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PATH_CHALLENGE_FRAME_RECEIVED,
794                     [&] { return NetLogQuicPathData(frame.data_buffer); });
795 }
796 
OnPathResponseFrame(const quic::QuicPathResponseFrame & frame)797 void QuicConnectionLogger::OnPathResponseFrame(
798     const quic::QuicPathResponseFrame& frame) {
799   if (!net_log_.IsCapturing())
800     return;
801   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PATH_RESPONSE_FRAME_RECEIVED,
802                     [&] { return NetLogQuicPathData(frame.data_buffer); });
803 }
804 
OnCryptoFrame(const quic::QuicCryptoFrame & frame)805 void QuicConnectionLogger::OnCryptoFrame(const quic::QuicCryptoFrame& frame) {
806   if (!net_log_.IsCapturing())
807     return;
808   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_CRYPTO_FRAME_RECEIVED, [&] {
809     return NetLogQuicCryptoFrameParams(&frame, /*has_buffer = */ true);
810   });
811 }
812 
OnStopSendingFrame(const quic::QuicStopSendingFrame & frame)813 void QuicConnectionLogger::OnStopSendingFrame(
814     const quic::QuicStopSendingFrame& frame) {
815   if (!net_log_.IsCapturing())
816     return;
817   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_STOP_SENDING_FRAME_RECEIVED,
818                     [&] { return NetLogQuicStopSendingFrameParams(&frame); });
819 }
820 
OnStreamsBlockedFrame(const quic::QuicStreamsBlockedFrame & frame)821 void QuicConnectionLogger::OnStreamsBlockedFrame(
822     const quic::QuicStreamsBlockedFrame& frame) {
823   if (!net_log_.IsCapturing())
824     return;
825   net_log_.AddEvent(
826       NetLogEventType::QUIC_SESSION_STREAMS_BLOCKED_FRAME_RECEIVED,
827       [&] { return NetLogQuicStreamsBlockedFrameParams(frame); });
828 }
829 
OnMaxStreamsFrame(const quic::QuicMaxStreamsFrame & frame)830 void QuicConnectionLogger::OnMaxStreamsFrame(
831     const quic::QuicMaxStreamsFrame& frame) {
832   if (!net_log_.IsCapturing())
833     return;
834   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_MAX_STREAMS_FRAME_RECEIVED,
835                     [&] { return NetLogQuicMaxStreamsFrameParams(frame); });
836 }
837 
OnIncomingAck(quic::QuicPacketNumber ack_packet_number,quic::EncryptionLevel,const quic::QuicAckFrame & frame,quic::QuicTime ack_receive_time,quic::QuicPacketNumber largest_observed,bool rtt_updated,quic::QuicPacketNumber least_unacked_sent_packet)838 void QuicConnectionLogger::OnIncomingAck(
839     quic::QuicPacketNumber ack_packet_number,
840     quic::EncryptionLevel /*ack_decrypted_level*/,
841     const quic::QuicAckFrame& frame,
842     quic::QuicTime ack_receive_time,
843     quic::QuicPacketNumber largest_observed,
844     bool rtt_updated,
845     quic::QuicPacketNumber least_unacked_sent_packet) {
846   const size_t kApproximateLargestSoloAckBytes = 100;
847   if (last_received_packet_number_ - first_received_packet_number_ <
848           received_acks_.size() &&
849       last_received_packet_size_ < kApproximateLargestSoloAckBytes) {
850     received_acks_[last_received_packet_number_ -
851                    first_received_packet_number_] = true;
852   }
853 
854   if (!net_log_.IsCapturing())
855     return;
856   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_ACK_FRAME_RECEIVED,
857                     [&] { return NetLogQuicAckFrameParams(&frame); });
858 
859   // TODO(rch, rtenneti) sort out histograms for QUIC_VERSION_34 and above.
860 }
861 
OnStopWaitingFrame(const quic::QuicStopWaitingFrame & frame)862 void QuicConnectionLogger::OnStopWaitingFrame(
863     const quic::QuicStopWaitingFrame& frame) {
864   if (!net_log_.IsCapturing())
865     return;
866   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_STOP_WAITING_FRAME_RECEIVED,
867                     [&] { return NetLogQuicStopWaitingFrameParams(&frame); });
868 }
869 
OnRstStreamFrame(const quic::QuicRstStreamFrame & frame)870 void QuicConnectionLogger::OnRstStreamFrame(
871     const quic::QuicRstStreamFrame& frame) {
872   base::UmaHistogramSparse("Net.QuicSession.RstStreamErrorCodeServer",
873                            frame.error_code);
874   if (!net_log_.IsCapturing())
875     return;
876   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_RST_STREAM_FRAME_RECEIVED,
877                     [&] { return NetLogQuicRstStreamFrameParams(&frame); });
878 }
879 
OnConnectionCloseFrame(const quic::QuicConnectionCloseFrame & frame)880 void QuicConnectionLogger::OnConnectionCloseFrame(
881     const quic::QuicConnectionCloseFrame& frame) {
882   if (!net_log_.IsCapturing())
883     return;
884   net_log_.AddEvent(
885       NetLogEventType::QUIC_SESSION_CONNECTION_CLOSE_FRAME_RECEIVED,
886       [&] { return NetLogQuicConnectionCloseFrameParams(&frame); });
887 }
888 
OnWindowUpdateFrame(const quic::QuicWindowUpdateFrame & frame,const quic::QuicTime & receive_time)889 void QuicConnectionLogger::OnWindowUpdateFrame(
890     const quic::QuicWindowUpdateFrame& frame,
891     const quic::QuicTime& receive_time) {
892   if (!net_log_.IsCapturing())
893     return;
894   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_WINDOW_UPDATE_FRAME_RECEIVED,
895                     [&] { return NetLogQuicWindowUpdateFrameParams(&frame); });
896 }
897 
OnBlockedFrame(const quic::QuicBlockedFrame & frame)898 void QuicConnectionLogger::OnBlockedFrame(const quic::QuicBlockedFrame& frame) {
899   ++num_blocked_frames_received_;
900   if (!net_log_.IsCapturing())
901     return;
902   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_BLOCKED_FRAME_RECEIVED,
903                     [&] { return NetLogQuicBlockedFrameParams(&frame); });
904 }
905 
OnGoAwayFrame(const quic::QuicGoAwayFrame & frame)906 void QuicConnectionLogger::OnGoAwayFrame(const quic::QuicGoAwayFrame& frame) {
907   UMA_HISTOGRAM_BOOLEAN("Net.QuicSession.GoAwayReceivedForConnectionMigration",
908                         frame.error_code == quic::QUIC_ERROR_MIGRATING_PORT);
909 
910   if (!net_log_.IsCapturing())
911     return;
912   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_GOAWAY_FRAME_RECEIVED,
913                     [&] { return NetLogQuicGoAwayFrameParams(&frame); });
914 }
915 
OnPingFrame(const quic::QuicPingFrame & frame)916 void QuicConnectionLogger::OnPingFrame(const quic::QuicPingFrame& frame) {
917   // PingFrame has no contents to log, so just record that it was received.
918   if (!net_log_.IsCapturing())
919     return;
920   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PING_FRAME_RECEIVED);
921 }
922 
OnPaddingFrame(const quic::QuicPaddingFrame & frame)923 void QuicConnectionLogger::OnPaddingFrame(const quic::QuicPaddingFrame& frame) {
924   if (!net_log_.IsCapturing())
925     return;
926   net_log_.AddEventWithIntParams(
927       NetLogEventType::QUIC_SESSION_PADDING_FRAME_RECEIVED, "num_padding_bytes",
928       frame.num_padding_bytes);
929 }
930 
OnNewConnectionIdFrame(const quic::QuicNewConnectionIdFrame & frame)931 void QuicConnectionLogger::OnNewConnectionIdFrame(
932     const quic::QuicNewConnectionIdFrame& frame) {
933   if (!net_log_.IsCapturing())
934     return;
935   net_log_.AddEvent(
936       NetLogEventType::QUIC_SESSION_NEW_CONNECTION_ID_FRAME_RECEIVED,
937       [&] { return NetLogQuicNewConnectionIdFrameParams(&frame); });
938 }
939 
OnNewTokenFrame(const quic::QuicNewTokenFrame & frame)940 void QuicConnectionLogger::OnNewTokenFrame(
941     const quic::QuicNewTokenFrame& frame) {
942   if (!net_log_.IsCapturing())
943     return;
944   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_NEW_TOKEN_FRAME_RECEIVED,
945                     [&] { return NetLogQuicNewTokenFrameParams(&frame); });
946 }
947 
OnRetireConnectionIdFrame(const quic::QuicRetireConnectionIdFrame & frame)948 void QuicConnectionLogger::OnRetireConnectionIdFrame(
949     const quic::QuicRetireConnectionIdFrame& frame) {
950   if (!net_log_.IsCapturing())
951     return;
952   net_log_.AddEvent(
953       NetLogEventType::QUIC_SESSION_RETIRE_CONNECTION_ID_FRAME_RECEIVED,
954       [&] { return NetLogQuicRetireConnectionIdFrameParams(&frame); });
955 }
956 
OnMessageFrame(const quic::QuicMessageFrame & frame)957 void QuicConnectionLogger::OnMessageFrame(const quic::QuicMessageFrame& frame) {
958   if (!net_log_.IsCapturing())
959     return;
960   net_log_.AddEventWithIntParams(
961       NetLogEventType::QUIC_SESSION_MESSAGE_FRAME_RECEIVED, "message_length",
962       frame.message_length);
963 }
964 
OnHandshakeDoneFrame(const quic::QuicHandshakeDoneFrame & frame)965 void QuicConnectionLogger::OnHandshakeDoneFrame(
966     const quic::QuicHandshakeDoneFrame& frame) {
967   if (!net_log_.IsCapturing())
968     return;
969   net_log_.AddEvent(
970       NetLogEventType::QUIC_SESSION_HANDSHAKE_DONE_FRAME_RECEIVED);
971 }
972 
OnCoalescedPacketSent(const quic::QuicCoalescedPacket & coalesced_packet,size_t length)973 void QuicConnectionLogger::OnCoalescedPacketSent(
974     const quic::QuicCoalescedPacket& coalesced_packet,
975     size_t length) {
976   if (!net_log_.IsCapturing())
977     return;
978   net_log_.AddEventWithStringParams(
979       NetLogEventType::QUIC_SESSION_COALESCED_PACKET_SENT, "info",
980       coalesced_packet.ToString(length));
981 }
982 
OnPublicResetPacket(const quic::QuicPublicResetPacket & packet)983 void QuicConnectionLogger::OnPublicResetPacket(
984     const quic::QuicPublicResetPacket& packet) {
985   UpdatePublicResetAddressMismatchHistogram(
986       local_address_from_shlo_, ToIPEndPoint(packet.client_address));
987   if (!net_log_.IsCapturing())
988     return;
989   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_PUBLIC_RESET_PACKET_RECEIVED,
990                     [&] {
991                       return NetLogQuicPublicResetPacketParams(
992                           local_address_from_shlo_, packet.client_address);
993                     });
994 }
995 
OnVersionNegotiationPacket(const quic::QuicVersionNegotiationPacket & packet)996 void QuicConnectionLogger::OnVersionNegotiationPacket(
997     const quic::QuicVersionNegotiationPacket& packet) {
998   if (!net_log_.IsCapturing())
999     return;
1000   net_log_.AddEvent(
1001       NetLogEventType::QUIC_SESSION_VERSION_NEGOTIATION_PACKET_RECEIVED,
1002       [&] { return NetLogQuicVersionNegotiationPacketParams(&packet); });
1003 }
1004 
OnCryptoHandshakeMessageReceived(const quic::CryptoHandshakeMessage & message)1005 void QuicConnectionLogger::OnCryptoHandshakeMessageReceived(
1006     const quic::CryptoHandshakeMessage& message) {
1007   if (message.tag() == quic::kSHLO) {
1008     quiche::QuicheStringPiece address;
1009     quic::QuicSocketAddressCoder decoder;
1010     if (message.GetStringPiece(quic::kCADR, &address) &&
1011         decoder.Decode(address.data(), address.size())) {
1012       local_address_from_shlo_ =
1013           IPEndPoint(ToIPAddress(decoder.ip()), decoder.port());
1014       UMA_HISTOGRAM_ENUMERATION(
1015           "Net.QuicSession.ConnectionTypeFromPeer",
1016           GetRealAddressFamily(local_address_from_shlo_.address()),
1017           ADDRESS_FAMILY_LAST);
1018 
1019       int sample = GetAddressMismatch(local_address_from_shlo_,
1020                                       local_address_from_self_);
1021       // We are seemingly talking to an older server that does not support the
1022       // feature, so we can't report the results in the histogram.
1023       if (sample >= 0) {
1024         UMA_HISTOGRAM_ENUMERATION("Net.QuicSession.SelfShloAddressMismatch",
1025                                   static_cast<QuicAddressMismatch>(sample),
1026                                   QUIC_ADDRESS_MISMATCH_MAX);
1027       }
1028     }
1029   }
1030   if (!net_log_.IsCapturing())
1031     return;
1032   net_log_.AddEvent(
1033       NetLogEventType::QUIC_SESSION_CRYPTO_HANDSHAKE_MESSAGE_RECEIVED,
1034       [&] { return NetLogQuicCryptoHandshakeMessageParams(&message); });
1035 }
1036 
OnCryptoHandshakeMessageSent(const quic::CryptoHandshakeMessage & message)1037 void QuicConnectionLogger::OnCryptoHandshakeMessageSent(
1038     const quic::CryptoHandshakeMessage& message) {
1039   if (!net_log_.IsCapturing())
1040     return;
1041   net_log_.AddEvent(
1042       NetLogEventType::QUIC_SESSION_CRYPTO_HANDSHAKE_MESSAGE_SENT,
1043       [&] { return NetLogQuicCryptoHandshakeMessageParams(&message); });
1044 }
1045 
OnConnectionClosed(const quic::QuicConnectionCloseFrame & frame,quic::ConnectionCloseSource source)1046 void QuicConnectionLogger::OnConnectionClosed(
1047     const quic::QuicConnectionCloseFrame& frame,
1048     quic::ConnectionCloseSource source) {
1049   if (!net_log_.IsCapturing())
1050     return;
1051   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_CLOSED, [&] {
1052     return NetLogQuicOnConnectionClosedParams(frame.quic_error_code,
1053                                               frame.error_details, source);
1054   });
1055 }
1056 
OnSuccessfulVersionNegotiation(const quic::ParsedQuicVersion & version)1057 void QuicConnectionLogger::OnSuccessfulVersionNegotiation(
1058     const quic::ParsedQuicVersion& version) {
1059   if (!net_log_.IsCapturing())
1060     return;
1061   string quic_version = quic::ParsedQuicVersionToString(version);
1062   net_log_.AddEventWithStringParams(
1063       NetLogEventType::QUIC_SESSION_VERSION_NEGOTIATED, "version",
1064       quic_version);
1065 }
1066 
UpdateReceivedFrameCounts(quic::QuicStreamId stream_id,int num_frames_received,int num_duplicate_frames_received)1067 void QuicConnectionLogger::UpdateReceivedFrameCounts(
1068     quic::QuicStreamId stream_id,
1069     int num_frames_received,
1070     int num_duplicate_frames_received) {
1071   if (!quic::QuicUtils::IsCryptoStreamId(session_->transport_version(),
1072                                          stream_id)) {
1073     num_frames_received_ += num_frames_received;
1074     num_duplicate_frames_received_ += num_duplicate_frames_received;
1075   }
1076 }
1077 
OnCertificateVerified(const CertVerifyResult & result)1078 void QuicConnectionLogger::OnCertificateVerified(
1079     const CertVerifyResult& result) {
1080   if (!net_log_.IsCapturing())
1081     return;
1082   if (result.cert_status == CERT_STATUS_INVALID) {
1083     net_log_.AddEvent(NetLogEventType::QUIC_SESSION_CERTIFICATE_VERIFY_FAILED);
1084     return;
1085   }
1086   net_log_.AddEvent(NetLogEventType::QUIC_SESSION_CERTIFICATE_VERIFIED, [&] {
1087     return NetLogQuicCertificateVerifiedParams(result.verified_cert);
1088   });
1089 }
1090 
Get6PacketHistogram(const char * which_6) const1091 base::HistogramBase* QuicConnectionLogger::Get6PacketHistogram(
1092     const char* which_6) const {
1093   // This histogram takes a binary encoding of the 6 consecutive packets
1094   // received.  As a result, there are 64 possible sample-patterns.
1095   string prefix("Net.QuicSession.6PacketsPatternsReceived_");
1096   return base::LinearHistogram::FactoryGet(
1097       prefix + which_6 + connection_description_, 1, 64, 65,
1098       base::HistogramBase::kUmaTargetedHistogramFlag);
1099 }
1100 
ReceivedPacketLossRate() const1101 float QuicConnectionLogger::ReceivedPacketLossRate() const {
1102   if (!largest_received_packet_number_.IsInitialized())
1103     return 0.0f;
1104   float num_packets =
1105       largest_received_packet_number_ - first_received_packet_number_ + 1;
1106   float num_missing = num_packets - num_packets_received_;
1107   return num_missing / num_packets;
1108 }
1109 
OnRttChanged(quic::QuicTime::Delta rtt) const1110 void QuicConnectionLogger::OnRttChanged(quic::QuicTime::Delta rtt) const {
1111   // Notify socket performance watcher of the updated RTT value.
1112   if (!socket_performance_watcher_)
1113     return;
1114 
1115   int64_t microseconds = rtt.ToMicroseconds();
1116   if (microseconds != 0 &&
1117       socket_performance_watcher_->ShouldNotifyUpdatedRTT()) {
1118     socket_performance_watcher_->OnUpdatedRTTAvailable(
1119         base::TimeDelta::FromMicroseconds(rtt.ToMicroseconds()));
1120   }
1121 }
1122 
RecordAggregatePacketLossRate() const1123 void QuicConnectionLogger::RecordAggregatePacketLossRate() const {
1124   // For short connections under 22 packets in length, we'll rely on the
1125   // Net.QuicSession.21CumulativePacketsReceived_* histogram to indicate packet
1126   // loss rates.  This way we avoid tremendously anomalous contributions to our
1127   // histogram.  (e.g., if we only got 5 packets, but lost 1, we'd otherwise
1128   // record a 20% loss in this histogram!). We may still get some strange data
1129   // (1 loss in 22 is still high :-/).
1130   if (!largest_received_packet_number_.IsInitialized() ||
1131       largest_received_packet_number_ - first_received_packet_number_ < 22)
1132     return;
1133 
1134   string prefix("Net.QuicSession.PacketLossRate_");
1135   base::HistogramBase* histogram = base::Histogram::FactoryGet(
1136       prefix + connection_description_, 1, 1000, 75,
1137       base::HistogramBase::kUmaTargetedHistogramFlag);
1138   histogram->Add(static_cast<base::HistogramBase::Sample>(
1139       ReceivedPacketLossRate() * 1000));
1140 }
1141 
1142 }  // namespace net
1143