From c8fe6fcfb89325ca1a685acc3ba4f2dd859402cd Mon Sep 17 00:00:00 2001 From: Roger Wang Date: Fri, 19 Apr 2019 17:12:13 +0800 Subject: LRWD: Restrict LRWD auto bug report notification 1. Avoid LRWD from triggering a bugreport unnecessarily. Bugreport triggered only if device connected to same SSID after LRWD recovery. 2. Add locallog mechanism Bug: 130148428 Bug: 119887816 Test: Manual test Test: ./frameworks/opt/net/wifi/tests/wifitests/runtests.sh OK (3689 tests) Change-Id: I206ba630297b9e5cbfaf48fd1f9489ee2849db52 --- .../com/android/server/wifi/ClientModeImpl.java | 1 + .../server/wifi/WifiLastResortWatchdog.java | 76 +++++++++++++++++---- .../server/wifi/WifiLastResortWatchdogTest.java | 79 ++++++++++++++++++++++ 3 files changed, 144 insertions(+), 12 deletions(-) diff --git a/service/java/com/android/server/wifi/ClientModeImpl.java b/service/java/com/android/server/wifi/ClientModeImpl.java index 0bdd37b1a..3cdc2ef74 100644 --- a/service/java/com/android/server/wifi/ClientModeImpl.java +++ b/service/java/com/android/server/wifi/ClientModeImpl.java @@ -2042,6 +2042,7 @@ public class ClientModeImpl extends StateMachine { mWifiConnectivityManager.dump(fd, pw, args); mWifiInjector.getWakeupController().dump(fd, pw, args); mLinkProbeManager.dump(fd, pw, args); + mWifiInjector.getWifiLastResortWatchdog().dump(fd, pw, args); } /** diff --git a/service/java/com/android/server/wifi/WifiLastResortWatchdog.java b/service/java/com/android/server/wifi/WifiLastResortWatchdog.java index 8ebd938b3..6889b5016 100644 --- a/service/java/com/android/server/wifi/WifiLastResortWatchdog.java +++ b/service/java/com/android/server/wifi/WifiLastResortWatchdog.java @@ -20,11 +20,15 @@ import android.net.wifi.ScanResult; import android.net.wifi.WifiConfiguration; import android.os.Handler; import android.os.Looper; +import android.text.TextUtils; +import android.util.LocalLog; import android.util.Log; import android.util.Pair; import com.android.internal.annotations.VisibleForTesting; +import java.io.FileDescriptor; +import java.io.PrintWriter; import java.util.HashMap; import java.util.Iterator; import java.util.List; @@ -90,6 +94,7 @@ public class WifiLastResortWatchdog { // successfully connecting or a new network (SSID) becomes available to connect to. private boolean mWatchdogAllowedToTrigger = true; private long mTimeLastTrigger = 0; + private String mSsidLastTrigger = null; private WifiInjector mWifiInjector; private WifiMetrics mWifiMetrics; @@ -101,6 +106,11 @@ public class WifiLastResortWatchdog { // did not fix the problem private boolean mWatchdogFixedWifi = true; + /** + * Local log used for debugging any WifiLastResortWatchdog issues. + */ + private final LocalLog mLocalLog = new LocalLog(100); + WifiLastResortWatchdog(WifiInjector wifiInjector, Clock clock, WifiMetrics wifiMetrics, ClientModeImpl clientModeImpl, Looper clientModeImplLooper) { mWifiInjector = wifiInjector; @@ -154,6 +164,7 @@ public class WifiLastResortWatchdog { if (mTimeLastTrigger == 0 || (mClock.getElapsedSinceBootMillis() - mTimeLastTrigger) >= LAST_TRIGGER_TIMEOUT_MILLIS) { + localLog("updateAvailableNetworks: setWatchdogTriggerEnabled to true"); setWatchdogTriggerEnabled(true); } } else { @@ -231,10 +242,13 @@ public class WifiLastResortWatchdog { } if (isRestartNeeded) { // Stop the watchdog from triggering until re-enabled + localLog("noteConnectionFailureAndTriggerIfNeeded: setWatchdogTriggerEnabled to false"); setWatchdogTriggerEnabled(false); mWatchdogFixedWifi = true; - Log.e(TAG, "Watchdog triggering recovery"); + loge("Watchdog triggering recovery"); + mSsidLastTrigger = ssid; mTimeLastTrigger = mClock.getElapsedSinceBootMillis(); + localLog(toString()); mWifiInjector.getSelfRecovery().trigger(SelfRecovery.REASON_LAST_RESORT_WATCHDOG); incrementWifiMetricsTriggerCounts(); clearAllFailureCounts(); @@ -248,15 +262,15 @@ public class WifiLastResortWatchdog { * @param isEntering true if called from ConnectedState.enter(), false for exit() */ public void connectedStateTransition(boolean isEntering) { - if (mVerboseLoggingEnabled) { - Log.v(TAG, "connectedStateTransition: isEntering = " + isEntering); - } + logv("connectedStateTransition: isEntering = " + isEntering); + mWifiIsConnected = isEntering; if (!isEntering) { return; } if (!mWatchdogAllowedToTrigger && mWatchdogFixedWifi - && checkIfAtleastOneNetworkHasEverConnected()) { + && checkIfAtleastOneNetworkHasEverConnected() + && checkIfConnectedBackToSameSsid()) { takeBugReportWithCurrentProbability("Wifi fixed after restart"); // WiFi has connected after a Watchdog trigger, without any new networks becoming // available, log a Watchdog success in wifi metrics @@ -268,9 +282,22 @@ public class WifiLastResortWatchdog { clearAllFailureCounts(); // If the watchdog trigger was disabled (it triggered), connecting means we did // something right, re-enable it so it can fire again. + localLog("connectedStateTransition: setWatchdogTriggerEnabled to true"); setWatchdogTriggerEnabled(true); } + /** + * Helper function to check if device connect back to same + * SSID after watchdog trigger + */ + private boolean checkIfConnectedBackToSameSsid() { + if (TextUtils.equals(mSsidLastTrigger, mClientModeImpl.getWifiInfo().getSSID())) { + return true; + } + localLog("checkIfConnectedBackToSameSsid: different SSID be connected"); + return false; + } + /** * Triggers a wifi specific bugreport with a based on the current trigger probability. * @param bugDetail description of the bug @@ -294,10 +321,8 @@ public class WifiLastResortWatchdog { * @param reason Message id from ClientModeImpl for this failure */ private void updateFailureCountForNetwork(String ssid, String bssid, int reason) { - if (mVerboseLoggingEnabled) { - Log.v(TAG, "updateFailureCountForNetwork: [" + ssid + ", " + bssid + ", " - + reason + "]"); - } + logv("updateFailureCountForNetwork: [" + ssid + ", " + bssid + ", " + + reason + "]"); if (BSSID_ANY.equals(bssid)) { incrementSsidFailureCount(ssid, reason); } else { @@ -428,9 +453,7 @@ public class WifiLastResortWatchdog { // We have met the failure count for every available network. // Trigger restart if there exists at-least one network that we have previously connected. boolean atleastOneNetworkHasEverConnected = checkIfAtleastOneNetworkHasEverConnected(); - if (mVerboseLoggingEnabled) { - Log.v(TAG, "checkTriggerCondition: return = " + atleastOneNetworkHasEverConnected); - } + logv("checkTriggerCondition: return = " + atleastOneNetworkHasEverConnected); return checkIfAtleastOneNetworkHasEverConnected(); } @@ -664,4 +687,33 @@ public class WifiLastResortWatchdog { + "}"; } } + + /** + * Helper function for logging into local log buffer. + */ + private void localLog(String s) { + mLocalLog.log(s); + } + + private void logv(String s) { + mLocalLog.log(s); + if (mVerboseLoggingEnabled) { + Log.v(TAG, s); + } + } + + private void loge(String s) { + mLocalLog.log(s); + Log.e(TAG, s); + } + + /** + * Dump the local log buffer and other internal state of WifiLastResortWatchdog. + */ + public void dump(FileDescriptor fd, PrintWriter pw, String[] args) { + pw.println("Dump of WifiLastResortWatchdog"); + pw.println("WifiLastResortWatchdog - Log Begin ----"); + mLocalLog.dump(fd, pw, args); + pw.println("WifiLastResortWatchdog - Log End ----"); + } } diff --git a/tests/wifitests/src/com/android/server/wifi/WifiLastResortWatchdogTest.java b/tests/wifitests/src/com/android/server/wifi/WifiLastResortWatchdogTest.java index a47b2cc17..9ae382640 100644 --- a/tests/wifitests/src/com/android/server/wifi/WifiLastResortWatchdogTest.java +++ b/tests/wifitests/src/com/android/server/wifi/WifiLastResortWatchdogTest.java @@ -22,6 +22,7 @@ import static org.mockito.Mockito.*; import static org.mockito.MockitoAnnotations.*; import android.net.wifi.WifiConfiguration; +import android.net.wifi.WifiInfo; import android.net.wifi.WifiSsid; import android.os.test.TestLooper; import android.util.Pair; @@ -47,6 +48,7 @@ public class WifiLastResortWatchdogTest { @Mock SelfRecovery mSelfRecovery; @Mock ClientModeImpl mClientModeImpl; @Mock Clock mClock; + @Mock WifiInfo mWifiInfo; private String[] mSsids = {"\"test1\"", "\"test2\"", "\"test3\"", "\"test4\""}; private String[] mBssids = {"6c:f3:7f:ae:8c:f3", "6c:f3:7f:ae:8c:f4", "de:ad:ba:b1:e5:55", @@ -58,6 +60,7 @@ public class WifiLastResortWatchdogTest { private boolean[] mIsEphemeral = {false, false, false, false}; private boolean[] mHasEverConnected = {false, false, false, false}; private TestLooper mLooper; + private static final String TEST_NETWORK_SSID = "\"test_ssid\""; @Before public void setUp() throws Exception { @@ -67,6 +70,8 @@ public class WifiLastResortWatchdogTest { mLastResortWatchdog = new WifiLastResortWatchdog(mWifiInjector, mClock, mWifiMetrics, mClientModeImpl, mLooper.getLooper()); mLastResortWatchdog.setBugReportProbability(1); + when(mClientModeImpl.getWifiInfo()).thenReturn(mWifiInfo); + when(mWifiInfo.getSSID()).thenReturn(TEST_NETWORK_SSID); } private List> createFilteredQnsCandidates(String[] ssids, @@ -1500,6 +1505,9 @@ public class WifiLastResortWatchdogTest { verify(mWifiMetrics, times(1)).addCountToNumLastResortWatchdogBadDhcpNetworksTotal(3); verify(mWifiMetrics, times(1)).incrementNumLastResortWatchdogTriggersWithBadDhcp(); + // set connection to ssids[0] + when(mWifiInfo.getSSID()).thenReturn(ssids[0]); + // Simulate wifi connecting after triggering mLastResortWatchdog.connectedStateTransition(true); @@ -1836,6 +1844,9 @@ public class WifiLastResortWatchdogTest { // Simulate wifi disconnecting mLastResortWatchdog.connectedStateTransition(false); + // set connection to ssids[0] + when(mWifiInfo.getSSID()).thenReturn(ssids[0]); + // Test another round, and this time successfully connect after restart trigger for (int i = 0; i < ssids.length; i++) { assertFailureCountEquals(bssids[i], 0, 0, 0); @@ -2073,4 +2084,72 @@ public class WifiLastResortWatchdogTest { // Watchdog should not be triggerred since time based logic. verify(mWifiMetrics, times(1)).incrementNumLastResortWatchdogTriggers(); } + + /** + * Test that LRWD success is only declared when connected back to same SSID. + * + * First tests the failure case: check success metric is not incremented when the first + * connection on different SSID. + * Then test state transition and the success case: check success metric is incremented + * when the first connection on same SSID. + */ + @Test + public void testWatchdogAssumesSuccessOnlyIfConnectedOnSameSsid() { + String[] ssids = {"\"test1\""}; + String[] bssids = {"6c:f3:7f:ae:8c:f3"}; + int[] frequencies = {2437}; + String[] caps = {"[WPA2-EAP-CCMP][ESS]"}; + int[] levels = {-60}; + boolean[] isEphemeral = {false}; + boolean[] hasEverConnected = {true}; + List> candidates = createFilteredQnsCandidates(ssids, + bssids, frequencies, caps, levels, isEphemeral, hasEverConnected); + mLastResortWatchdog.updateAvailableNetworks(candidates); + + // Ensure new networks have zero'ed failure counts + for (int i = 0; i < ssids.length; i++) { + assertFailureCountEquals(bssids[i], 0, 0, 0); + } + + //Increment failure counts + for (int i = 0; i < WifiLastResortWatchdog.FAILURE_THRESHOLD; i++) { + mLastResortWatchdog.noteConnectionFailureAndTriggerIfNeeded( + ssids[0], bssids[0], WifiLastResortWatchdog.FAILURE_CODE_ASSOCIATION); + } + + // Verify watchdog has triggered a restart + verify(mWifiMetrics, times(1)).incrementNumLastResortWatchdogTriggers(); + + // Simulate wifi connecting after triggering + mLastResortWatchdog.connectedStateTransition(true); + // Verify takeBugReport is not called because connected on different SSID + mLooper.dispatchAll(); + verify(mClientModeImpl, never()).takeBugReport(anyString(), anyString()); + verify(mWifiMetrics, never()).incrementNumLastResortWatchdogSuccesses(); + + // Simulate wifi disconnecting + mLastResortWatchdog.connectedStateTransition(false); + + // set connection to ssids[0] + when(mWifiInfo.getSSID()).thenReturn(ssids[0]); + + // Test another round, and this time successfully connect after restart trigger + for (int i = 0; i < ssids.length; i++) { + assertFailureCountEquals(bssids[i], 0, 0, 0); + } + for (int i = 0; i < WifiLastResortWatchdog.FAILURE_THRESHOLD; i++) { + mLastResortWatchdog.noteConnectionFailureAndTriggerIfNeeded( + ssids[0], bssids[0], WifiLastResortWatchdog.FAILURE_CODE_ASSOCIATION); + } + + // Verify watchdog has triggered a restart + verify(mWifiMetrics, times(2)).incrementNumLastResortWatchdogTriggers(); + // Simulate wifi connecting after triggering + mLastResortWatchdog.connectedStateTransition(true); + // Verify takeBugReport is called because connected back on same SSID + mLooper.dispatchAll(); + verify(mClientModeImpl, times(1)).takeBugReport(anyString(), anyString()); + verify(mWifiMetrics, times(1)).incrementNumLastResortWatchdogSuccesses(); + } + } -- cgit v1.2.3