Fix logic for default network notification

chromeos/network/network_state_handler.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 "chromeos/network/network_state_handler.h"
 
 #include "base/bind.h"
 #include "base/format_macros.h"
 #include "base/guid.h"
 #include "base/json/json_string_value_serializer.h"
@@ skipping 746 matching lines @@
 
 void NetworkStateHandler::DefaultNetworkServiceChanged(
     const std::string& service_path) {
   // Shill uses '/' for empty service path values; check explicitly for that.
   const char* kEmptyServicePath = "/";
   std::string new_service_path =
       (service_path != kEmptyServicePath) ? service_path : "";
   if (new_service_path == default_network_path_)
     return;
 
   default_network_path_ = service_path;

[pneubeck (no reviews), 2015/03/12 09:57:48]

Not that it is affecting this CL, but just a reminder:

You fix the notifications sent out by NetworkStateHandler, but the exposed state
might still show a connecting default network.
I.e. if someone happens to poll the network state at an unlucky moment, he will
still see this weird state.

[stevenjb, 2015/03/12 16:42:28]

Yes, that is true. I've limited the notifications here to reduce noise, and
hopefully we will now end up always in a stable state, but the rest of the code
should be able to handle an intermediate state with a non connected default
network. Might be worth re-examining that though.

Ideally Shill will never set this to a non connected network so the state update
for the network will immediately follow, before any notifications are triggered
(now).

   NET_LOG_EVENT("DefaultNetworkServiceChanged:", default_network_path_);
   const NetworkState* network = nullptr;
   if (!default_network_path_.empty()) {
     network = GetNetworkState(default_network_path_);
     if (!network) {
       // If NetworkState is not available yet, do not notify observers here,
       // they will be notified when the state is received.
-      NET_LOG_DEBUG("Default NetworkState not available",
-                    default_network_path_);
+      NET_LOG(EVENT) "Default NetworkState not available: "

[pneubeck (no reviews), 2015/03/12 09:57:48]

missing '<<' after NET_LOG(EVENT) ?

how can this compile?

[stevenjb, 2015/03/12 16:42:28]

It doesn't. Last second change to use the same LOG format within the function on
self review.
Fixed.

+          << default_network_path_;
       return;
     }
   }
   if (network && !network->IsConnectedState()) {
-    NET_LOG_ERROR(
-        "DefaultNetwork is not connected: " + network->connection_state(),
-        network->path());
+    NET_LOG(EVENT) << "DefaultNetwork is not connected: " << GetLogName(network)
+                   << ": " << network->connection_state();
+    // Do not notify observers here, the notification will occur when the

[pneubeck (no reviews), 2015/03/12 09:57:48]

is it worth logging an error here if the state is neither Connected nor
Connecting? (as you do in the OnNetworkConnectionStateChanged function below)

[stevenjb, 2015/03/12 16:42:28]

Yes, done.

+    // connection state changes.

[Paul Stewart, 2015/03/11 23:29:03]

Awesome.  This might fix some page load attempts before the connection is fully
up.

[stevenjb, 2015/03/12 16:42:28]

I hope so!

+    return;
   }
   NotifyDefaultNetworkChanged(network);
 }
 
 //------------------------------------------------------------------------------
 // Private methods
 
 void NetworkStateHandler::UpdateGuid(NetworkState* network) {
   std::string specifier = network->GetSpecifier();
   DCHECK(!specifier.empty());
@@ skipping 66 matching lines @@
       return &device_list_;
   }
   NOTREACHED();
   return nullptr;
 }
 
 void NetworkStateHandler::OnNetworkConnectionStateChanged(
     NetworkState* network) {
   SCOPED_NET_LOG_IF_SLOW();
   DCHECK(network);
-  std::string event = "NetworkConnectionStateChanged";
+  bool notify_default = false;
   if (network->path() == default_network_path_) {
-    event = "Default" + event;
-    if (!network->IsConnectedState()) {
-      NET_LOG_EVENT(
-          "DefaultNetwork is not connected: " + network->connection_state(),
-          network->path());
+    if (network->IsConnectedState()) {
+      notify_default = true;
+    } else if (network->IsConnectingState()) {
+      // Wait until the network is actually connected to notify that the default
+      // network changed.
+      NET_LOG(EVENT) << "Default network is not connected: "
+                     << GetLogName(network)
+                     << "State: " << network->connection_state();
+    } else {
+      NET_LOG(ERROR) << "Default network in unexpected state: "
+                     << GetLogName(network)
+                     << "State: " << network->connection_state();
       default_network_path_.clear();
       SortNetworkList();
       NotifyDefaultNetworkChanged(nullptr);
     }
   }
-  NET_LOG_EVENT("NOTIFY:" + event + ": " + network->connection_state(),
-                GetLogName(network));
+  std::string desc = "NetworkConnectionStateChanged";
+  if (notify_default)

[pneubeck (no reviews), 2015/03/12 09:57:48]

the log message should always use the prefix 'Default' if the default network is
affected. Currently, you do that only if the default network is also connected.

Note, that you can also not compare network-path() with default_network_path_
here anymore, since the latter is cleared in line 886.

[stevenjb, 2015/03/12 16:42:28]

My intention is to have the log match the *notification* (thus the NOTIFY:
prefix). The logic is to avoid having two nearly identical log messages when we
notify about the default network changing.

We log DefaultNetworkServiceChanged on line 768.

[pneubeck (no reviews), 2015/03/12 19:40:09]

ok, makes sense.

+    desc = "Default" + desc;
+  NET_LOG(EVENT) << "NOTIFY: " << desc << ": " << GetLogName(network) << ": "
+                 << network->connection_state();
   FOR_EACH_OBSERVER(NetworkStateHandlerObserver, observers_,
                     NetworkConnectionStateChanged(network));
-  if (network->path() == default_network_path_)
+  if (notify_default)
     NotifyDefaultNetworkChanged(network);
 }
 
 void NetworkStateHandler::NotifyDefaultNetworkChanged(
     const NetworkState* default_network) {
   SCOPED_NET_LOG_IF_SLOW();
   NET_LOG_EVENT("NOTIFY:DefaultNetworkChanged", GetLogName(default_network));
   FOR_EACH_OBSERVER(NetworkStateHandlerObserver, observers_,
                     DefaultNetworkChanged(default_network));
 }
@@ skipping 59 matching lines @@
   if (type.MatchesType(shill::kTypeBluetooth))
     technologies.push_back(new std::string(shill::kTypeBluetooth));
   if (type.MatchesType(shill::kTypeVPN))
     technologies.push_back(new std::string(shill::kTypeVPN));
 
   CHECK_GT(technologies.size(), 0ul);
   return technologies.Pass();
 }
 
 }  // namespace chromeos