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