diff options
author | Eric Schwarzenbach <easchwar@google.com> | 2018-03-26 20:28:25 +0000 |
---|---|---|
committer | Android (Google) Code Review <android-gerrit@google.com> | 2018-03-26 20:28:25 +0000 |
commit | c2f7a0676ef6c6bec3e1e60cb8e3eecaec362026 (patch) | |
tree | 164dab084d859cd2dfdefd5332a4d610d12acc90 /service | |
parent | 2d5ae699905ffec6bc0f50d17a28e1132fd498b1 (diff) | |
parent | eaa590a3216ed7bf971c67a43ae68ed6e3ad1ce1 (diff) |
Merge changes I9fccc14f,I0bb64c9a into pi-dev
* changes:
Add more Wifi Wake log statements
Add metrics for Wifi Wake
Diffstat (limited to 'service')
6 files changed, 375 insertions, 16 deletions
diff --git a/service/java/com/android/server/wifi/WakeupConfigStoreData.java b/service/java/com/android/server/wifi/WakeupConfigStoreData.java index ae4cd808b..b936a4c6c 100644 --- a/service/java/com/android/server/wifi/WakeupConfigStoreData.java +++ b/service/java/com/android/server/wifi/WakeupConfigStoreData.java @@ -17,6 +17,7 @@ package com.android.server.wifi; import android.util.ArraySet; +import android.util.Log; import com.android.server.wifi.WifiConfigStore.StoreData; import com.android.server.wifi.util.XmlUtil; @@ -141,7 +142,10 @@ public class WakeupConfigStoreData implements StoreData { public void deserializeData(XmlPullParser in, int outerTagDepth, boolean shared) throws XmlPullParserException, IOException { if (!shared) { - mHasBeenRead = true; + if (!mHasBeenRead) { + Log.d(TAG, "WifiWake user data has been read"); + mHasBeenRead = true; + } } // Ignore empty reads. diff --git a/service/java/com/android/server/wifi/WakeupController.java b/service/java/com/android/server/wifi/WakeupController.java index 4adee42c5..9743390ed 100644 --- a/service/java/com/android/server/wifi/WakeupController.java +++ b/service/java/com/android/server/wifi/WakeupController.java @@ -61,6 +61,7 @@ public class WakeupController { private final WifiConfigManager mWifiConfigManager; private final WifiInjector mWifiInjector; private final WakeupConfigStoreData mWakeupConfigStoreData; + private final WifiWakeMetrics mWifiWakeMetrics; private final WifiScanner.ScanListener mScanListener = new WifiScanner.ScanListener() { @Override @@ -97,6 +98,12 @@ public class WakeupController { /** Whether the WakeupController is currently active. */ private boolean mIsActive = false; + /** The number of scans that have been handled by the controller since last {@link #reset()}. */ + private int mNumScansHandled = 0; + + /** Whether Wifi verbose logging is enabled. */ + private boolean mVerboseLoggingEnabled; + public WakeupController( Context context, Looper looper, @@ -105,6 +112,7 @@ public class WakeupController { WakeupOnboarding wakeupOnboarding, WifiConfigManager wifiConfigManager, WifiConfigStore wifiConfigStore, + WifiWakeMetrics wifiWakeMetrics, WifiInjector wifiInjector, FrameworkFacade frameworkFacade) { mContext = context; @@ -113,6 +121,7 @@ public class WakeupController { mWakeupEvaluator = wakeupEvaluator; mWakeupOnboarding = wakeupOnboarding; mWifiConfigManager = wifiConfigManager; + mWifiWakeMetrics = wifiWakeMetrics; mFrameworkFacade = frameworkFacade; mWifiInjector = wifiInjector; mContentObserver = new ContentObserver(mHandler) { @@ -120,6 +129,7 @@ public class WakeupController { public void onChange(boolean selfChange) { mWifiWakeupEnabled = mFrameworkFacade.getIntegerSetting( mContext, Settings.Global.WIFI_WAKEUP_ENABLED, 0) == 1; + Log.d(TAG, "WifiWake " + (mWifiWakeupEnabled ? "enabled" : "disabled")); } }; mFrameworkFacade.registerContentObserver(mContext, Settings.Global.getUriFor( @@ -156,6 +166,7 @@ public class WakeupController { // If already active, we don't want to re-initialize the lock, so return early. if (mIsActive) { + // TODO record metric for calls to start() when already active return; } setActive(true); @@ -163,7 +174,15 @@ public class WakeupController { // ensure feature is enabled and store data has been read before performing work if (isEnabled()) { mWakeupOnboarding.maybeShowNotification(); - mWakeupLock.initialize(getMostRecentSavedScanResults()); + + Set<ScanResultMatchInfo> mostRecentSavedScanResults = getMostRecentSavedScanResults(); + + if (mVerboseLoggingEnabled) { + Log.d(TAG, "Saved networks in most recent scan:" + mostRecentSavedScanResults); + } + + mWifiWakeMetrics.recordStartEvent(mostRecentSavedScanResults.size()); + mWakeupLock.initialize(mostRecentSavedScanResults); } } @@ -182,9 +201,17 @@ public class WakeupController { /** Resets the WakeupController, setting {@link #mIsActive} to false. */ public void reset() { Log.d(TAG, "reset()"); + mWifiWakeMetrics.recordResetEvent(mNumScansHandled); + mNumScansHandled = 0; setActive(false); } + /** Sets verbose logging flag based on verbose level. */ + public void enableVerboseLogging(int verbose) { + mVerboseLoggingEnabled = verbose > 0; + mWakeupLock.enableVerboseLogging(mVerboseLoggingEnabled); + } + /** Returns a list of saved networks from the last full scan. */ private Set<ScanResultMatchInfo> getMostRecentSavedScanResults() { Set<ScanResultMatchInfo> goodSavedNetworks = getGoodSavedNetworks(); @@ -214,7 +241,6 @@ public class WakeupController { goodSavedNetworks.add(ScanResultMatchInfo.fromWifiConfiguration(config)); } - Log.d(TAG, "getGoodSavedNetworks: " + goodSavedNetworks.size()); return goodSavedNetworks; } @@ -237,9 +263,18 @@ public class WakeupController { */ private void handleScanResults(Collection<ScanResult> scanResults) { if (!isEnabled()) { + Log.d(TAG, "Attempted to handleScanResults while not enabled"); return; } + // only count scan as handled if isEnabled + mNumScansHandled++; + + if (mVerboseLoggingEnabled) { + Log.d(TAG, "Incoming scan. Total scans handled: " + mNumScansHandled); + Log.d(TAG, "ScanResults: " + scanResults); + } + // need to show notification here in case user enables Wifi Wake when Wifi is off mWakeupOnboarding.maybeShowNotification(); if (!mWakeupOnboarding.isOnboarded()) { @@ -248,6 +283,10 @@ public class WakeupController { // only update the wakeup lock if it's not already empty if (!mWakeupLock.isEmpty()) { + if (mVerboseLoggingEnabled) { + Log.d(TAG, "WakeupLock not empty. Updating."); + } + Set<ScanResultMatchInfo> networks = new ArraySet<>(); for (ScanResult scanResult : scanResults) { networks.add(ScanResultMatchInfo.fromScanResult(scanResult)); @@ -260,20 +299,14 @@ public class WakeupController { } Log.d(TAG, "WakeupLock emptied"); + mWifiWakeMetrics.recordUnlockEvent(mNumScansHandled); } ScanResult network = mWakeupEvaluator.findViableNetwork(scanResults, getGoodSavedNetworks()); if (network != null) { - Log.d(TAG, "Found viable network: " + network.SSID); - onNetworkFound(network); - } - } - - private void onNetworkFound(ScanResult scanResult) { - if (isEnabled() && mIsActive && USE_PLATFORM_WIFI_WAKE) { - Log.d(TAG, "Enabling wifi for network: " + scanResult.SSID); + Log.d(TAG, "Enabling wifi for network: " + network.SSID); enableWifi(); } } @@ -285,9 +318,12 @@ public class WakeupController { * in ScanModeState. */ private void enableWifi() { - // TODO(b/72180295): ensure that there is no race condition with WifiServiceImpl here - if (mWifiInjector.getWifiSettingsStore().handleWifiToggled(true /* wifiEnabled */)) { - mWifiInjector.getWifiController().sendMessage(CMD_WIFI_TOGGLED); + if (USE_PLATFORM_WIFI_WAKE) { + // TODO(b/72180295): ensure that there is no race condition with WifiServiceImpl here + if (mWifiInjector.getWifiSettingsStore().handleWifiToggled(true /* wifiEnabled */)) { + mWifiInjector.getWifiController().sendMessage(CMD_WIFI_TOGGLED); + mWifiWakeMetrics.recordWakeupEvent(mNumScansHandled); + } } } @@ -305,9 +341,13 @@ public class WakeupController { /** Dumps wakeup controller state. */ public void dump(FileDescriptor fd, PrintWriter pw, String[] args) { pw.println("Dump of WakeupController"); - pw.println("mWifiWakeupEnabled: " + mWifiWakeupEnabled); pw.println("USE_PLATFORM_WIFI_WAKE: " + USE_PLATFORM_WIFI_WAKE); + pw.println("mWifiWakeupEnabled: " + mWifiWakeupEnabled); + pw.println("isOnboarded: " + mWakeupOnboarding.isOnboarded()); + pw.println("configStore hasBeenRead: " + mWakeupConfigStoreData.hasBeenRead()); pw.println("mIsActive: " + mIsActive); + pw.println("mNumScansHandled: " + mNumScansHandled); + mWakeupLock.dump(fd, pw, args); } diff --git a/service/java/com/android/server/wifi/WakeupLock.java b/service/java/com/android/server/wifi/WakeupLock.java index 1fcd9f836..9e617a498 100644 --- a/service/java/com/android/server/wifi/WakeupLock.java +++ b/service/java/com/android/server/wifi/WakeupLock.java @@ -43,6 +43,7 @@ public class WakeupLock { private final WifiConfigManager mWifiConfigManager; private final Map<ScanResultMatchInfo, Integer> mLockedNetworks = new ArrayMap<>(); + private boolean mVerboseLoggingEnabled; public WakeupLock(WifiConfigManager wifiConfigManager) { mWifiConfigManager = wifiConfigManager; @@ -84,6 +85,9 @@ public class WakeupLock { // if present in scan list, reset to max if (scanResultList.contains(entry.getKey())) { + if (mVerboseLoggingEnabled) { + Log.d(TAG, "Found network in lock: " + entry.getKey().networkSsid); + } entry.setValue(CONSECUTIVE_MISSED_SCANS_REQUIRED_TO_EVICT); continue; } @@ -91,6 +95,7 @@ public class WakeupLock { // decrement and remove if necessary entry.setValue(entry.getValue() - 1); if (entry.getValue() <= 0) { + Log.d(TAG, "Removed network from lock: " + entry.getKey().networkSsid); it.remove(); hasChanged = true; } @@ -122,6 +127,11 @@ public class WakeupLock { } } + /** Set whether verbose logging is enabled. */ + public void enableVerboseLogging(boolean enabled) { + mVerboseLoggingEnabled = enabled; + } + private class WakeupLockDataSource implements WakeupConfigStoreData.DataSource<Set<ScanResultMatchInfo>> { diff --git a/service/java/com/android/server/wifi/WifiInjector.java b/service/java/com/android/server/wifi/WifiInjector.java index 2e0591978..4313ff4cf 100644 --- a/service/java/com/android/server/wifi/WifiInjector.java +++ b/service/java/com/android/server/wifi/WifiInjector.java @@ -274,7 +274,7 @@ public class WifiInjector { mWakeupController = new WakeupController(mContext, mWifiStateMachineHandlerThread.getLooper(), new WakeupLock(mWifiConfigManager), WakeupEvaluator.fromContext(mContext), wakeupOnboarding, mWifiConfigManager, - mWifiConfigStore, this, mFrameworkFacade); + mWifiConfigStore, mWifiMetrics.getWakeupMetrics(), this, mFrameworkFacade); mLockManager = new WifiLockManager(mContext, BatteryStatsService.getService()); mWifiController = new WifiController(mContext, mWifiStateMachine, wifiStateMachineLooper, mSettingsStore, mWifiServiceHandlerThread.getLooper(), mFrameworkFacade, @@ -310,6 +310,7 @@ public class WifiInjector { mWifiBackupRestore.enableVerboseLogging(verbose); mHalDeviceManager.enableVerboseLogging(verbose); mScanRequestProxy.enableVerboseLogging(verbose); + mWakeupController.enableVerboseLogging(verbose); LogcatLog.enableVerboseLogging(verbose); } diff --git a/service/java/com/android/server/wifi/WifiMetrics.java b/service/java/com/android/server/wifi/WifiMetrics.java index af8b50595..d39eb4e59 100644 --- a/service/java/com/android/server/wifi/WifiMetrics.java +++ b/service/java/com/android/server/wifi/WifiMetrics.java @@ -190,6 +190,9 @@ public class WifiMetrics { /** Wifi power metrics*/ private WifiPowerMetrics mWifiPowerMetrics = new WifiPowerMetrics(); + /** Wifi Wake metrics */ + private final WifiWakeMetrics mWifiWakeMetrics = new WifiWakeMetrics(); + class RouterFingerPrint { private WifiMetricsProto.RouterFingerPrint mRouterFingerPrintProto; RouterFingerPrint() { @@ -1910,6 +1913,7 @@ public class WifiMetrics { + mWpsMetrics.numWpsCancellation); mWifiPowerMetrics.dump(pw); + mWifiWakeMetrics.dump(pw); } } } @@ -2196,6 +2200,7 @@ public class WifiMetrics { mWifiLogProto.wpsMetrics = mWpsMetrics; mWifiLogProto.wifiPowerStats = mWifiPowerMetrics.buildProto(); + mWifiLogProto.wifiWakeStats = mWifiWakeMetrics.buildProto(); } } @@ -2259,6 +2264,7 @@ public class WifiMetrics { mSoftApEventListTethered.clear(); mSoftApEventListLocalOnly.clear(); mWpsMetrics.clear(); + mWifiWakeMetrics.clear(); } } @@ -2443,6 +2449,10 @@ public class WifiMetrics { return mWifiAwareMetrics; } + public WifiWakeMetrics getWakeupMetrics() { + return mWifiWakeMetrics; + } + // Rather than generate a StaEvent for each SUPPLICANT_STATE_CHANGE, cache these in a bitmask // and attach it to the next event which is generated. private int mSupplicantStateChangeBitmask = 0; diff --git a/service/java/com/android/server/wifi/WifiWakeMetrics.java b/service/java/com/android/server/wifi/WifiWakeMetrics.java new file mode 100644 index 000000000..fba72369f --- /dev/null +++ b/service/java/com/android/server/wifi/WifiWakeMetrics.java @@ -0,0 +1,294 @@ +/* + * Copyright (C) 2018 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.android.server.wifi; + +import android.annotation.Nullable; +import android.os.SystemClock; + +import com.android.internal.annotations.GuardedBy; +import com.android.internal.annotations.VisibleForTesting; +import com.android.server.wifi.nano.WifiMetricsProto.WifiWakeStats; + +import java.io.PrintWriter; +import java.util.ArrayList; +import java.util.List; + +/** + * Holds WifiWake metrics and converts them to a protobuf included in WifiLog. + */ +public class WifiWakeMetrics { + + /** Maximum number of sessions to store in WifiWakeStats proto. */ + @VisibleForTesting + static final int MAX_RECORDED_SESSIONS = 10; + + @GuardedBy("mLock") + private final List<Session> mSessions = new ArrayList<>(); + @GuardedBy("mLock") + private Session mCurrentSession; + + private boolean mIsInSession = false; + private int mTotalSessions = 0; + + private final Object mLock = new Object(); + + /** + * Records the beginning of a Wifi Wake session. + * + * <p>Starts the session. + * + * @param numNetworks The total number of networks stored in the WakeupLock at initialization. + */ + public void recordStartEvent(int numNetworks) { + synchronized (mLock) { + mCurrentSession = new Session(numNetworks, SystemClock.elapsedRealtime()); + mIsInSession = true; + } + } + + /** + * Records the unlock event of the current Wifi Wake session. + * + * <p>The unlock event occurs when the WakeupLock has all of its networks removed. This event + * will not be recorded if the start event recorded 0 locked networks. + * + * <p>Note: The start event must be recorded before this event, otherwise this call will be + * ignored. + * + * @param numScans The total number of elapsed scans since start. + */ + public void recordUnlockEvent(int numScans) { + synchronized (mLock) { + if (!mIsInSession) { + return; + } + mCurrentSession.recordUnlockEvent(numScans, SystemClock.elapsedRealtime()); + } + } + + /** + * Records the wakeup event of the current Wifi Wake session. + * + * <p>The wakeup event occurs when Wifi is re-enabled by the WakeupController. + * + * <p>Note: The start event must be recorded before this event, otherwise this call will be + * ignored. + * + * @param numScans The total number of elapsed scans since start. + */ + public void recordWakeupEvent(int numScans) { + synchronized (mLock) { + if (!mIsInSession) { + return; + } + mCurrentSession.recordWakeupEvent(numScans, SystemClock.elapsedRealtime()); + } + } + + /** + * Records the reset event of the current Wifi Wake session. + * + * <p>The reset event occurs when Wifi enters client mode. Stores the first + * {@link #MAX_RECORDED_SESSIONS} in the session list. + * + * <p>Note: The start event must be recorded before this event, otherwise this call will be + * ignored. This event ends the current session. + * + * @param numScans The total number of elapsed scans since start. + */ + public void recordResetEvent(int numScans) { + synchronized (mLock) { + if (!mIsInSession) { + return; + } + mCurrentSession.recordResetEvent(numScans, SystemClock.elapsedRealtime()); + + mTotalSessions++; + if (mSessions.size() < MAX_RECORDED_SESSIONS) { + mSessions.add(mCurrentSession); + } + mIsInSession = false; + } + } + + /** + * Returns the consolidated WifiWakeStats proto for WifiMetrics. + */ + public WifiWakeStats buildProto() { + WifiWakeStats proto = new WifiWakeStats(); + + proto.numSessions = mTotalSessions; + proto.sessions = new WifiWakeStats.Session[mSessions.size()]; + + for (int i = 0; i < mSessions.size(); i++) { + proto.sessions[i] = mSessions.get(i).buildProto(); + } + + return proto; + } + + /** + * Dump all WifiWake stats to console (pw) + * @param pw + */ + public void dump(PrintWriter pw) { + synchronized (mLock) { + pw.println("-------WifiWake metrics-------"); + pw.println("mTotalSessions: " + mTotalSessions); + pw.println("mIsInSession: " + mIsInSession); + pw.println("Stored Sessions: " + mSessions.size()); + for (Session session : mSessions) { + session.dump(pw); + } + if (mCurrentSession != null) { + pw.println("Current Session: "); + mCurrentSession.dump(pw); + } + pw.println("----end of WifiWake metrics----"); + } + } + + /** + * Clears WifiWakeMetrics. + * + * <p>Keeps the current WifiWake session. + */ + public void clear() { + mSessions.clear(); + mTotalSessions = 0; + } + + /** A single WifiWake session. */ + public static class Session { + + private final long mStartTimestamp; + private final int mNumNetworks; + + @VisibleForTesting + @Nullable + Event mUnlockEvent; + @VisibleForTesting + @Nullable + Event mWakeupEvent; + @VisibleForTesting + @Nullable + Event mResetEvent; + + /** Creates a new WifiWake session. */ + public Session(int numNetworks, long timestamp) { + mNumNetworks = numNetworks; + mStartTimestamp = timestamp; + } + + /** + * Records an unlock event. + * + * <p>Ignores subsequent calls. + * + * @param numScans Total number of scans at the time of this event. + * @param timestamp The timestamp of the event. + */ + public void recordUnlockEvent(int numScans, long timestamp) { + if (mUnlockEvent == null) { + mUnlockEvent = new Event(numScans, timestamp - mStartTimestamp); + } + } + + /** + * Records a wakeup event. + * + * <p>Ignores subsequent calls. + * + * @param numScans Total number of scans at the time of this event. + * @param timestamp The timestamp of the event. + */ + public void recordWakeupEvent(int numScans, long timestamp) { + if (mWakeupEvent == null) { + mWakeupEvent = new Event(numScans, timestamp - mStartTimestamp); + } + } + + /** + * Records a reset event. + * + * <p>Ignores subsequent calls. + * + * @param numScans Total number of scans at the time of this event. + * @param timestamp The timestamp of the event. + */ + public void recordResetEvent(int numScans, long timestamp) { + if (mResetEvent == null) { + mResetEvent = new Event(numScans, timestamp - mStartTimestamp); + } + } + + /** Returns the proto representation of this session. */ + public WifiWakeStats.Session buildProto() { + WifiWakeStats.Session sessionProto = new WifiWakeStats.Session(); + sessionProto.startTimeMillis = mStartTimestamp; + sessionProto.lockedNetworksAtStart = mNumNetworks; + + if (mUnlockEvent != null) { + sessionProto.unlockEvent = mUnlockEvent.buildProto(); + } + if (mWakeupEvent != null) { + sessionProto.wakeupEvent = mWakeupEvent.buildProto(); + } + if (mResetEvent != null) { + sessionProto.resetEvent = mResetEvent.buildProto(); + } + + return sessionProto; + } + + /** Dumps the current state of the session. */ + public void dump(PrintWriter pw) { + pw.println("WifiWakeMetrics.Session:"); + pw.println("mStartTimestamp: " + mStartTimestamp); + pw.println("mNumNetworks: " + mNumNetworks); + pw.println("mUnlockEvent: " + (mUnlockEvent == null ? "{}" : mUnlockEvent.toString())); + pw.println("mWakeupEvent: " + (mWakeupEvent == null ? "{}" : mWakeupEvent.toString())); + pw.println("mResetEvent: " + (mResetEvent == null ? "{}" : mResetEvent.toString())); + } + } + + /** An event in a WifiWake session. */ + public static class Event { + + /** Total number of scans that have elapsed prior to this event. */ + public final int mNumScans; + /** Total elapsed time in milliseconds at the instant of this event. */ + public final long mElapsedTime; + + public Event(int numScans, long elapsedTime) { + mNumScans = numScans; + mElapsedTime = elapsedTime; + } + + /** Returns the proto representation of this event. */ + public WifiWakeStats.Session.Event buildProto() { + WifiWakeStats.Session.Event eventProto = new WifiWakeStats.Session.Event(); + eventProto.elapsedScans = mNumScans; + eventProto.elapsedTimeMillis = mElapsedTime; + return eventProto; + } + + @Override + public String toString() { + return "{ mNumScans: " + mNumScans + ", elapsedTime: " + mElapsedTime + " }"; + } + } +} |