Additional logging to debug lost Wifi APs

This change adds some in-memory logging to get some information that
doesn't seem to get captured in bug reports readily. We can remove this
after we've got to the bottom of this issue.

This is the sort of log it produces in bugreport -

WifiConfigStore - Log Begin ----
16:30:06 - loadConfiguredNetwork GoogleGuest
16:30:06 - loadConfiguredNetworks loaded 1networks
16:30:06 - disableAllNetworks
16:30:06 - loadConfiguredNetwork GoogleGuest
16:30:06 - loadConfiguredNetworks loaded 1networks
WifiConfigStore - Log End ----

Bug: 10375978
Change-Id: Iaecd3b391aea3711bf376d6cb520217d3242e6f1

4 files changed, 80 insertions, 1 deletions

diff --git a/wifi/java/android/net/wifi/WifiConfigStore.java b/wifi/java/android/net/wifi/WifiConfigStore.java
index ad700aa..3f6fb6e 100644
--- a/wifi/java/android/net/wifi/WifiConfigStore.java
+++ b/wifi/java/android/net/wifi/WifiConfigStore.java
@@ -37,6 +37,7 @@ import android.os.HandlerThread;
 import android.os.UserHandle;
 import android.security.KeyStore;
 import android.text.TextUtils;
+import android.util.LocalLog;
 import android.util.Log;
 
 import java.io.BufferedInputStream;
@@ -108,7 +109,7 @@ class WifiConfigStore {
 
     private Context mContext;
     private static final String TAG = "WifiConfigStore";
-    private static final boolean DBG = false;
+    private static final boolean DBG = true;
 
     /* configured networks with network id as the key */
     private HashMap<Integer, WifiConfiguration> mConfiguredNetworks =
@@ -145,12 +146,19 @@ class WifiConfigStore {
     private static final String EXCLUSION_LIST_KEY = "exclusionList";
     private static final String EOS = "eos";
 
+    private final LocalLog mLocalLog;
+
     private WifiNative mWifiNative;
     private final KeyStore mKeyStore = KeyStore.getInstance();
 
     WifiConfigStore(Context c, WifiNative wn) {
         mContext = c;
         mWifiNative = wn;
+
+        if (DBG) {
+            mLocalLog = new LocalLog(1024);                         // takes about 64 K
+            mWifiNative.setLocalLog(mLocalLog);
+        }
     }
 
     /**
@@ -212,6 +220,7 @@ class WifiConfigStore {
      * @return false if the network id is invalid
      */
     boolean selectNetwork(int netId) {
+        localLog("selectNetwork", netId);
         if (netId == INVALID_NETWORK_ID) return false;
 
         // Reset the priority of each network at start or if it goes too high.
@@ -248,6 +257,7 @@ class WifiConfigStore {
      * @return network update result
      */
     NetworkUpdateResult saveNetwork(WifiConfiguration config) {
+        localLog("saveNetwork", config.networkId);
         // A new network cannot have null SSID
         if (config == null || (config.networkId == INVALID_NETWORK_ID &&
                 config.SSID == null)) {
@@ -296,6 +306,7 @@ class WifiConfigStore {
      * @return {@code true} if it succeeds, {@code false} otherwise
      */
     boolean forgetNetwork(int netId) {
+        localLog("forgetNetwork", netId);
         if (mWifiNative.removeNetwork(netId)) {
             mWifiNative.saveConfig();
             removeConfigAndSendBroadcastIfNeeded(netId);
@@ -316,6 +327,7 @@ class WifiConfigStore {
      * @return network Id
      */
     int addOrUpdateNetwork(WifiConfiguration config) {
+        localLog("addOrUpdateNetwork", config.networkId);
         NetworkUpdateResult result = addOrUpdateNetworkNative(config);
         if (result.getNetworkId() != WifiConfiguration.INVALID_NETWORK_ID) {
             sendConfiguredNetworksChangedBroadcast(mConfiguredNetworks.get(result.getNetworkId()),
@@ -335,6 +347,7 @@ class WifiConfigStore {
      * @return {@code true} if it succeeds, {@code false} otherwise
      */
     boolean removeNetwork(int netId) {
+        localLog("removeNetwork", netId);
         boolean ret = mWifiNative.removeNetwork(netId);
         if (ret) {
             removeConfigAndSendBroadcastIfNeeded(netId);
@@ -369,8 +382,10 @@ class WifiConfigStore {
     boolean enableNetwork(int netId, boolean disableOthers) {
         boolean ret = enableNetworkWithoutBroadcast(netId, disableOthers);
         if (disableOthers) {
+            localLog("enableNetwork(disableOthers=true) ", netId);
             sendConfiguredNetworksChangedBroadcast();
         } else {
+            localLog("enableNetwork(disableOthers=false) ", netId);
             WifiConfiguration enabledNetwork = null;
             synchronized(mConfiguredNetworks) {
                 enabledNetwork = mConfiguredNetworks.get(netId);
@@ -397,6 +412,7 @@ class WifiConfigStore {
     }
 
     void disableAllNetworks() {
+        localLog("disableAllNetworks");
         boolean networkDisabled = false;
         for(WifiConfiguration config : mConfiguredNetworks.values()) {
             if(config != null && config.status != Status.DISABLED) {
@@ -429,6 +445,7 @@ class WifiConfigStore {
      * @return {@code true} if it succeeds, {@code false} otherwise
      */
     boolean disableNetwork(int netId, int reason) {
+        localLog("disableNetwork", netId);
         boolean ret = mWifiNative.disableNetwork(netId);
         WifiConfiguration network = null;
         WifiConfiguration config = mConfiguredNetworks.get(netId);
@@ -639,10 +656,13 @@ class WifiConfigStore {
             config.proxySettings = ProxySettings.NONE;
             mConfiguredNetworks.put(config.networkId, config);
             mNetworkIds.put(configKey(config), config.networkId);
+            localLog("loaded configured network", config.networkId);
         }
 
         readIpAndProxyConfigurations();
         sendConfiguredNetworksChangedBroadcast();
+
+        localLog("loadConfiguredNetworks loaded " + mNetworkIds.size() + " networks");
     }
 
     /* Mark all networks except specified netId as disabled */
@@ -972,6 +992,9 @@ class WifiConfigStore {
          * network configuration. Otherwise, the networkId should
          * refer to an existing configuration.
          */
+
+        localLog("addOrUpdateNetworkNative " + config.getPrintableSsid());
+
         int netId = config.networkId;
         boolean newNetwork = false;
         // networkId of INVALID_NETWORK_ID means we want to create a new network
@@ -1577,6 +1600,12 @@ class WifiConfigStore {
             pw.println(conf);
         }
         pw.println();
+
+        if (mLocalLog != null) {
+            pw.println("WifiConfigStore - Log Begin ----");
+            mLocalLog.dump(fd, pw, args);
+            pw.println("WifiConfigStore - Log End ----");
+        }
     }
 
     public String getConfigFile() {
@@ -1590,4 +1619,28 @@ class WifiConfigStore {
     private void log(String s) {
         Log.d(TAG, s);
     }
+
+    private void localLog(String s) {
+        if (mLocalLog != null) {
+            mLocalLog.log(s);
+        }
+    }
+
+    private void localLog(String s, int netId) {
+        if (mLocalLog == null) {
+            return;
+        }
+
+        WifiConfiguration config;
+        synchronized(mConfiguredNetworks) {
+            config = mConfiguredNetworks.get(netId);
+        }
+
+        if (config != null) {
+            mLocalLog.log(s + " " + config.getPrintableSsid());
+        } else {
+            mLocalLog.log(s + " " + netId);
+        }
+    }
+
 }
diff --git a/wifi/java/android/net/wifi/WifiMonitor.java b/wifi/java/android/net/wifi/WifiMonitor.java
index a80238b..6817777 100644
--- a/wifi/java/android/net/wifi/WifiMonitor.java
+++ b/wifi/java/android/net/wifi/WifiMonitor.java
@@ -435,6 +435,7 @@ public class WifiMonitor {
                     } else {
                         mIfaceMap.remove(iface);
                         m.mWifiStateMachine.sendMessage(SUP_DISCONNECTION_EVENT);
+                        Log.e(TAG, "startMonitoring(" + iface + ") failed!");
                         break;
                     }
                 }
diff --git a/wifi/java/android/net/wifi/WifiNative.java b/wifi/java/android/net/wifi/WifiNative.java
index c3ed03c..79c1163 100644
--- a/wifi/java/android/net/wifi/WifiNative.java
+++ b/wifi/java/android/net/wifi/WifiNative.java
@@ -20,6 +20,7 @@ import android.net.wifi.p2p.WifiP2pConfig;
 import android.net.wifi.p2p.WifiP2pGroup;
 import android.text.TextUtils;
 import android.net.wifi.p2p.nsd.WifiP2pServiceInfo;
+import android.util.LocalLog;
 import android.util.Log;
 
 import java.util.ArrayList;
@@ -91,6 +92,18 @@ public class WifiNative {
         }
     }
 
+
+    private LocalLog mLocalLog;
+
+    public void setLocalLog(LocalLog l) {
+        mLocalLog = l;
+    }
+
+    private void localLog(String s) {
+        if (mLocalLog != null)
+            mLocalLog.log(mInterfaceName + ": " + s);
+    }
+
     public boolean connectToSupplicant() {
         return connectToSupplicantNative();
     }
@@ -144,15 +157,18 @@ public class WifiNative {
     }
 
     public String listNetworks() {
+        localLog("LIST_NETWORKS");
         return doStringCommand("LIST_NETWORKS");
     }
 
     public int addNetwork() {
+        localLog("ADD_NETWORK");
         return doIntCommand("ADD_NETWORK");
     }
 
     public boolean setNetworkVariable(int netId, String name, String value) {
         if (TextUtils.isEmpty(name) || TextUtils.isEmpty(value)) return false;
+        localLog("SET_NETWORK " + netId + " " + name + "=" + value);
         return doBooleanCommand("SET_NETWORK " + netId + " " + name + " " + value);
     }
 
@@ -162,22 +178,27 @@ public class WifiNative {
     }
 
     public boolean removeNetwork(int netId) {
+        localLog("REMOVE_NETWORK " + netId);
         return doBooleanCommand("REMOVE_NETWORK " + netId);
     }
 
     public boolean enableNetwork(int netId, boolean disableOthers) {
         if (disableOthers) {
+            localLog("SELECT_NETWORK " + netId);
             return doBooleanCommand("SELECT_NETWORK " + netId);
         } else {
+            localLog("ENABLE_NETWORK " + netId);
             return doBooleanCommand("ENABLE_NETWORK " + netId);
         }
     }
 
     public boolean disableNetwork(int netId) {
+        localLog("DISABLE_NETWORK " + netId);
         return doBooleanCommand("DISABLE_NETWORK " + netId);
     }
 
     public boolean reconnect() {
+        localLog("RECONNECT");
         return doBooleanCommand("RECONNECT");
     }
 
@@ -376,6 +397,7 @@ public class WifiNative {
     }
 
     public boolean saveConfig() {
+        localLog("SAVE_CONFIG");
         return doBooleanCommand("SAVE_CONFIG");
     }
 
diff --git a/wifi/java/android/net/wifi/WifiStateMachine.java b/wifi/java/android/net/wifi/WifiStateMachine.java
index 8b7b8ae..85fbdd8 100644
--- a/wifi/java/android/net/wifi/WifiStateMachine.java
+++ b/wifi/java/android/net/wifi/WifiStateMachine.java
@@ -2790,7 +2790,10 @@ public class WifiStateMachine extends StateMachine {
             } else {
                 /* Driver stop may have disabled networks, enable right after start */
                 mWifiConfigStore.enableAllNetworks();
+
+                if (DBG) log("Attempting to reconnect to wifi network ..");
                 mWifiNative.reconnect();
+
                 // Status pulls in the current supplicant state and network connection state
                 // events over the monitor connection. This helps framework sync up with
                 // current supplicant state