Add quic_logging

net/quic/core/quic_framer.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "net/quic/core/quic_framer.h"
 
 #include <cstdint>
 #include <memory>
 
 #include "base/compiler_specific.h"
-#include "base/logging.h"
 #include "base/memory/ptr_util.h"
 #include "base/stl_util.h"
 #include "net/quic/core/crypto/crypto_framer.h"
 #include "net/quic/core/crypto/crypto_handshake_message.h"
 #include "net/quic/core/crypto/crypto_protocol.h"
 #include "net/quic/core/crypto/null_decrypter.h"
 #include "net/quic/core/crypto/null_encrypter.h"
 #include "net/quic/core/crypto/quic_decrypter.h"
 #include "net/quic/core/crypto/quic_encrypter.h"
 #include "net/quic/core/quic_data_reader.h"
 #include "net/quic/core/quic_data_writer.h"
 #include "net/quic/core/quic_flags.h"
 #include "net/quic/core/quic_socket_address_coder.h"
 #include "net/quic/core/quic_utils.h"
 #include "net/quic/platform/api/quic_aligned.h"
 #include "net/quic/platform/api/quic_bug_tracker.h"
+#include "net/quic/platform/api/quic_logging.h"
 
 using base::ContainsKey;
 using base::StringPiece;
 using std::string;
 #define PREDICT_FALSE(x) (x)
 
 namespace net {
 
 namespace {
 
@@ skipping 263 matching lines @@
   if (!first_frame) {
     return 0;
   }
   bool can_truncate =
       frame.type == ACK_FRAME &&
       free_bytes >=
           GetMinAckFrameSize(quic_version_, PACKET_6BYTE_PACKET_NUMBER);
   if (can_truncate) {
     // Truncate the frame so the packet will not exceed kMaxPacketSize.
     // Note that we may not use every byte of the writer in this case.
-    DVLOG(1) << ENDPOINT
-             << "Truncating large frame, free bytes: " << free_bytes;
+    QUIC_DLOG(INFO) << ENDPOINT
+                    << "Truncating large frame, free bytes: " << free_bytes;
     return free_bytes;
   }
   return 0;
 }
 
 QuicFramer::AckFrameInfo::AckFrameInfo()
     : max_block_length(0), first_block_length(0), num_ack_blocks(0) {}
 
 QuicFramer::AckFrameInfo::AckFrameInfo(const AckFrameInfo& other) = default;
 
@@ skipping 176 matching lines @@
 
 bool QuicFramer::ProcessPacket(const QuicEncryptedPacket& packet) {
   QuicDataReader reader(packet.data(), packet.length());
 
   visitor_->OnPacket();
 
   // First parse the public header.
   QuicPacketPublicHeader public_header;
   if (!ProcessPublicHeader(&reader, &public_header)) {
     DCHECK_NE("", detailed_error_);
-    DVLOG(1) << ENDPOINT
-             << "Unable to process public header. Error: " << detailed_error_;
+    QUIC_DVLOG(1) << ENDPOINT << "Unable to process public header. Error: "
+                  << detailed_error_;
     DCHECK_NE("", detailed_error_);
     return RaiseError(QUIC_INVALID_PACKET_HEADER);
   }
 
   if (!visitor_->OnUnauthenticatedPublicHeader(public_header)) {
     // The visitor suppresses further processing of the packet.
     return true;
   }
 
   if (perspective_ == Perspective::IS_SERVER && public_header.version_flag &&
@@ skipping 44 matching lines @@
 }
 
 bool QuicFramer::ProcessDataPacket(QuicDataReader* encrypted_reader,
                                    const QuicPacketPublicHeader& public_header,
                                    const QuicEncryptedPacket& packet,
                                    char* decrypted_buffer,
                                    size_t buffer_length) {
   QuicPacketHeader header(public_header);
   if (!ProcessUnauthenticatedHeader(encrypted_reader, &header)) {
     DCHECK_NE("", detailed_error_);
-    DVLOG(1) << ENDPOINT
-             << "Unable to process packet header. Stopping parsing. Error: "
-             << detailed_error_;
+    QUIC_DVLOG(1)
+        << ENDPOINT
+        << "Unable to process packet header. Stopping parsing. Error: "
+        << detailed_error_;
     return false;
   }
 
   size_t decrypted_length = 0;
   if (!DecryptPayload(encrypted_reader, header, packet, decrypted_buffer,
                       buffer_length, &decrypted_length)) {
     set_detailed_error("Unable to decrypt payload.");
     return RaiseError(QUIC_DECRYPTION_FAILURE);
   }
 
@@ skipping 11 matching lines @@
   if (packet.length() > kMaxPacketSize) {
     // If the packet has gotten this far, it should not be too large.
     QUIC_BUG << "Packet too large:" << packet.length();
     return RaiseError(QUIC_PACKET_TOO_LARGE);
   }
 
   // Handle the payload.
   if (!ProcessFrameData(&reader, header)) {
     DCHECK_NE(QUIC_NO_ERROR, error_);  // ProcessFrameData sets the error.
     DCHECK_NE("", detailed_error_);
-    DLOG(WARNING) << ENDPOINT
-                  << "Unable to process frame data. Error: " << detailed_error_;
+    QUIC_DLOG(WARNING) << ENDPOINT << "Unable to process frame data. Error: "
+                       << detailed_error_;
     return false;
   }
 
   visitor_->OnPacketComplete();
   return true;
 }
 
 bool QuicFramer::ProcessPublicResetPacket(
     QuicDataReader* reader,
     const QuicPacketPublicHeader& public_header) {
@@ skipping 24 matching lines @@
           QuicSocketAddress(address_coder.ip(), address_coder.port());
     }
   }
 
   visitor_->OnPublicResetPacket(packet);
   return true;
 }
 
 bool QuicFramer::AppendPacketHeader(const QuicPacketHeader& header,
                                     QuicDataWriter* writer) {
-  DVLOG(1) << ENDPOINT << "Appending header: " << header;
+  QUIC_DVLOG(1) << ENDPOINT << "Appending header: " << header;
   uint8_t public_flags = 0;
   if (header.public_header.reset_flag) {
     public_flags |= PACKET_PUBLIC_FLAGS_RST;
   }
   if (header.public_header.version_flag) {
     public_flags |= PACKET_PUBLIC_FLAGS_VERSION;
   }
   if (header.public_header.multipath_flag) {
     public_flags |= PACKET_PUBLIC_FLAGS_MULTIPATH;
   }
@@ skipping 25 matching lines @@
         return false;
       }
       break;
   }
   last_serialized_connection_id_ = header.public_header.connection_id;
 
   if (header.public_header.version_flag) {
     DCHECK_EQ(Perspective::IS_CLIENT, perspective_);
     QuicTag tag = QuicVersionToQuicTag(quic_version_);
     writer->WriteUInt32(tag);
-    DVLOG(1) << ENDPOINT << "version = " << quic_version_ << ", tag = '"
-             << QuicTagToString(tag) << "'";
+    QUIC_DVLOG(1) << ENDPOINT << "version = " << quic_version_ << ", tag = '"
+                  << QuicTagToString(tag) << "'";
   }
 
   if (header.public_header.multipath_flag &&
       !writer->WriteUInt8(header.path_id)) {
     return false;
   }
 
   if (header.public_header.nonce != nullptr &&
       !writer->WriteBytes(header.public_header.nonce,
                           kDiversificationNonceSize)) {
@@ skipping 318 matching lines @@
     }
 
     if (frame_type & kQuicFrameTypeSpecialMask) {
       // Stream Frame
       if (frame_type & kQuicFrameTypeStreamMask) {
         QuicStreamFrame frame;
         if (!ProcessStreamFrame(reader, frame_type, &frame)) {
           return RaiseError(QUIC_INVALID_STREAM_DATA);
         }
         if (!visitor_->OnStreamFrame(frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       // Ack Frame
       if (frame_type & kQuicFrameTypeAckMask) {
         QuicAckFrame frame;
         if (!ProcessAckFrame(reader, frame_type, &frame)) {
           return RaiseError(QUIC_INVALID_ACK_DATA);
         }
         if (!visitor_->OnAckFrame(frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       // This was a special frame type that did not match any
       // of the known ones. Error.
       set_detailed_error("Illegal frame type.");
-      DLOG(WARNING) << ENDPOINT
-                    << "Illegal frame type: " << static_cast<int>(frame_type);
+      QUIC_DLOG(WARNING) << ENDPOINT << "Illegal frame type: "
+                         << static_cast<int>(frame_type);
       return RaiseError(QUIC_INVALID_FRAME_DATA);
     }
 
     switch (frame_type) {
       case PADDING_FRAME: {
         QuicPaddingFrame frame(reader->BytesRemaining());
         if (!visitor_->OnPaddingFrame(frame)) {
-          DVLOG(1) << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << "Visitor asked to stop further processing.";
         }
         // We're done with the packet.
         return true;
       }
 
       case RST_STREAM_FRAME: {
         QuicRstStreamFrame frame;
         if (!ProcessRstStreamFrame(reader, &frame)) {
           return RaiseError(QUIC_INVALID_RST_STREAM_DATA);
         }
         if (!visitor_->OnRstStreamFrame(frame)) {
-          DVLOG(1) << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       case CONNECTION_CLOSE_FRAME: {
         QuicConnectionCloseFrame frame;
         if (!ProcessConnectionCloseFrame(reader, &frame)) {
           return RaiseError(QUIC_INVALID_CONNECTION_CLOSE_DATA);
         }
 
         if (!visitor_->OnConnectionCloseFrame(frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       case GOAWAY_FRAME: {
         QuicGoAwayFrame goaway_frame;
         if (!ProcessGoAwayFrame(reader, &goaway_frame)) {
           return RaiseError(QUIC_INVALID_GOAWAY_DATA);
         }
         if (!visitor_->OnGoAwayFrame(goaway_frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       case WINDOW_UPDATE_FRAME: {
         QuicWindowUpdateFrame window_update_frame;
         if (!ProcessWindowUpdateFrame(reader, &window_update_frame)) {
           return RaiseError(QUIC_INVALID_WINDOW_UPDATE_DATA);
         }
         if (!visitor_->OnWindowUpdateFrame(window_update_frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       case BLOCKED_FRAME: {
         QuicBlockedFrame blocked_frame;
         if (!ProcessBlockedFrame(reader, &blocked_frame)) {
           return RaiseError(QUIC_INVALID_BLOCKED_DATA);
         }
         if (!visitor_->OnBlockedFrame(blocked_frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       case STOP_WAITING_FRAME: {
         QuicStopWaitingFrame stop_waiting_frame;
         if (!ProcessStopWaitingFrame(reader, header, &stop_waiting_frame)) {
           return RaiseError(QUIC_INVALID_STOP_WAITING_DATA);
         }
         if (!visitor_->OnStopWaitingFrame(stop_waiting_frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
       case PING_FRAME: {
         // Ping has no payload.
         QuicPingFrame ping_frame;
         if (!visitor_->OnPingFrame(ping_frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
       case PATH_CLOSE_FRAME: {
         QuicPathCloseFrame path_close_frame;
         if (!ProcessPathCloseFrame(reader, &path_close_frame)) {
           return RaiseError(QUIC_INVALID_PATH_CLOSE_DATA);
         }
         if (!visitor_->OnPathCloseFrame(path_close_frame)) {
-          DVLOG(1) << ENDPOINT << "Visitor asked to stop further processing.";
+          QUIC_DVLOG(1) << ENDPOINT
+                        << "Visitor asked to stop further processing.";
           // Returning true since there was no parsing error.
           return true;
         }
         continue;
       }
 
       default:
         set_detailed_error("Illegal frame type.");
-        DLOG(WARNING) << ENDPOINT
-                      << "Illegal frame type: " << static_cast<int>(frame_type);
+        QUIC_DLOG(WARNING) << ENDPOINT << "Illegal frame type: "
+                           << static_cast<int>(frame_type);
         return RaiseError(QUIC_INVALID_FRAME_DATA);
     }
   }
 
   return true;
 }
 
 bool QuicFramer::ProcessStreamFrame(QuicDataReader* reader,
                                     uint8_t frame_type,
                                     QuicStreamFrame* frame) {
@@ skipping 479 matching lines @@
         // Switch the alternative decrypter so that we use it first next time.
         decrypter_.swap(alternative_decrypter_);
         EncryptionLevel level = alternative_decrypter_level_;
         alternative_decrypter_level_ = decrypter_level_;
         decrypter_level_ = level;
       }
     }
   }
 
   if (!success) {
-    DVLOG(1) << ENDPOINT << "DecryptPacket failed for packet_number:"
-             << header.packet_number;
+    QUIC_DVLOG(1) << ENDPOINT << "DecryptPacket failed for packet_number:"
+                  << header.packet_number;
     return false;
   }
 
   return true;
 }
 
 size_t QuicFramer::GetAckFrameTimeStampSize(const QuicAckFrame& ack) {
   if (ack.received_packet_times.empty()) {
     return 0;
   }
@@ skipping 496 matching lines @@
 bool QuicFramer::AppendPathCloseFrame(const QuicPathCloseFrame& frame,
                                       QuicDataWriter* writer) {
   uint8_t path_id = static_cast<uint8_t>(frame.path_id);
   if (!writer->WriteUInt8(path_id)) {
     return false;
   }
   return true;
 }
 
 bool QuicFramer::RaiseError(QuicErrorCode error) {
-  DVLOG(1) << ENDPOINT << "Error: " << QuicErrorCodeToString(error)
-           << " detail: " << detailed_error_;
+  QUIC_DLOG(INFO) << ENDPOINT << "Error: " << QuicErrorCodeToString(error)
+                  << " detail: " << detailed_error_;
   set_error(error);
   visitor_->OnError(this);
   return false;
 }
 
 }  // namespace net