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 import com.android.internal.util.function.pooled.PooledLambda;
39 
40 import libcore.util.EmptyArray;
41 
42 import java.util.concurrent.CompletableFuture;
43 import java.util.concurrent.ExecutorService;
44 import java.util.concurrent.Executors;
45 import java.util.concurrent.Future;
46 import java.util.concurrent.ScheduledExecutorService;
47 import java.util.concurrent.ScheduledFuture;
48 import java.util.concurrent.ThreadFactory;
49 import java.util.concurrent.TimeUnit;
50 import java.util.concurrent.TimeoutException;
51 
52 /**
53  * A Worker that fetches data from external sources (WiFi controller, bluetooth chipset) on a
54  * dedicated thread and updates BatteryStatsImpl with that information.
55  *
56  * As much work as possible is done without holding the BatteryStatsImpl lock, and only the
57  * readily available data is pushed into BatteryStatsImpl with the lock held.
58  */
59 class BatteryExternalStatsWorker implements BatteryStatsImpl.ExternalStatsSync {
60     private static final String TAG = "BatteryExternalStatsWorker";
61     private static final boolean DEBUG = false;
62 
63     /**
64      * How long to wait on an individual subsystem to return its stats.
65      */
66     private static final long EXTERNAL_STATS_SYNC_TIMEOUT_MILLIS = 2000;
67 
68     // There is some accuracy error in wifi reports so allow some slop in the results.
69     private static final long MAX_WIFI_STATS_SAMPLE_ERROR_MILLIS = 750;
70 
71     private final ScheduledExecutorService mExecutorService =
72             Executors.newSingleThreadScheduledExecutor(
73                     (ThreadFactory) r -> {
74                         Thread t = new Thread(r, "batterystats-worker");
75                         t.setPriority(Thread.NORM_PRIORITY);
76                         return t;
77                     });
78 
79     private final Context mContext;
80     private final BatteryStatsImpl mStats;
81 
82     @GuardedBy("this")
83     private int mUpdateFlags = 0;
84 
85     @GuardedBy("this")
86     private Future<?> mCurrentFuture = null;
87 
88     @GuardedBy("this")
89     private String mCurrentReason = null;
90 
91     @GuardedBy("this")
92     private boolean mOnBattery;
93 
94     @GuardedBy("this")
95     private boolean mOnBatteryScreenOff;
96 
97     @GuardedBy("this")
98     private boolean mUseLatestStates = true;
99 
100     @GuardedBy("this")
101     private final IntArray mUidsToRemove = new IntArray();
102 
103     @GuardedBy("this")
104     private Future<?> mWakelockChangesUpdate;
105 
106     @GuardedBy("this")
107     private Future<?> mBatteryLevelSync;
108 
109     private final Object mWorkerLock = new Object();
110 
111     @GuardedBy("mWorkerLock")
112     private IWifiManager mWifiManager = null;
113 
114     @GuardedBy("mWorkerLock")
115     private TelephonyManager mTelephony = null;
116 
117     // WiFi keeps an accumulated total of stats, unlike Bluetooth.
118     // Keep the last WiFi stats so we can compute a delta.
119     @GuardedBy("mWorkerLock")
120     private WifiActivityEnergyInfo mLastInfo =
121             new WifiActivityEnergyInfo(0, 0, 0, new long[]{0}, 0, 0, 0, 0);
122 
123     /**
124      * Timestamp at which all external stats were last collected in
125      * {@link SystemClock#elapsedRealtime()} time base.
126      */
127     @GuardedBy("this")
128     private long mLastCollectionTimeStamp;
129 
BatteryExternalStatsWorker(Context context, BatteryStatsImpl stats)130     BatteryExternalStatsWorker(Context context, BatteryStatsImpl stats) {
131         mContext = context;
132         mStats = stats;
133     }
134 
135     @Override
scheduleSync(String reason, int flags)136     public synchronized Future<?> scheduleSync(String reason, int flags) {
137         return scheduleSyncLocked(reason, flags);
138     }
139 
140     @Override
scheduleCpuSyncDueToRemovedUid(int uid)141     public synchronized Future<?> scheduleCpuSyncDueToRemovedUid(int uid) {
142         mUidsToRemove.add(uid);
143         return scheduleSyncLocked("remove-uid", UPDATE_CPU);
144     }
145 
146     @Override
scheduleCpuSyncDueToSettingChange()147     public synchronized Future<?> scheduleCpuSyncDueToSettingChange() {
148         return scheduleSyncLocked("setting-change", UPDATE_CPU);
149     }
150 
151     @Override
scheduleReadProcStateCpuTimes( boolean onBattery, boolean onBatteryScreenOff, long delayMillis)152     public Future<?> scheduleReadProcStateCpuTimes(
153             boolean onBattery, boolean onBatteryScreenOff, long delayMillis) {
154         synchronized (mStats) {
155             if (!mStats.trackPerProcStateCpuTimes()) {
156                 return null;
157             }
158         }
159         synchronized (BatteryExternalStatsWorker.this) {
160             if (!mExecutorService.isShutdown()) {
161                 return mExecutorService.schedule(PooledLambda.obtainRunnable(
162                         BatteryStatsImpl::updateProcStateCpuTimes,
163                         mStats, onBattery, onBatteryScreenOff).recycleOnUse(),
164                         delayMillis, TimeUnit.MILLISECONDS);
165             }
166         }
167         return null;
168     }
169 
170     @Override
scheduleCopyFromAllUidsCpuTimes( boolean onBattery, boolean onBatteryScreenOff)171     public Future<?> scheduleCopyFromAllUidsCpuTimes(
172             boolean onBattery, boolean onBatteryScreenOff) {
173         synchronized (mStats) {
174             if (!mStats.trackPerProcStateCpuTimes()) {
175                 return null;
176             }
177         }
178         synchronized (BatteryExternalStatsWorker.this) {
179             if (!mExecutorService.isShutdown()) {
180                 return mExecutorService.submit(PooledLambda.obtainRunnable(
181                         BatteryStatsImpl::copyFromAllUidsCpuTimes,
182                         mStats, onBattery, onBatteryScreenOff).recycleOnUse());
183             }
184         }
185         return null;
186     }
187 
188     @Override
scheduleCpuSyncDueToScreenStateChange( boolean onBattery, boolean onBatteryScreenOff)189     public Future<?> scheduleCpuSyncDueToScreenStateChange(
190             boolean onBattery, boolean onBatteryScreenOff) {
191         synchronized (BatteryExternalStatsWorker.this) {
192             if (mCurrentFuture == null || (mUpdateFlags & UPDATE_CPU) == 0) {
193                 mOnBattery = onBattery;
194                 mOnBatteryScreenOff = onBatteryScreenOff;
195                 mUseLatestStates = false;
196             }
197             return scheduleSyncLocked("screen-state", UPDATE_CPU);
198         }
199     }
200 
201     @Override
scheduleCpuSyncDueToWakelockChange(long delayMillis)202     public Future<?> scheduleCpuSyncDueToWakelockChange(long delayMillis) {
203         synchronized (BatteryExternalStatsWorker.this) {
204             mWakelockChangesUpdate = scheduleDelayedSyncLocked(mWakelockChangesUpdate,
205                     () -> {
206                         scheduleSync("wakelock-change", UPDATE_CPU);
207                         scheduleRunnable(() -> mStats.postBatteryNeedsCpuUpdateMsg());
208                     },
209                     delayMillis);
210             return mWakelockChangesUpdate;
211         }
212     }
213 
214     @Override
cancelCpuSyncDueToWakelockChange()215     public void cancelCpuSyncDueToWakelockChange() {
216         synchronized (BatteryExternalStatsWorker.this) {
217             if (mWakelockChangesUpdate != null) {
218                 mWakelockChangesUpdate.cancel(false);
219                 mWakelockChangesUpdate = null;
220             }
221         }
222     }
223 
224     @Override
scheduleSyncDueToBatteryLevelChange(long delayMillis)225     public Future<?> scheduleSyncDueToBatteryLevelChange(long delayMillis) {
226         synchronized (BatteryExternalStatsWorker.this) {
227             mBatteryLevelSync = scheduleDelayedSyncLocked(mBatteryLevelSync,
228                     () -> scheduleSync("battery-level", UPDATE_ALL),
229                     delayMillis);
230             return mBatteryLevelSync;
231         }
232     }
233 
234     @GuardedBy("this")
cancelSyncDueToBatteryLevelChangeLocked()235     private void cancelSyncDueToBatteryLevelChangeLocked() {
236         if (mBatteryLevelSync != null) {
237             mBatteryLevelSync.cancel(false);
238             mBatteryLevelSync = null;
239         }
240     }
241 
242     /**
243      * Schedule a sync {@param syncRunnable} with a delay. If there's already a scheduled sync, a
244      * new sync won't be scheduled unless it is being scheduled to run immediately (delayMillis=0).
245      *
246      * @param lastScheduledSync the task which was earlier scheduled to run
247      * @param syncRunnable the task that needs to be scheduled to run
248      * @param delayMillis time after which {@param syncRunnable} needs to be scheduled
249      * @return scheduled {@link Future} which can be used to check if task is completed or to
250      *         cancel it if needed
251      */
252     @GuardedBy("this")
scheduleDelayedSyncLocked(Future<?> lastScheduledSync, Runnable syncRunnable, long delayMillis)253     private Future<?> scheduleDelayedSyncLocked(Future<?> lastScheduledSync, Runnable syncRunnable,
254             long delayMillis) {
255         if (mExecutorService.isShutdown()) {
256             return CompletableFuture.failedFuture(new IllegalStateException("worker shutdown"));
257         }
258 
259         if (lastScheduledSync != null) {
260             // If there's already a scheduled task, leave it as is if we're trying to
261             // re-schedule it again with a delay, otherwise cancel and re-schedule it.
262             if (delayMillis == 0) {
263                 lastScheduledSync.cancel(false);
264             } else {
265                 return lastScheduledSync;
266             }
267         }
268 
269         return mExecutorService.schedule(syncRunnable, delayMillis, TimeUnit.MILLISECONDS);
270     }
271 
scheduleWrite()272     public synchronized Future<?> scheduleWrite() {
273         if (mExecutorService.isShutdown()) {
274             return CompletableFuture.failedFuture(new IllegalStateException("worker shutdown"));
275         }
276 
277         scheduleSyncLocked("write", UPDATE_ALL);
278         // Since we use a single threaded executor, we can assume the next scheduled task's
279         // Future finishes after the sync.
280         return mExecutorService.submit(mWriteTask);
281     }
282 
283     /**
284      * Schedules a task to run on the BatteryExternalStatsWorker thread. If scheduling more work
285      * within the task, never wait on the resulting Future. This will result in a deadlock.
286      */
scheduleRunnable(Runnable runnable)287     public synchronized void scheduleRunnable(Runnable runnable) {
288         if (!mExecutorService.isShutdown()) {
289             mExecutorService.submit(runnable);
290         }
291     }
292 
shutdown()293     public void shutdown() {
294         mExecutorService.shutdownNow();
295     }
296 
297     @GuardedBy("this")
scheduleSyncLocked(String reason, int flags)298     private Future<?> scheduleSyncLocked(String reason, int flags) {
299         if (mExecutorService.isShutdown()) {
300             return CompletableFuture.failedFuture(new IllegalStateException("worker shutdown"));
301         }
302 
303         if (mCurrentFuture == null) {
304             mUpdateFlags = flags;
305             mCurrentReason = reason;
306             mCurrentFuture = mExecutorService.submit(mSyncTask);
307         }
308         mUpdateFlags |= flags;
309         return mCurrentFuture;
310     }
311 
getLastCollectionTimeStamp()312     long getLastCollectionTimeStamp() {
313         synchronized (this) {
314             return mLastCollectionTimeStamp;
315         }
316     }
317 
318     private final Runnable mSyncTask = new Runnable() {
319         @Override
320         public void run() {
321             // Capture a snapshot of the state we are meant to process.
322             final int updateFlags;
323             final String reason;
324             final int[] uidsToRemove;
325             final boolean onBattery;
326             final boolean onBatteryScreenOff;
327             final boolean useLatestStates;
328             synchronized (BatteryExternalStatsWorker.this) {
329                 updateFlags = mUpdateFlags;
330                 reason = mCurrentReason;
331                 uidsToRemove = mUidsToRemove.size() > 0 ? mUidsToRemove.toArray() : EmptyArray.INT;
332                 onBattery = mOnBattery;
333                 onBatteryScreenOff = mOnBatteryScreenOff;
334                 useLatestStates = mUseLatestStates;
335                 mUpdateFlags = 0;
336                 mCurrentReason = null;
337                 mUidsToRemove.clear();
338                 mCurrentFuture = null;
339                 mUseLatestStates = true;
340                 if ((updateFlags & UPDATE_ALL) != 0) {
341                     cancelSyncDueToBatteryLevelChangeLocked();
342                 }
343                 if ((updateFlags & UPDATE_CPU) != 0) {
344                     cancelCpuSyncDueToWakelockChange();
345                 }
346             }
347 
348             try {
349                 synchronized (mWorkerLock) {
350                     if (DEBUG) {
351                         Slog.d(TAG, "begin updateExternalStatsSync reason=" + reason);
352                     }
353                     try {
354                         updateExternalStatsLocked(reason, updateFlags, onBattery,
355                                 onBatteryScreenOff, useLatestStates);
356                     } finally {
357                         if (DEBUG) {
358                             Slog.d(TAG, "end updateExternalStatsSync");
359                         }
360                     }
361                 }
362 
363                 if ((updateFlags & UPDATE_CPU) != 0) {
364                     mStats.copyFromAllUidsCpuTimes();
365                 }
366 
367                 // Clean up any UIDs if necessary.
368                 synchronized (mStats) {
369                     for (int uid : uidsToRemove) {
370                         mStats.removeIsolatedUidLocked(uid);
371                     }
372                     mStats.clearPendingRemovedUids();
373                 }
374             } catch (Exception e) {
375                 Slog.wtf(TAG, "Error updating external stats: ", e);
376             }
377 
378             synchronized (BatteryExternalStatsWorker.this) {
379                 mLastCollectionTimeStamp = SystemClock.elapsedRealtime();
380             }
381         }
382     };
383 
384     private final Runnable mWriteTask = new Runnable() {
385         @Override
386         public void run() {
387             synchronized (mStats) {
388                 mStats.writeAsyncLocked();
389             }
390         }
391     };
392 
393     @GuardedBy("mWorkerLock")
updateExternalStatsLocked(final String reason, int updateFlags, boolean onBattery, boolean onBatteryScreenOff, boolean useLatestStates)394     private void updateExternalStatsLocked(final String reason, int updateFlags,
395             boolean onBattery, boolean onBatteryScreenOff, boolean useLatestStates) {
396         // We will request data from external processes asynchronously, and wait on a timeout.
397         SynchronousResultReceiver wifiReceiver = null;
398         SynchronousResultReceiver bluetoothReceiver = null;
399         SynchronousResultReceiver modemReceiver = null;
400 
401         if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_WIFI) != 0) {
402             // We were asked to fetch WiFi data.
403             if (mWifiManager == null) {
404                 mWifiManager = IWifiManager.Stub.asInterface(ServiceManager.getService(
405                         Context.WIFI_SERVICE));
406             }
407 
408             if (mWifiManager != null) {
409                 try {
410                     wifiReceiver = new SynchronousResultReceiver("wifi");
411                     mWifiManager.requestActivityInfo(wifiReceiver);
412                 } catch (RemoteException e) {
413                     // Oh well.
414                 }
415             }
416         }
417 
418         if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_BT) != 0) {
419             // We were asked to fetch Bluetooth data.
420             final BluetoothAdapter adapter = BluetoothAdapter.getDefaultAdapter();
421             if (adapter != null) {
422                 bluetoothReceiver = new SynchronousResultReceiver("bluetooth");
423                 adapter.requestControllerActivityEnergyInfo(bluetoothReceiver);
424             }
425         }
426 
427         if ((updateFlags & BatteryStatsImpl.ExternalStatsSync.UPDATE_RADIO) != 0) {
428             // We were asked to fetch Telephony data.
429             if (mTelephony == null) {
430                 mTelephony = TelephonyManager.from(mContext);
431             }
432 
433             if (mTelephony != null) {
434                 modemReceiver = new SynchronousResultReceiver("telephony");
435                 mTelephony.requestModemActivityInfo(modemReceiver);
436             }
437         }
438 
439         final WifiActivityEnergyInfo wifiInfo = awaitControllerInfo(wifiReceiver);
440         final BluetoothActivityEnergyInfo bluetoothInfo = awaitControllerInfo(bluetoothReceiver);
441         final ModemActivityInfo modemInfo = awaitControllerInfo(modemReceiver);
442 
443         synchronized (mStats) {
444             mStats.addHistoryEventLocked(
445                     SystemClock.elapsedRealtime(),
446                     SystemClock.uptimeMillis(),
447                     BatteryStats.HistoryItem.EVENT_COLLECT_EXTERNAL_STATS,
448                     reason, 0);
449 
450             if ((updateFlags & UPDATE_CPU) != 0) {
451                 if (useLatestStates) {
452                     onBattery = mStats.isOnBatteryLocked();
453                     onBatteryScreenOff = mStats.isOnBatteryScreenOffLocked();
454                 }
455                 mStats.updateCpuTimeLocked(onBattery, onBatteryScreenOff);
456             }
457 
458             if ((updateFlags & UPDATE_ALL) != 0) {
459                 mStats.updateKernelWakelocksLocked();
460                 mStats.updateKernelMemoryBandwidthLocked();
461             }
462 
463             if ((updateFlags & UPDATE_RPM) != 0) {
464                 mStats.updateRpmStatsLocked();
465             }
466 
467             if (bluetoothInfo != null) {
468                 if (bluetoothInfo.isValid()) {
469                     mStats.updateBluetoothStateLocked(bluetoothInfo);
470                 } else {
471                     Slog.w(TAG, "bluetooth info is invalid: " + bluetoothInfo);
472                 }
473             }
474         }
475 
476         // WiFi and Modem state are updated without the mStats lock held, because they
477         // do some network stats retrieval before internally grabbing the mStats lock.
478 
479         if (wifiInfo != null) {
480             if (wifiInfo.isValid()) {
481                 mStats.updateWifiState(extractDeltaLocked(wifiInfo));
482             } else {
483                 Slog.w(TAG, "wifi info is invalid: " + wifiInfo);
484             }
485         }
486 
487         if (modemInfo != null) {
488             if (modemInfo.isValid()) {
489                 mStats.updateMobileRadioState(modemInfo);
490             } else {
491                 Slog.w(TAG, "modem info is invalid: " + modemInfo);
492             }
493         }
494     }
495 
496     /**
497      * Helper method to extract the Parcelable controller info from a
498      * SynchronousResultReceiver.
499      */
awaitControllerInfo( @ullable SynchronousResultReceiver receiver)500     private static <T extends Parcelable> T awaitControllerInfo(
501             @Nullable SynchronousResultReceiver receiver) {
502         if (receiver == null) {
503             return null;
504         }
505 
506         try {
507             final SynchronousResultReceiver.Result result =
508                     receiver.awaitResult(EXTERNAL_STATS_SYNC_TIMEOUT_MILLIS);
509             if (result.bundle != null) {
510                 // This is the final destination for the Bundle.
511                 result.bundle.setDefusable(true);
512 
513                 final T data = result.bundle.getParcelable(
514                         BatteryStats.RESULT_RECEIVER_CONTROLLER_KEY);
515                 if (data != null) {
516                     return data;
517                 }
518             }
519             Slog.e(TAG, "no controller energy info supplied for " + receiver.getName());
520         } catch (TimeoutException e) {
521             Slog.w(TAG, "timeout reading " + receiver.getName() + " stats");
522         }
523         return null;
524     }
525 
526     @GuardedBy("mWorkerLock")
extractDeltaLocked(WifiActivityEnergyInfo latest)527     private WifiActivityEnergyInfo extractDeltaLocked(WifiActivityEnergyInfo latest) {
528         final long timePeriodMs = latest.mTimestamp - mLastInfo.mTimestamp;
529         final long lastScanMs = mLastInfo.mControllerScanTimeMs;
530         final long lastIdleMs = mLastInfo.mControllerIdleTimeMs;
531         final long lastTxMs = mLastInfo.mControllerTxTimeMs;
532         final long lastRxMs = mLastInfo.mControllerRxTimeMs;
533         final long lastEnergy = mLastInfo.mControllerEnergyUsed;
534 
535         // We will modify the last info object to be the delta, and store the new
536         // WifiActivityEnergyInfo object as our last one.
537         final WifiActivityEnergyInfo delta = mLastInfo;
538         delta.mTimestamp = latest.getTimeStamp();
539         delta.mStackState = latest.getStackState();
540 
541         final long txTimeMs = latest.mControllerTxTimeMs - lastTxMs;
542         final long rxTimeMs = latest.mControllerRxTimeMs - lastRxMs;
543         final long idleTimeMs = latest.mControllerIdleTimeMs - lastIdleMs;
544         final long scanTimeMs = latest.mControllerScanTimeMs - lastScanMs;
545 
546         if (txTimeMs < 0 || rxTimeMs < 0 || scanTimeMs < 0) {
547             // The stats were reset by the WiFi system (which is why our delta is negative).
548             // Returns the unaltered stats.
549             delta.mControllerEnergyUsed = latest.mControllerEnergyUsed;
550             delta.mControllerRxTimeMs = latest.mControllerRxTimeMs;
551             delta.mControllerTxTimeMs = latest.mControllerTxTimeMs;
552             delta.mControllerIdleTimeMs = latest.mControllerIdleTimeMs;
553             delta.mControllerScanTimeMs = latest.mControllerScanTimeMs;
554             Slog.v(TAG, "WiFi energy data was reset, new WiFi energy data is " + delta);
555         } else {
556             final long totalActiveTimeMs = txTimeMs + rxTimeMs;
557             long maxExpectedIdleTimeMs;
558             if (totalActiveTimeMs > timePeriodMs) {
559                 // Cap the max idle time at zero since the active time consumed the whole time
560                 maxExpectedIdleTimeMs = 0;
561                 if (totalActiveTimeMs > timePeriodMs + MAX_WIFI_STATS_SAMPLE_ERROR_MILLIS) {
562                     StringBuilder sb = new StringBuilder();
563                     sb.append("Total Active time ");
564                     TimeUtils.formatDuration(totalActiveTimeMs, sb);
565                     sb.append(" is longer than sample period ");
566                     TimeUtils.formatDuration(timePeriodMs, sb);
567                     sb.append(".\n");
568                     sb.append("Previous WiFi snapshot: ").append("idle=");
569                     TimeUtils.formatDuration(lastIdleMs, sb);
570                     sb.append(" rx=");
571                     TimeUtils.formatDuration(lastRxMs, sb);
572                     sb.append(" tx=");
573                     TimeUtils.formatDuration(lastTxMs, sb);
574                     sb.append(" e=").append(lastEnergy);
575                     sb.append("\n");
576                     sb.append("Current WiFi snapshot: ").append("idle=");
577                     TimeUtils.formatDuration(latest.mControllerIdleTimeMs, sb);
578                     sb.append(" rx=");
579                     TimeUtils.formatDuration(latest.mControllerRxTimeMs, sb);
580                     sb.append(" tx=");
581                     TimeUtils.formatDuration(latest.mControllerTxTimeMs, sb);
582                     sb.append(" e=").append(latest.mControllerEnergyUsed);
583                     Slog.wtf(TAG, sb.toString());
584                 }
585             } else {
586                 maxExpectedIdleTimeMs = timePeriodMs - totalActiveTimeMs;
587             }
588             // These times seem to be the most reliable.
589             delta.mControllerTxTimeMs = txTimeMs;
590             delta.mControllerRxTimeMs = rxTimeMs;
591             delta.mControllerScanTimeMs = scanTimeMs;
592             // WiFi calculates the idle time as a difference from the on time and the various
593             // Rx + Tx times. There seems to be some missing time there because this sometimes
594             // becomes negative. Just cap it at 0 and ensure that it is less than the expected idle
595             // time from the difference in timestamps.
596             // b/21613534
597             delta.mControllerIdleTimeMs = Math.min(maxExpectedIdleTimeMs, Math.max(0, idleTimeMs));
598             delta.mControllerEnergyUsed = Math.max(0, latest.mControllerEnergyUsed - lastEnergy);
599         }
600 
601         mLastInfo = latest;
602         return delta;
603     }
604 }
605