shill: Makes netlink message logging finer-grained.

Logs netlink message headers at a more permissive log level than the
bodies of those messages.

While I was in there, I changed a couple comments.

BUG=None
TEST=unittest.

Change-Id: I7d6e415dd5a7d3ec86e260a0a6664b8be813f42a
Reviewed-on: https://gerrit.chromium.org/gerrit/48015
Reviewed-by: Wade Guthrie <wdg@chromium.org>
Tested-by: Wade Guthrie <wdg@chromium.org>
Commit-Queue: Wade Guthrie <wdg@chromium.org>
diff --git a/callback80211_metrics.cc b/callback80211_metrics.cc
index 28437ad..511609c 100644
--- a/callback80211_metrics.cc
+++ b/callback80211_metrics.cc
@@ -37,10 +37,9 @@
   const Nl80211Message &message =
       * reinterpret_cast<const Nl80211Message *>(&netlink_message);
 
-  SLOG(WiFi, 3) << "Received " << message.command_string()
-                << " (" << + message.command() << ")";
   if (metrics_ &&
       message.command() == DeauthenticateMessage::kCommand) {
+    SLOG(WiFi, 3) << "Handling Deauthenticate Message";
     Metrics::WiFiDisconnectByWhom by_whom =
         message.const_attributes()->IsFlagAttributeTrue(
             NL80211_ATTR_DISCONNECTED_BY_AP) ?
diff --git a/generic_netlink_message.cc b/generic_netlink_message.cc
index fcd4f42..79526e7 100644
--- a/generic_netlink_message.cc
+++ b/generic_netlink_message.cc
@@ -83,11 +83,12 @@
   return true;
 }
 
-void GenericNetlinkMessage::Print(int log_level) const {
-  SLOG(WiFi, log_level) << StringPrintf("Message %s (%d)",
-                                        command_string(),
-                                        command());
-  attributes_->Print(log_level, 1);
+void GenericNetlinkMessage::Print(int header_log_level,
+                                  int detail_log_level) const {
+  SLOG(WiFi, header_log_level) << StringPrintf("Message %s (%d)",
+                                               command_string(),
+                                               command());
+  attributes_->Print(detail_log_level, 1);
 }
 
 // Control Message
diff --git a/generic_netlink_message.h b/generic_netlink_message.h
index 23bd067..3393bba 100644
--- a/generic_netlink_message.h
+++ b/generic_netlink_message.h
@@ -71,7 +71,7 @@
   AttributeListConstRefPtr const_attributes() const { return attributes_; }
   AttributeListRefPtr attributes() { return attributes_; }
 
-  virtual void Print(int log_level) const;
+  virtual void Print(int header_log_level, int detail_log_level) const;
 
  protected:
   // Returns a string of bytes representing _both_ an |nlmsghdr| and a
diff --git a/manager.h b/manager.h
index 12e31a5..6f946ea 100644
--- a/manager.h
+++ b/manager.h
@@ -49,8 +49,6 @@
 
 class Manager : public base::SupportsWeakPtr<Manager> {
  public:
-  // Specifies whether a scan request is made from outside shill (ostensibly
-  // across dbus via RPC) or from within shill.
   typedef base::Callback<void(const ServiceRefPtr &service)> ServiceCallback;
 
   struct Properties {
diff --git a/netlink_attribute.cc b/netlink_attribute.cc
index 45696b4..a348aab 100644
--- a/netlink_attribute.cc
+++ b/netlink_attribute.cc
@@ -866,8 +866,9 @@
   // restriction exists for nested array attributes -- this code starts the id
   // at one in order to be consistent with nested structures).
   //
-  // TODO(wdg): Determine whether any code depends on the value of
-  // |nlattr::nla_type| for nested array attributes.
+  // TODO(wdg): Need an iterator for arrays (and don't renumber their IDs) since
+  // some code depends on the value of |nlattr::nla_type| for nested array
+  // attributes.
   int id = 1;
   nla_for_each_nested_type_corrected(attr, attrs, remaining) {
     string attribute_name = StringPrintf(
diff --git a/netlink_manager.cc b/netlink_manager.cc
index 14dc422..faa11ce 100644
--- a/netlink_manager.cc
+++ b/netlink_manager.cc
@@ -331,11 +331,11 @@
     message_handlers_[message->sequence_number()] = handler;
   }
 
-  SLOG(WiFi, 6) << "NL Message " << message->sequence_number()
+  SLOG(WiFi, 5) << "NL Message " << message->sequence_number()
                 << " Sending (" << message_string.GetLength()
                 << " bytes) ===>";
-  message->Print(6);
-  NetlinkMessage::PrintBytes(6, message_string.GetConstData(),
+  message->Print(6, 7);
+  NetlinkMessage::PrintBytes(8, message_string.GetConstData(),
                              message_string.GetLength());
 
   if (!sock_->SendMessage(message_string)) {
@@ -416,15 +416,15 @@
     SLOG(WiFi, 3) << __func__ << "(msg:NULL)";
     return;  // Skip current message, continue parsing buffer.
   }
-  SLOG(WiFi, 3) << "NL Message " << sequence_number
+  SLOG(WiFi, 5) << "NL Message " << sequence_number
                 << " Received (" << msg->nlmsg_len << " bytes) <===";
-  message->Print(6);
+  message->Print(6, 7);
   NetlinkMessage::PrintBytes(8, reinterpret_cast<const unsigned char *>(msg),
                              msg->nlmsg_len);
 
   // Call (then erase) any message-specific handler.
   if (ContainsKey(message_handlers_, sequence_number)) {
-    SLOG(WiFi, 3) << "found message-specific handler";
+    SLOG(WiFi, 6) << "found message-specific handler";
     if (message_handlers_[sequence_number].is_null()) {
       LOG(ERROR) << "NetlinkMessageHandler exists but is NULL for ID "
                  << sequence_number;
@@ -443,16 +443,16 @@
       }
     } else if ((message->flags() & NLM_F_MULTI) &&
         (message->message_type() != NLMSG_DONE)) {
-      SLOG(WiFi, 3) << "Multi-part message -- not removing callback";
+      SLOG(WiFi, 6) << "Multi-part message -- not removing callback";
     } else {
-      SLOG(WiFi, 3) << "Removing callback";
+      SLOG(WiFi, 6) << "Removing callback";
       message_handlers_.erase(sequence_number);
     }
   } else {
     list<NetlinkMessageHandler>::const_iterator i =
         broadcast_handlers_.begin();
     while (i != broadcast_handlers_.end()) {
-      SLOG(WiFi, 3) << __func__ << " - calling broadcast handler";
+      SLOG(WiFi, 6) << __func__ << " - calling broadcast handler";
       i->Run(*message);
       ++i;
     }
diff --git a/netlink_message.cc b/netlink_message.cc
index 08ed514..dfb75af 100644
--- a/netlink_message.cc
+++ b/netlink_message.cc
@@ -177,8 +177,9 @@
   return output;
 }
 
-void ErrorAckMessage::Print(int log_level) const {
-  SLOG(WiFi, log_level) << ToString();
+void ErrorAckMessage::Print(int header_log_level,
+                            int /*detail_log_level*/) const {
+  SLOG(WiFi, header_log_level) << ToString();
 }
 
 // NoopMessage.
@@ -190,8 +191,8 @@
   return ByteString();
 }
 
-void NoopMessage::Print(int log_level) const {
-  SLOG(WiFi, log_level) << ToString();
+void NoopMessage::Print(int header_log_level, int /*detail_log_level*/) const {
+  SLOG(WiFi, header_log_level) << ToString();
 }
 
 // DoneMessage.
@@ -204,8 +205,8 @@
   return ByteString();
 }
 
-void DoneMessage::Print(int log_level) const {
-  SLOG(WiFi, log_level) << ToString();
+void DoneMessage::Print(int header_log_level, int /*detail_log_level*/) const {
+  SLOG(WiFi, header_log_level) << ToString();
 }
 
 // OverrunMessage.
@@ -217,8 +218,9 @@
   return ByteString();
 }
 
-void OverrunMessage::Print(int log_level) const {
-  SLOG(WiFi, log_level) << ToString();
+void OverrunMessage::Print(int header_log_level,
+                           int /*detail_log_level*/) const {
+  SLOG(WiFi, header_log_level) << ToString();
 }
 
 // UnknownMessage.
@@ -228,7 +230,8 @@
   return ByteString();
 }
 
-void UnknownMessage::Print(int log_level) const {
+void UnknownMessage::Print(int header_log_level,
+                           int /*detail_log_level*/) const {
   int total_bytes = message_body_.GetLength();
   const uint8_t *const_data = message_body_.GetConstData();
 
@@ -236,7 +239,7 @@
   for (int i = 0; i < total_bytes; ++i) {
     StringAppendF(&output, " 0x%02x", const_data[i]);
   }
-  SLOG(WiFi, log_level) << output;
+  SLOG(WiFi, header_log_level) << output;
 }
 
 //
diff --git a/netlink_message.h b/netlink_message.h
index 8eae625..5b059e1 100644
--- a/netlink_message.h
+++ b/netlink_message.h
@@ -84,7 +84,9 @@
   void AddFlag(uint16_t new_flag) { flags_ |= new_flag; }
   uint16_t flags() const { return flags_; }
   uint32_t sequence_number() const { return sequence_number_; }
-  virtual void Print(int log_level) const = 0;
+  // Logs the message.  Allows a different log level (presumably more
+  // stringent) for the body of the message than the header.
+  virtual void Print(int header_log_level, int detail_log_level) const = 0;
 
   // Logs the message's raw bytes (with minimal interpretation).
   static void PrintBytes(int log_level, const unsigned char *buf,
@@ -123,7 +125,7 @@
   ErrorAckMessage() : NetlinkMessage(kMessageType), error_(0) {}
   virtual bool InitFromNlmsg(const nlmsghdr *const_msg);
   virtual ByteString Encode(uint32_t sequence_number);
-  virtual void Print(int log_level) const;
+  virtual void Print(int header_log_level, int detail_log_level) const;
   std::string ToString() const;
   uint32_t error() const { return -error_; }
 
@@ -140,7 +142,7 @@
 
   NoopMessage() : NetlinkMessage(kMessageType) {}
   virtual ByteString Encode(uint32_t sequence_number);
-  virtual void Print(int log_level) const;
+  virtual void Print(int header_log_level, int detail_log_level) const;
   std::string ToString() const { return "<NOOP>"; }
 
  private:
@@ -154,7 +156,7 @@
 
   DoneMessage() : NetlinkMessage(kMessageType) {}
   virtual ByteString Encode(uint32_t sequence_number);
-  virtual void Print(int log_level) const;
+  virtual void Print(int header_log_level, int detail_log_level) const;
   std::string ToString() const { return "<DONE with multipart message>"; }
 
  private:
@@ -168,7 +170,7 @@
 
   OverrunMessage() : NetlinkMessage(kMessageType) {}
   virtual ByteString Encode(uint32_t sequence_number);
-  virtual void Print(int log_level) const;
+  virtual void Print(int header_log_level, int detail_log_level) const;
   std::string ToString() const { return "<OVERRUN - data lost>"; }
 
  private:
@@ -181,7 +183,7 @@
   UnknownMessage(uint16_t message_type, ByteString message_body) :
       NetlinkMessage(message_type), message_body_(message_body) {}
   virtual ByteString Encode(uint32_t sequence_number);
-  virtual void Print(int log_level) const;
+  virtual void Print(int header_log_level, int detail_log_level) const;
 
  private:
   ByteString message_body_;