Home | History | Annotate | Download | only in am 
      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.CompletableFuture;
     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 
    119     public synchronized Future<?> scheduleWrite() {
    120         if (mExecutorService.isShutdown()) {
    121             return CompletableFuture.failedFuture(new IllegalStateException("worker shutdown"));
    122         }
    123 
    124         scheduleSyncLocked("write", UPDATE_ALL);
    125         // Since we use a single threaded executor, we can assume the next scheduled task's
    126         // Future finishes after the sync.
    127         return mExecutorService.submit(mWriteTask);
    128     }
    129 
    130     /**
    131      * Schedules a task to run on the BatteryExternalStatsWorker thread. If scheduling more work
    132      * within the task, never wait on the resulting Future. This will result in a deadlock.
    133      */
    134     public synchronized void scheduleRunnable(Runnable runnable) {
    135         if (!mExecutorService.isShutdown()) {
    136             mExecutorService.submit(runnable);
    137         }
    138     }
    139 
    140     public void shutdown() {
    141         mExecutorService.shutdownNow();
    142     }
    143 
    144     private Future<?> scheduleSyncLocked(String reason, int flags) {
    145         if (mExecutorService.isShutdown()) {
    146             return CompletableFuture.failedFuture(new IllegalStateException("worker shutdown"));
    147         }
    148 
    149         if (mCurrentFuture == null) {
    150             mUpdateFlags = flags;
    151             mCurrentReason = reason;
    152             mCurrentFuture = mExecutorService.submit(mSyncTask);
    153         }
    154         mUpdateFlags |= flags;
    155         return mCurrentFuture;
    156     }
    157 
    158     private final Runnable mSyncTask = new Runnable() {
    159         @Override
    160         public void run() {
    161             // Capture a snapshot of the state we are meant to process.
    162             final int updateFlags;
    163             final String reason;
    164             final int[] uidsToRemove;
    165             synchronized (BatteryExternalStatsWorker.this) {
    166                 updateFlags = mUpdateFlags;
    167                 reason = mCurrentReason;
    168                 uidsToRemove = mUidsToRemove.size() > 0 ? mUidsToRemove.toArray() : EmptyArray.INT;
    169                 mUpdateFlags = 0;
    170                 mCurrentReason = null;
    171                 mUidsToRemove.clear();
    172                 mCurrentFuture = null;
    173             }
    174 
    175             synchronized (mWorkerLock) {
    176                 if (DEBUG) {
    177                     Slog.d(TAG, "begin updateExternalStatsSync reason=" + reason);
    178                 }
    179                 try {
    180                     updateExternalStatsLocked(reason, updateFlags);
    181                 } finally {
    182                     if (DEBUG) {
    183                         Slog.d(TAG, "end updateExternalStatsSync");
    184                     }
    185                 }
    186             }
    187 
    188             // Clean up any UIDs if necessary.
    189             synchronized (mStats) {
    190                 for (int uid : uidsToRemove) {
    191                     mStats.removeIsolatedUidLocked(uid);
    192                 }
    193             }
    194         }
    195     };
    196 
    197     private final Runnable mWriteTask = new Runnable() {
    198         @Override
    199         public void run() {
    200             synchronized (mStats) {
    201                 mStats.writeAsyncLocked();
    202             }
    203         }
    204     };
    205 
    206     private void updateExternalStatsLocked(final String reason, int updateFlags) {
    207         // We will request data from external processes asynchronously, and wait on a timeout.
    208         SynchronousResultReceiver wifiReceiver = null;
    209         SynchronousResultReceiver bluetoothReceiver = null;
    210         SynchronousResultReceiver modemReceiver = null;
    211 
    212         if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_WIFI) != 0) {
    213             // We were asked to fetch WiFi data.
    214             if (mWifiManager == null) {
    215                 mWifiManager = IWifiManager.Stub.asInterface(ServiceManager.getService(
    216                         Context.WIFI_SERVICE));
    217             }
    218 
    219             if (mWifiManager != null) {
    220                 try {
    221                     wifiReceiver = new SynchronousResultReceiver("wifi");
    222                     mWifiManager.requestActivityInfo(wifiReceiver);
    223                 } catch (RemoteException e) {
    224                     // Oh well.
    225                 }
    226             }
    227         }
    228 
    229         if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_BT) != 0) {
    230             // We were asked to fetch Bluetooth data.
    231             final BluetoothAdapter adapter = BluetoothAdapter.getDefaultAdapter();
    232             if (adapter != null) {
    233                 bluetoothReceiver = new SynchronousResultReceiver("bluetooth");
    234                 adapter.requestControllerActivityEnergyInfo(bluetoothReceiver);
    235             }
    236         }
    237 
    238         if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_RADIO) != 0) {
    239             // We were asked to fetch Telephony data.
    240             if (mTelephony == null) {
    241                 mTelephony = TelephonyManager.from(mContext);
    242             }
    243 
    244             if (mTelephony != null) {
    245                 modemReceiver = new SynchronousResultReceiver("telephony");
    246                 mTelephony.requestModemActivityInfo(modemReceiver);
    247             }
    248         }
    249 
    250         final WifiActivityEnergyInfo wifiInfo = awaitControllerInfo(wifiReceiver);
    251         final BluetoothActivityEnergyInfo bluetoothInfo = awaitControllerInfo(bluetoothReceiver);
    252         final ModemActivityInfo modemInfo = awaitControllerInfo(modemReceiver);
    253 
    254         synchronized (mStats) {
    255             mStats.addHistoryEventLocked(
    256                     SystemClock.elapsedRealtime(),
    257                     SystemClock.uptimeMillis(),
    258                     BatteryStats.HistoryItem.EVENT_COLLECT_EXTERNAL_STATS,
    259                     reason, 0);
    260 
    261             if ((updateFlags & UPDATE_CPU) != 0) {
    262                 mStats.updateCpuTimeLocked(true /* updateCpuFreqData */);
    263                 mStats.updateKernelWakelocksLocked();
    264                 mStats.updateKernelMemoryBandwidthLocked();
    265             }
    266 
    267             if ((updateFlags & UPDATE_RPM) != 0) {
    268                 mStats.updateRpmStatsLocked();
    269             }
    270 
    271             if (bluetoothInfo != null) {
    272                 if (bluetoothInfo.isValid()) {
    273                     mStats.updateBluetoothStateLocked(bluetoothInfo);
    274                 } else {
    275                     Slog.e(TAG, "bluetooth info is invalid: " + bluetoothInfo);
    276                 }
    277             }
    278         }
    279 
    280         // WiFi and Modem state are updated without the mStats lock held, because they
    281         // do some network stats retrieval before internally grabbing the mStats lock.
    282 
    283         if (wifiInfo != null) {
    284             if (wifiInfo.isValid()) {
    285                 mStats.updateWifiState(extractDeltaLocked(wifiInfo));
    286             } else {
    287                 Slog.e(TAG, "wifi info is invalid: " + wifiInfo);
    288             }
    289         }
    290 
    291         if (modemInfo != null) {
    292             if (modemInfo.isValid()) {
    293                 mStats.updateMobileRadioState(modemInfo);
    294             } else {
    295                 Slog.e(TAG, "modem info is invalid: " + modemInfo);
    296             }
    297         }
    298     }
    299 
    300     /**
    301      * Helper method to extract the Parcelable controller info from a
    302      * SynchronousResultReceiver.
    303      */
    304     private static <T extends Parcelable> T awaitControllerInfo(
    305             @Nullable SynchronousResultReceiver receiver) {
    306         if (receiver == null) {
    307             return null;
    308         }
    309 
    310         try {
    311             final SynchronousResultReceiver.Result result =
    312                     receiver.awaitResult(EXTERNAL_STATS_SYNC_TIMEOUT_MILLIS);
    313             if (result.bundle != null) {
    314                 // This is the final destination for the Bundle.
    315                 result.bundle.setDefusable(true);
    316 
    317                 final T data = result.bundle.getParcelable(
    318                         BatteryStats.RESULT_RECEIVER_CONTROLLER_KEY);
    319                 if (data != null) {
    320                     return data;
    321                 }
    322             }
    323             Slog.e(TAG, "no controller energy info supplied for " + receiver.getName());
    324         } catch (TimeoutException e) {
    325             Slog.w(TAG, "timeout reading " + receiver.getName() + " stats");
    326         }
    327         return null;
    328     }
    329 
    330     private WifiActivityEnergyInfo extractDeltaLocked(WifiActivityEnergyInfo latest) {
    331         final long timePeriodMs = latest.mTimestamp - mLastInfo.mTimestamp;
    332         final long lastIdleMs = mLastInfo.mControllerIdleTimeMs;
    333         final long lastTxMs = mLastInfo.mControllerTxTimeMs;
    334         final long lastRxMs = mLastInfo.mControllerRxTimeMs;
    335         final long lastEnergy = mLastInfo.mControllerEnergyUsed;
    336 
    337         // We will modify the last info object to be the delta, and store the new
    338         // WifiActivityEnergyInfo object as our last one.
    339         final WifiActivityEnergyInfo delta = mLastInfo;
    340         delta.mTimestamp = latest.getTimeStamp();
    341         delta.mStackState = latest.getStackState();
    342 
    343         final long txTimeMs = latest.mControllerTxTimeMs - lastTxMs;
    344         final long rxTimeMs = latest.mControllerRxTimeMs - lastRxMs;
    345         final long idleTimeMs = latest.mControllerIdleTimeMs - lastIdleMs;
    346 
    347         if (txTimeMs < 0 || rxTimeMs < 0) {
    348             // The stats were reset by the WiFi system (which is why our delta is negative).
    349             // Returns the unaltered stats.
    350             delta.mControllerEnergyUsed = latest.mControllerEnergyUsed;
    351             delta.mControllerRxTimeMs = latest.mControllerRxTimeMs;
    352             delta.mControllerTxTimeMs = latest.mControllerTxTimeMs;
    353             delta.mControllerIdleTimeMs = latest.mControllerIdleTimeMs;
    354             Slog.v(TAG, "WiFi energy data was reset, new WiFi energy data is " + delta);
    355         } else {
    356             final long totalActiveTimeMs = txTimeMs + rxTimeMs;
    357             long maxExpectedIdleTimeMs;
    358             if (totalActiveTimeMs > timePeriodMs) {
    359                 // Cap the max idle time at zero since the active time consumed the whole time
    360                 maxExpectedIdleTimeMs = 0;
    361                 if (totalActiveTimeMs > timePeriodMs + MAX_WIFI_STATS_SAMPLE_ERROR_MILLIS) {
    362                     StringBuilder sb = new StringBuilder();
    363                     sb.append("Total Active time ");
    364                     TimeUtils.formatDuration(totalActiveTimeMs, sb);
    365                     sb.append(" is longer than sample period ");
    366                     TimeUtils.formatDuration(timePeriodMs, sb);
    367                     sb.append(".\n");
    368                     sb.append("Previous WiFi snapshot: ").append("idle=");
    369                     TimeUtils.formatDuration(lastIdleMs, sb);
    370                     sb.append(" rx=");
    371                     TimeUtils.formatDuration(lastRxMs, sb);
    372                     sb.append(" tx=");
    373                     TimeUtils.formatDuration(lastTxMs, sb);
    374                     sb.append(" e=").append(lastEnergy);
    375                     sb.append("\n");
    376                     sb.append("Current WiFi snapshot: ").append("idle=");
    377                     TimeUtils.formatDuration(latest.mControllerIdleTimeMs, sb);
    378                     sb.append(" rx=");
    379                     TimeUtils.formatDuration(latest.mControllerRxTimeMs, sb);
    380                     sb.append(" tx=");
    381                     TimeUtils.formatDuration(latest.mControllerTxTimeMs, sb);
    382                     sb.append(" e=").append(latest.mControllerEnergyUsed);
    383                     Slog.wtf(TAG, sb.toString());
    384                 }
    385             } else {
    386                 maxExpectedIdleTimeMs = timePeriodMs - totalActiveTimeMs;
    387             }
    388             // These times seem to be the most reliable.
    389             delta.mControllerTxTimeMs = txTimeMs;
    390             delta.mControllerRxTimeMs = rxTimeMs;
    391             // WiFi calculates the idle time as a difference from the on time and the various
    392             // Rx + Tx times. There seems to be some missing time there because this sometimes
    393             // becomes negative. Just cap it at 0 and ensure that it is less than the expected idle
    394             // time from the difference in timestamps.
    395             // b/21613534
    396             delta.mControllerIdleTimeMs = Math.min(maxExpectedIdleTimeMs, Math.max(0, idleTimeMs));
    397             delta.mControllerEnergyUsed = Math.max(0, latest.mControllerEnergyUsed - lastEnergy);
    398         }
    399 
    400         mLastInfo = latest;
    401         return delta;
    402     }
    403 }
    404