Cleanup network event logging, add to ManagedNetworkConfigurationHandler

I noticed we were getting some ERROR spam when we request properites for
networks that are no longer visible, which required some additiona
logging to track down (and hopefully make it easier to track down other
issues in the future).

BUG=none
TBR=pneubeck@chromium.org

Original CL: https://codereview.chromium.org/207183003/

Review URL: https://codereview.chromium.org/210073007

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@259145 0039d316-1c4b-4281-b951-d872f2087c98

6 files changed, 75 insertions, 31 deletions

diff --git a/chromeos/network/managed_network_configuration_handler_impl.cc b/chromeos/network/managed_network_configuration_handler_impl.cc
index 67ab01f..f233147 100644
--- a/chromeos/network/managed_network_configuration_handler_impl.cc
+++ b/chromeos/network/managed_network_configuration_handler_impl.cc
@@ -69,7 +69,10 @@ void InvokeErrorCallback(const std::string& service_path,
 void LogErrorWithDict(const tracked_objects::Location& from_where,
                       const std::string& error_name,
                       scoped_ptr<base::DictionaryValue> error_data) {
-  LOG(ERROR) << from_where.ToString() << ": " << error_name;
+  network_event_log::internal::AddEntry(
+       from_where.file_name(), from_where.line_number(),
+       network_event_log::LOG_LEVEL_ERROR,
+       error_name, "");
 }
 
 const base::DictionaryValue* GetByGUID(const GuidToPolicyMap& policies,
@@ -143,10 +146,8 @@ void ManagedNetworkConfigurationHandlerImpl::GetManagedPropertiesCallback(
                                                  &profile_path);
   const NetworkProfile* profile =
       network_profile_handler_->GetProfileForPath(profile_path);
-  if (!profile) {
-    LOG(ERROR) << "No or no known profile received for service "
-            << service_path << ".";
-  }
+  if (!profile)
+    NET_LOG_ERROR("No profile for service: " + profile_path, service_path);
 
   scoped_ptr<NetworkUIData> ui_data =
       shill_property_util::GetUIDataFromProperties(shill_properties);
@@ -162,8 +163,7 @@ void ManagedNetworkConfigurationHandlerImpl::GetManagedPropertiesCallback(
     else
       NOTREACHED();
   } else if (profile) {
-    LOG(WARNING) << "Service " << service_path << " of profile "
-                 << profile_path << " contains no or no valid UIData.";
+    NET_LOG_ERROR("Service contains empty or invalid UIData", service_path);
     // TODO(pneubeck): add a conversion of user configured entries of old
     // ChromeOS versions. We will have to use a heuristic to determine which
     // properties _might_ be user configured.
@@ -377,9 +377,8 @@ void ManagedNetworkConfigurationHandlerImpl::SetPolicy(
     DCHECK(!guid.empty());
 
     if (policies->per_network_config.count(guid) > 0) {
-      LOG(ERROR) << "ONC from " << ToDebugString(onc_source, userhash)
-                 << " contains several entries for the same GUID "
-                 << guid << ".";
+      NET_LOG_ERROR("ONC from " + ToDebugString(onc_source, userhash) +
+                    " contains several entries for the same GUID ", guid);
       delete policies->per_network_config[guid];
     }
     const base::DictionaryValue* new_entry = network->DeepCopy();
@@ -461,7 +460,9 @@ void ManagedNetworkConfigurationHandlerImpl::
   existing_properties.GetStringWithoutPathExpansion(shill::kProfileProperty,
                                                     &profile);
   if (profile.empty()) {
-    LOG(ERROR) << "Missing profile property.";
+    NET_LOG_ERROR("Missing profile property",
+                  shill_property_util::GetNetworkIdFromProperties(
+                      existing_properties));
     return;
   }
   shill_properties.SetStringWithoutPathExpansion(shill::kProfileProperty,
@@ -469,7 +470,9 @@ void ManagedNetworkConfigurationHandlerImpl::
 
   if (!shill_property_util::CopyIdentifyingProperties(existing_properties,
                                                       &shill_properties)) {
-    LOG(ERROR) << "Missing identifying properties.";
+    NET_LOG_ERROR("Missing identifying properties",
+                  shill_property_util::GetNetworkIdFromProperties(
+                      existing_properties));
   }
 
   shill_properties.MergeDictionary(&new_properties);
@@ -536,7 +539,7 @@ ManagedNetworkConfigurationHandlerImpl::FindPolicyByGuidAndProfile(
   const NetworkProfile* profile =
       network_profile_handler_->GetProfileForPath(profile_path);
   if (!profile) {
-    LOG(ERROR) << "Profile path unknown: " << profile_path;
+    NET_LOG_ERROR("Profile path unknown:" + profile_path, guid);
     return NULL;
   }
 
diff --git a/chromeos/network/network_configuration_handler.cc b/chromeos/network/network_configuration_handler.cc
index 315f7a8..ea81a75 100644
--- a/chromeos/network/network_configuration_handler.cc
+++ b/chromeos/network/network_configuration_handler.cc
@@ -53,13 +53,6 @@ void GetPropertiesCallback(
     const std::string& service_path,
     DBusMethodCallStatus call_status,
     const base::DictionaryValue& properties) {
-  // Get the correct name from WifiHex if necessary.
-  scoped_ptr<base::DictionaryValue> properties_copy(properties.DeepCopy());
-  std::string name =
-      shill_property_util::GetNameFromProperties(service_path, properties);
-  if (!name.empty()) {
-    properties_copy->SetStringWithoutPathExpansion(shill::kNameProperty, name);
-  }
   if (call_status != DBUS_METHOD_CALL_SUCCESS) {
     // Because network services are added and removed frequently, we will see
     // failures regularly, so don't log these.
@@ -67,9 +60,18 @@ void GetPropertiesCallback(
                                       service_path,
                                       network_handler::kDBusFailedError,
                                       network_handler::kDBusFailedErrorMessage);
-  } else if (!callback.is_null()) {
-    callback.Run(service_path, *properties_copy.get());
+    return;
   }
+  if (callback.is_null())
+    return;
+
+  // Get the correct name from WifiHex if necessary.
+  scoped_ptr<base::DictionaryValue> properties_copy(properties.DeepCopy());
+  std::string name =
+      shill_property_util::GetNameFromProperties(service_path, properties);
+  if (!name.empty())
+    properties_copy->SetStringWithoutPathExpansion(shill::kNameProperty, name);
+  callback.Run(service_path, *properties_copy.get());
 }
 
 void SetNetworkProfileErrorCallback(
@@ -267,15 +269,17 @@ void NetworkConfigurationHandler::CreateConfiguration(
       DBusThreadManager::Get()->GetShillManagerClient();
   std::string type;
   properties.GetStringWithoutPathExpansion(shill::kTypeProperty, &type);
+  DCHECK(!type.empty());
   if (NetworkTypePattern::Ethernet().MatchesType(type)) {
     InvokeErrorCallback(
-        "" /* no service path */,
+        shill_property_util::GetNetworkIdFromProperties(properties),
         error_callback,
-        "ConfigureServiceForProfile is not implemented for Ethernet");
+        "ConfigureServiceForProfile: Invalid type: " + type);
     return;
   }
 
-  NET_LOG_USER("CreateConfiguration", type);
+  NET_LOG_USER("CreateConfiguration: " + type,
+               shill_property_util::GetNetworkIdFromProperties(properties));
   LogConfigProperties("Configure", type, properties);
 
   std::string profile;
diff --git a/chromeos/network/network_configuration_handler_unittest.cc b/chromeos/network/network_configuration_handler_unittest.cc
index 03fabc4..f181848 100644
--- a/chromeos/network/network_configuration_handler_unittest.cc
+++ b/chromeos/network/network_configuration_handler_unittest.cc
@@ -346,9 +346,12 @@ TEST_F(NetworkConfigurationHandlerTest, ClearPropertiesError) {
 TEST_F(NetworkConfigurationHandlerTest, CreateConfiguration) {
   std::string networkName = "MyNetwork";
   std::string key = "SSID";
+  std::string type = "wifi";
   std::string profile = "profile path";
   base::DictionaryValue value;
   shill_property_util::SetSSID(networkName, &value);
+  value.SetWithoutPathExpansion(shill::kTypeProperty,
+                                base::Value::CreateStringValue(type));
   value.SetWithoutPathExpansion(shill::kProfileProperty,
                                 base::Value::CreateStringValue(profile));
 
diff --git a/chromeos/network/network_state.cc b/chromeos/network/network_state.cc
index e6f344d..eb598f0 100644
--- a/chromeos/network/network_state.cc
+++ b/chromeos/network/network_state.cc
@@ -158,7 +158,13 @@ bool NetworkState::PropertyChanged(const std::string& key,
 bool NetworkState::InitialPropertiesReceived(
     const base::DictionaryValue& properties) {
   NET_LOG_DEBUG("InitialPropertiesReceived", path());
-  bool changed = UpdateName(properties);
+  bool changed = false;
+  if (!properties.HasKey(shill::kTypeProperty)) {
+    NET_LOG_ERROR("NetworkState has no type",
+                  shill_property_util::GetNetworkIdFromProperties(properties));
+  } else {
+    changed |= UpdateName(properties);
+  }
   bool had_ca_cert_nss = has_ca_cert_nss_;
   has_ca_cert_nss_ = IsCaCertNssSet(properties);
   changed |= had_ca_cert_nss != has_ca_cert_nss_;
diff --git a/chromeos/network/shill_property_util.cc b/chromeos/network/shill_property_util.cc
index 613478e..35e4bb1 100644
--- a/chromeos/network/shill_property_util.cc
+++ b/chromeos/network/shill_property_util.cc
@@ -120,6 +120,22 @@ std::string GetSSIDFromProperties(const base::DictionaryValue& properties,
   return ssid;
 }
 
+std::string GetNetworkIdFromProperties(
+    const base::DictionaryValue& properties) {
+  if (properties.empty())
+    return "EmptyProperties";
+  std::string result;
+  if (properties.GetStringWithoutPathExpansion(shill::kGuidProperty, &result))
+    return result;
+  if (properties.GetStringWithoutPathExpansion(shill::kSSIDProperty, &result))
+    return result;
+  if (properties.GetStringWithoutPathExpansion(shill::kNameProperty, &result))
+    return result;
+  std::string type = "UnknownType";
+  properties.GetStringWithoutPathExpansion(shill::kTypeProperty, &type);
+  return "Unidentified " + type;
+}
+
 std::string GetNameFromProperties(const std::string& service_path,
                                   const base::DictionaryValue& properties) {
   std::string name;
@@ -135,6 +151,10 @@ std::string GetNameFromProperties(const std::string& service_path,
 
   std::string type;
   properties.GetStringWithoutPathExpansion(shill::kTypeProperty, &type);
+  if (type.empty()) {
+    NET_LOG_ERROR("GetNameFromProperties: No type", service_path);
+    return validated_name;
+  }
   if (!NetworkTypePattern::WiFi().MatchesType(type))
     return validated_name;
 
@@ -222,8 +242,9 @@ bool CopyIdentifyingProperties(const base::DictionaryValue& service_properties,
     // with the keys "Provider.Type" and "Provider.Host".
     const base::DictionaryValue* provider_properties = NULL;
     if (!service_properties.GetDictionaryWithoutPathExpansion(
-             shill::kProviderProperty, &provider_properties)) {
-      NET_LOG_ERROR("CopyIdentifyingProperties", "Missing VPN provider dict");
+            shill::kProviderProperty, &provider_properties)) {
+      NET_LOG_ERROR("Missing VPN provider dict",
+                    GetNetworkIdFromProperties(service_properties));
       return false;
     }
     std::string vpn_provider_type;
@@ -246,8 +267,10 @@ bool CopyIdentifyingProperties(const base::DictionaryValue& service_properties,
     NOTREACHED() << "Unsupported network type " << type;
     success = false;
   }
-  if (!success)
-    NET_LOG_ERROR("CopyIdentifyingProperties", "Missing required properties");
+  if (!success) {
+    NET_LOG_ERROR("Missing required properties",
+                  GetNetworkIdFromProperties(service_properties));
+  }
   return success;
 }
 
diff --git a/chromeos/network/shill_property_util.h b/chromeos/network/shill_property_util.h
index ebc7bb3..4ae1df5 100644
--- a/chromeos/network/shill_property_util.h
+++ b/chromeos/network/shill_property_util.h
@@ -31,7 +31,12 @@ CHROMEOS_EXPORT std::string GetSSIDFromProperties(
     const base::DictionaryValue& properties,
     bool* unknown_encoding);
 
-// Returns the name for the network represented by the Shill |properties|. For
+// Returns the GUID (if available), SSID, or Name from |properties|. Only used
+// for logging and debugging.
+CHROMEOS_EXPORT std::string GetNetworkIdFromProperties(
+    const base::DictionaryValue& properties);
+
+  // Returns the name for the network represented by the Shill |properties|. For
 // WiFi it refers to the HexSSID.
 CHROMEOS_EXPORT std::string GetNameFromProperties(
     const std::string& service_path,