Adam Lesinski | b3a1bad | 2017-05-26 11:50:40 -0700 | [diff] [blame] | 1 | /* |
| 2 | * Copyright (C) 2017 The Android Open Source Project |
| 3 | * |
| 4 | * Licensed under the Apache License, Version 2.0 (the "License"); you may not |
| 5 | * use this file except in compliance with the License. You may obtain a copy |
| 6 | * of the License at |
| 7 | * |
| 8 | * http://www.apache.org/licenses/LICENSE-2.0 |
| 9 | * |
| 10 | * Unless required by applicable law or agreed to in writing, software |
| 11 | * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT |
| 12 | * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the |
| 13 | * License for the specific language governing permissions and limitations |
| 14 | * under the License. |
| 15 | */ |
| 16 | package com.android.server.am; |
| 17 | |
| 18 | import android.annotation.Nullable; |
| 19 | import android.bluetooth.BluetoothActivityEnergyInfo; |
| 20 | import android.bluetooth.BluetoothAdapter; |
| 21 | import android.content.Context; |
| 22 | import android.net.wifi.IWifiManager; |
| 23 | import android.net.wifi.WifiActivityEnergyInfo; |
| 24 | import android.os.BatteryStats; |
| 25 | import android.os.Parcelable; |
| 26 | import android.os.RemoteException; |
| 27 | import android.os.ServiceManager; |
| 28 | import android.os.SynchronousResultReceiver; |
| 29 | import android.os.SystemClock; |
| 30 | import android.telephony.ModemActivityInfo; |
| 31 | import android.telephony.TelephonyManager; |
| 32 | import android.util.IntArray; |
| 33 | import android.util.Slog; |
| 34 | import android.util.TimeUtils; |
| 35 | |
| 36 | import com.android.internal.annotations.GuardedBy; |
| 37 | import com.android.internal.os.BatteryStatsImpl; |
| 38 | |
| 39 | import libcore.util.EmptyArray; |
| 40 | |
| 41 | import java.util.concurrent.ExecutorService; |
| 42 | import java.util.concurrent.Executors; |
| 43 | import java.util.concurrent.Future; |
| 44 | import java.util.concurrent.ThreadFactory; |
| 45 | import java.util.concurrent.TimeoutException; |
| 46 | |
| 47 | /** |
| 48 | * A Worker that fetches data from external sources (WiFi controller, bluetooth chipset) on a |
| 49 | * dedicated thread and updates BatteryStatsImpl with that information. |
| 50 | * |
| 51 | * As much work as possible is done without holding the BatteryStatsImpl lock, and only the |
| 52 | * readily available data is pushed into BatteryStatsImpl with the lock held. |
| 53 | */ |
| 54 | class BatteryExternalStatsWorker implements BatteryStatsImpl.ExternalStatsSync { |
| 55 | private static final String TAG = "BatteryExternalStatsWorker"; |
| 56 | private static final boolean DEBUG = false; |
| 57 | |
| 58 | /** |
| 59 | * How long to wait on an individual subsystem to return its stats. |
| 60 | */ |
| 61 | private static final long EXTERNAL_STATS_SYNC_TIMEOUT_MILLIS = 2000; |
| 62 | |
| 63 | // There is some accuracy error in wifi reports so allow some slop in the results. |
| 64 | private static final long MAX_WIFI_STATS_SAMPLE_ERROR_MILLIS = 750; |
| 65 | |
| 66 | private final ExecutorService mExecutorService = Executors.newSingleThreadExecutor( |
| 67 | (ThreadFactory) r -> { |
| 68 | Thread t = new Thread(r, "batterystats-worker"); |
| 69 | t.setPriority(Thread.NORM_PRIORITY); |
| 70 | return t; |
| 71 | }); |
| 72 | |
| 73 | private final Context mContext; |
| 74 | private final BatteryStatsImpl mStats; |
| 75 | |
| 76 | @GuardedBy("this") |
| 77 | private int mUpdateFlags = 0; |
| 78 | |
| 79 | @GuardedBy("this") |
| 80 | private Future<?> mCurrentFuture = null; |
| 81 | |
| 82 | @GuardedBy("this") |
| 83 | private String mCurrentReason = null; |
| 84 | |
| 85 | @GuardedBy("this") |
| 86 | private final IntArray mUidsToRemove = new IntArray(); |
| 87 | |
| 88 | private final Object mWorkerLock = new Object(); |
| 89 | |
| 90 | @GuardedBy("mWorkerLock") |
| 91 | private IWifiManager mWifiManager = null; |
| 92 | |
| 93 | @GuardedBy("mWorkerLock") |
| 94 | private TelephonyManager mTelephony = null; |
| 95 | |
| 96 | // WiFi keeps an accumulated total of stats, unlike Bluetooth. |
| 97 | // Keep the last WiFi stats so we can compute a delta. |
| 98 | @GuardedBy("mWorkerLock") |
| 99 | private WifiActivityEnergyInfo mLastInfo = |
| 100 | new WifiActivityEnergyInfo(0, 0, 0, new long[]{0}, 0, 0, 0); |
| 101 | |
| 102 | BatteryExternalStatsWorker(Context context, BatteryStatsImpl stats) { |
| 103 | mContext = context; |
| 104 | mStats = stats; |
| 105 | } |
| 106 | |
| 107 | @Override |
| 108 | public synchronized Future<?> scheduleSync(String reason, int flags) { |
| 109 | return scheduleSyncLocked(reason, flags); |
| 110 | } |
| 111 | |
| 112 | @Override |
| 113 | public synchronized Future<?> scheduleCpuSyncDueToRemovedUid(int uid) { |
| 114 | mUidsToRemove.add(uid); |
| 115 | return scheduleSyncLocked("remove-uid", UPDATE_CPU); |
| 116 | } |
| 117 | |
| 118 | public synchronized Future<?> scheduleWrite() { |
| 119 | scheduleSyncLocked("write", UPDATE_ALL); |
| 120 | // Since we use a single threaded executor, we can assume the next scheduled task's |
| 121 | // Future finishes after the sync. |
| 122 | return mExecutorService.submit(mWriteTask); |
| 123 | } |
| 124 | |
| 125 | /** |
| 126 | * Schedules a task to run on the BatteryExternalStatsWorker thread. If scheduling more work |
| 127 | * within the task, never wait on the resulting Future. This will result in a deadlock. |
| 128 | */ |
| 129 | public synchronized void scheduleRunnable(Runnable runnable) { |
| 130 | mExecutorService.submit(runnable); |
| 131 | } |
| 132 | |
| 133 | public void shutdown() { |
| 134 | mExecutorService.shutdownNow(); |
| 135 | } |
| 136 | |
| 137 | private Future<?> scheduleSyncLocked(String reason, int flags) { |
| 138 | if (mCurrentFuture == null) { |
| 139 | mUpdateFlags = flags; |
| 140 | mCurrentReason = reason; |
| 141 | mCurrentFuture = mExecutorService.submit(mSyncTask); |
| 142 | } |
| 143 | mUpdateFlags |= flags; |
| 144 | return mCurrentFuture; |
| 145 | } |
| 146 | |
| 147 | private final Runnable mSyncTask = new Runnable() { |
| 148 | @Override |
| 149 | public void run() { |
| 150 | // Capture a snapshot of the state we are meant to process. |
| 151 | final int updateFlags; |
| 152 | final String reason; |
| 153 | final int[] uidsToRemove; |
| 154 | synchronized (BatteryExternalStatsWorker.this) { |
| 155 | updateFlags = mUpdateFlags; |
| 156 | reason = mCurrentReason; |
| 157 | uidsToRemove = mUidsToRemove.size() > 0 ? mUidsToRemove.toArray() : EmptyArray.INT; |
| 158 | mUpdateFlags = 0; |
| 159 | mCurrentReason = null; |
| 160 | mUidsToRemove.clear(); |
| 161 | mCurrentFuture = null; |
| 162 | } |
| 163 | |
| 164 | synchronized (mWorkerLock) { |
| 165 | if (DEBUG) { |
| 166 | Slog.d(TAG, "begin updateExternalStatsSync reason=" + reason); |
| 167 | } |
| 168 | try { |
| 169 | updateExternalStatsLocked(reason, updateFlags); |
| 170 | } finally { |
| 171 | if (DEBUG) { |
| 172 | Slog.d(TAG, "end updateExternalStatsSync"); |
| 173 | } |
| 174 | } |
| 175 | } |
| 176 | |
| 177 | // Clean up any UIDs if necessary. |
| 178 | synchronized (mStats) { |
| 179 | for (int uid : uidsToRemove) { |
| 180 | mStats.removeIsolatedUidLocked(uid); |
| 181 | } |
| 182 | } |
| 183 | } |
| 184 | }; |
| 185 | |
| 186 | private final Runnable mWriteTask = new Runnable() { |
| 187 | @Override |
| 188 | public void run() { |
| 189 | synchronized (mStats) { |
| 190 | mStats.writeAsyncLocked(); |
| 191 | } |
| 192 | } |
| 193 | }; |
| 194 | |
| 195 | private void updateExternalStatsLocked(final String reason, int updateFlags) { |
| 196 | // We will request data from external processes asynchronously, and wait on a timeout. |
| 197 | SynchronousResultReceiver wifiReceiver = null; |
| 198 | SynchronousResultReceiver bluetoothReceiver = null; |
| 199 | SynchronousResultReceiver modemReceiver = null; |
| 200 | |
| 201 | if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_WIFI) != 0) { |
| 202 | // We were asked to fetch WiFi data. |
| 203 | if (mWifiManager == null) { |
| 204 | mWifiManager = IWifiManager.Stub.asInterface(ServiceManager.getService( |
| 205 | Context.WIFI_SERVICE)); |
| 206 | } |
| 207 | |
| 208 | if (mWifiManager != null) { |
| 209 | try { |
| 210 | wifiReceiver = new SynchronousResultReceiver("wifi"); |
| 211 | mWifiManager.requestActivityInfo(wifiReceiver); |
| 212 | } catch (RemoteException e) { |
| 213 | // Oh well. |
| 214 | } |
| 215 | } |
| 216 | } |
| 217 | |
| 218 | if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_BT) != 0) { |
| 219 | // We were asked to fetch Bluetooth data. |
| 220 | final BluetoothAdapter adapter = BluetoothAdapter.getDefaultAdapter(); |
| 221 | if (adapter != null) { |
| 222 | bluetoothReceiver = new SynchronousResultReceiver("bluetooth"); |
| 223 | adapter.requestControllerActivityEnergyInfo(bluetoothReceiver); |
| 224 | } |
| 225 | } |
| 226 | |
| 227 | if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_RADIO) != 0) { |
| 228 | // We were asked to fetch Telephony data. |
| 229 | if (mTelephony == null) { |
| 230 | mTelephony = TelephonyManager.from(mContext); |
| 231 | } |
| 232 | |
| 233 | if (mTelephony != null) { |
| 234 | modemReceiver = new SynchronousResultReceiver("telephony"); |
| 235 | mTelephony.requestModemActivityInfo(modemReceiver); |
| 236 | } |
| 237 | } |
| 238 | |
| 239 | final WifiActivityEnergyInfo wifiInfo = awaitControllerInfo(wifiReceiver); |
| 240 | final BluetoothActivityEnergyInfo bluetoothInfo = awaitControllerInfo(bluetoothReceiver); |
| 241 | final ModemActivityInfo modemInfo = awaitControllerInfo(modemReceiver); |
| 242 | |
| 243 | synchronized (mStats) { |
| 244 | mStats.addHistoryEventLocked( |
| 245 | SystemClock.elapsedRealtime(), |
| 246 | SystemClock.uptimeMillis(), |
| 247 | BatteryStats.HistoryItem.EVENT_COLLECT_EXTERNAL_STATS, |
| 248 | reason, 0); |
| 249 | |
| 250 | if ((updateFlags & UPDATE_CPU) != 0) { |
Sudheer Shanka | b8ad594 | 2017-08-08 12:16:09 -0700 | [diff] [blame] | 251 | mStats.updateCpuTimeLocked(); |
Adam Lesinski | b3a1bad | 2017-05-26 11:50:40 -0700 | [diff] [blame] | 252 | mStats.updateKernelWakelocksLocked(); |
| 253 | mStats.updateKernelMemoryBandwidthLocked(); |
| 254 | } |
| 255 | |
| 256 | if (bluetoothInfo != null) { |
| 257 | if (bluetoothInfo.isValid()) { |
| 258 | mStats.updateBluetoothStateLocked(bluetoothInfo); |
| 259 | } else { |
| 260 | Slog.e(TAG, "bluetooth info is invalid: " + bluetoothInfo); |
| 261 | } |
| 262 | } |
| 263 | } |
| 264 | |
| 265 | // WiFi and Modem state are updated without the mStats lock held, because they |
| 266 | // do some network stats retrieval before internally grabbing the mStats lock. |
| 267 | |
| 268 | if (wifiInfo != null) { |
| 269 | if (wifiInfo.isValid()) { |
| 270 | mStats.updateWifiState(extractDeltaLocked(wifiInfo)); |
| 271 | } else { |
| 272 | Slog.e(TAG, "wifi info is invalid: " + wifiInfo); |
| 273 | } |
| 274 | } |
| 275 | |
| 276 | if (modemInfo != null) { |
| 277 | if (modemInfo.isValid()) { |
| 278 | mStats.updateMobileRadioState(modemInfo); |
| 279 | } else { |
| 280 | Slog.e(TAG, "modem info is invalid: " + modemInfo); |
| 281 | } |
| 282 | } |
| 283 | } |
| 284 | |
| 285 | /** |
| 286 | * Helper method to extract the Parcelable controller info from a |
| 287 | * SynchronousResultReceiver. |
| 288 | */ |
| 289 | private static <T extends Parcelable> T awaitControllerInfo( |
| 290 | @Nullable SynchronousResultReceiver receiver) { |
| 291 | if (receiver == null) { |
| 292 | return null; |
| 293 | } |
| 294 | |
| 295 | try { |
| 296 | final SynchronousResultReceiver.Result result = |
| 297 | receiver.awaitResult(EXTERNAL_STATS_SYNC_TIMEOUT_MILLIS); |
| 298 | if (result.bundle != null) { |
| 299 | // This is the final destination for the Bundle. |
| 300 | result.bundle.setDefusable(true); |
| 301 | |
| 302 | final T data = result.bundle.getParcelable( |
| 303 | BatteryStats.RESULT_RECEIVER_CONTROLLER_KEY); |
| 304 | if (data != null) { |
| 305 | return data; |
| 306 | } |
| 307 | } |
| 308 | Slog.e(TAG, "no controller energy info supplied for " + receiver.getName()); |
| 309 | } catch (TimeoutException e) { |
| 310 | Slog.w(TAG, "timeout reading " + receiver.getName() + " stats"); |
| 311 | } |
| 312 | return null; |
| 313 | } |
| 314 | |
| 315 | private WifiActivityEnergyInfo extractDeltaLocked(WifiActivityEnergyInfo latest) { |
| 316 | final long timePeriodMs = latest.mTimestamp - mLastInfo.mTimestamp; |
| 317 | final long lastIdleMs = mLastInfo.mControllerIdleTimeMs; |
| 318 | final long lastTxMs = mLastInfo.mControllerTxTimeMs; |
| 319 | final long lastRxMs = mLastInfo.mControllerRxTimeMs; |
| 320 | final long lastEnergy = mLastInfo.mControllerEnergyUsed; |
| 321 | |
| 322 | // We will modify the last info object to be the delta, and store the new |
| 323 | // WifiActivityEnergyInfo object as our last one. |
| 324 | final WifiActivityEnergyInfo delta = mLastInfo; |
| 325 | delta.mTimestamp = latest.getTimeStamp(); |
| 326 | delta.mStackState = latest.getStackState(); |
| 327 | |
| 328 | final long txTimeMs = latest.mControllerTxTimeMs - lastTxMs; |
| 329 | final long rxTimeMs = latest.mControllerRxTimeMs - lastRxMs; |
| 330 | final long idleTimeMs = latest.mControllerIdleTimeMs - lastIdleMs; |
| 331 | |
| 332 | if (txTimeMs < 0 || rxTimeMs < 0) { |
| 333 | // The stats were reset by the WiFi system (which is why our delta is negative). |
| 334 | // Returns the unaltered stats. |
| 335 | delta.mControllerEnergyUsed = latest.mControllerEnergyUsed; |
| 336 | delta.mControllerRxTimeMs = latest.mControllerRxTimeMs; |
| 337 | delta.mControllerTxTimeMs = latest.mControllerTxTimeMs; |
| 338 | delta.mControllerIdleTimeMs = latest.mControllerIdleTimeMs; |
| 339 | Slog.v(TAG, "WiFi energy data was reset, new WiFi energy data is " + delta); |
| 340 | } else { |
| 341 | final long totalActiveTimeMs = txTimeMs + rxTimeMs; |
| 342 | long maxExpectedIdleTimeMs; |
| 343 | if (totalActiveTimeMs > timePeriodMs) { |
| 344 | // Cap the max idle time at zero since the active time consumed the whole time |
| 345 | maxExpectedIdleTimeMs = 0; |
| 346 | if (totalActiveTimeMs > timePeriodMs + MAX_WIFI_STATS_SAMPLE_ERROR_MILLIS) { |
| 347 | StringBuilder sb = new StringBuilder(); |
| 348 | sb.append("Total Active time "); |
| 349 | TimeUtils.formatDuration(totalActiveTimeMs, sb); |
| 350 | sb.append(" is longer than sample period "); |
| 351 | TimeUtils.formatDuration(timePeriodMs, sb); |
| 352 | sb.append(".\n"); |
| 353 | sb.append("Previous WiFi snapshot: ").append("idle="); |
| 354 | TimeUtils.formatDuration(lastIdleMs, sb); |
| 355 | sb.append(" rx="); |
| 356 | TimeUtils.formatDuration(lastRxMs, sb); |
| 357 | sb.append(" tx="); |
| 358 | TimeUtils.formatDuration(lastTxMs, sb); |
| 359 | sb.append(" e=").append(lastEnergy); |
| 360 | sb.append("\n"); |
| 361 | sb.append("Current WiFi snapshot: ").append("idle="); |
| 362 | TimeUtils.formatDuration(latest.mControllerIdleTimeMs, sb); |
| 363 | sb.append(" rx="); |
| 364 | TimeUtils.formatDuration(latest.mControllerRxTimeMs, sb); |
| 365 | sb.append(" tx="); |
| 366 | TimeUtils.formatDuration(latest.mControllerTxTimeMs, sb); |
| 367 | sb.append(" e=").append(latest.mControllerEnergyUsed); |
| 368 | Slog.wtf(TAG, sb.toString()); |
| 369 | } |
| 370 | } else { |
| 371 | maxExpectedIdleTimeMs = timePeriodMs - totalActiveTimeMs; |
| 372 | } |
| 373 | // These times seem to be the most reliable. |
| 374 | delta.mControllerTxTimeMs = txTimeMs; |
| 375 | delta.mControllerRxTimeMs = rxTimeMs; |
| 376 | // WiFi calculates the idle time as a difference from the on time and the various |
| 377 | // Rx + Tx times. There seems to be some missing time there because this sometimes |
| 378 | // becomes negative. Just cap it at 0 and ensure that it is less than the expected idle |
| 379 | // time from the difference in timestamps. |
| 380 | // b/21613534 |
| 381 | delta.mControllerIdleTimeMs = Math.min(maxExpectedIdleTimeMs, Math.max(0, idleTimeMs)); |
| 382 | delta.mControllerEnergyUsed = Math.max(0, latest.mControllerEnergyUsed - lastEnergy); |
| 383 | } |
| 384 | |
| 385 | mLastInfo = latest; |
| 386 | return delta; |
| 387 | } |
| 388 | } |