• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2016 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy 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,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 package com.android.bluetooth.gatt;
17 
18 import android.bluetooth.le.ScanSettings;
19 import android.os.Binder;
20 import android.os.RemoteException;
21 import android.os.ServiceManager;
22 import android.os.SystemClock;
23 import android.os.WorkSource;
24 import android.util.StatsLog;
25 
26 import com.android.bluetooth.BluetoothMetricsProto;
27 import com.android.internal.app.IBatteryStats;
28 
29 import java.text.DateFormat;
30 import java.text.SimpleDateFormat;
31 import java.util.ArrayList;
32 import java.util.Date;
33 import java.util.HashMap;
34 import java.util.Iterator;
35 import java.util.List;
36 
37 /**
38  * ScanStats class helps keep track of information about scans
39  * on a per application basis.
40  * @hide
41  */
42 /*package*/ class AppScanStats {
43     private static final String TAG = AppScanStats.class.getSimpleName();
44 
45     static final DateFormat DATE_FORMAT = new SimpleDateFormat("MM-dd HH:mm:ss");
46 
47     /* ContextMap here is needed to grab Apps and Connections */ ContextMap mContextMap;
48 
49     /* GattService is needed to add scan event protos to be dumped later */ GattService
50             mGattService;
51 
52     /* Battery stats is used to keep track of scans and result stats */ IBatteryStats mBatteryStats;
53 
54     class LastScan {
55         public long duration;
56         public long suspendDuration;
57         public long suspendStartTime;
58         public boolean isSuspended;
59         public long timestamp;
60         public boolean opportunistic;
61         public boolean timeout;
62         public boolean background;
63         public boolean filtered;
64         public int results;
65         public int scannerId;
66 
LastScan(long timestamp, long duration, boolean opportunistic, boolean background, boolean filtered, int scannerId)67         LastScan(long timestamp, long duration, boolean opportunistic, boolean background,
68                 boolean filtered, int scannerId) {
69             this.duration = duration;
70             this.timestamp = timestamp;
71             this.opportunistic = opportunistic;
72             this.background = background;
73             this.filtered = filtered;
74             this.results = 0;
75             this.scannerId = scannerId;
76             this.suspendDuration = 0;
77             this.suspendStartTime = 0;
78             this.isSuspended = false;
79         }
80     }
81 
82     static final int NUM_SCAN_DURATIONS_KEPT = 5;
83 
84     // This constant defines the time window an app can scan multiple times.
85     // Any single app can scan up to |NUM_SCAN_DURATIONS_KEPT| times during
86     // this window. Once they reach this limit, they must wait until their
87     // earliest recorded scan exits this window.
88     static final long EXCESSIVE_SCANNING_PERIOD_MS = 30 * 1000;
89 
90     // Maximum msec before scan gets downgraded to opportunistic
91     static final int SCAN_TIMEOUT_MS = 30 * 60 * 1000;
92 
93     public String appName;
94     public WorkSource mWorkSource; // Used for BatteryStats and StatsLog
95     private int mScansStarted = 0;
96     private int mScansStopped = 0;
97     public boolean isRegistered = false;
98     private long mMinScanTime = Long.MAX_VALUE;
99     private long mMaxScanTime = 0;
100     private long mScanStartTime = 0;
101     private long mTotalScanTime = 0;
102     private long mTotalSuspendTime = 0;
103     private List<LastScan> mLastScans = new ArrayList<LastScan>(NUM_SCAN_DURATIONS_KEPT);
104     private HashMap<Integer, LastScan> mOngoingScans = new HashMap<Integer, LastScan>();
105     public long startTime = 0;
106     public long stopTime = 0;
107     public int results = 0;
108 
AppScanStats(String name, WorkSource source, ContextMap map, GattService service)109     AppScanStats(String name, WorkSource source, ContextMap map, GattService service) {
110         appName = name;
111         mContextMap = map;
112         mGattService = service;
113         mBatteryStats = IBatteryStats.Stub.asInterface(ServiceManager.getService("batterystats"));
114 
115         if (source == null) {
116             // Bill the caller if the work source isn't passed through
117             source = new WorkSource(Binder.getCallingUid(), appName);
118         }
119         mWorkSource = source;
120     }
121 
addResult(int scannerId)122     synchronized void addResult(int scannerId) {
123         LastScan scan = getScanFromScannerId(scannerId);
124         if (scan != null) {
125             scan.results++;
126 
127             // Only update battery stats after receiving 100 new results in order
128             // to lower the cost of the binder transaction
129             if (scan.results % 100 == 0) {
130                 try {
131                     mBatteryStats.noteBleScanResults(mWorkSource, 100);
132                 } catch (RemoteException e) {
133                     /* ignore */
134                 }
135                 StatsLog.write(StatsLog.BLE_SCAN_RESULT_RECEIVED, mWorkSource, 100);
136             }
137         }
138 
139         results++;
140     }
141 
isScanning()142     boolean isScanning() {
143         return !mOngoingScans.isEmpty();
144     }
145 
getScanFromScannerId(int scannerId)146     LastScan getScanFromScannerId(int scannerId) {
147         return mOngoingScans.get(scannerId);
148     }
149 
recordScanStart(ScanSettings settings, boolean filtered, int scannerId)150     synchronized void recordScanStart(ScanSettings settings, boolean filtered, int scannerId) {
151         LastScan existingScan = getScanFromScannerId(scannerId);
152         if (existingScan != null) {
153             return;
154         }
155         this.mScansStarted++;
156         startTime = SystemClock.elapsedRealtime();
157 
158         LastScan scan = new LastScan(startTime, 0, false, false, filtered, scannerId);
159         if (settings != null) {
160             scan.opportunistic = settings.getScanMode() == ScanSettings.SCAN_MODE_OPPORTUNISTIC;
161             scan.background =
162                     (settings.getCallbackType() & ScanSettings.CALLBACK_TYPE_FIRST_MATCH) != 0;
163         }
164 
165         BluetoothMetricsProto.ScanEvent scanEvent = BluetoothMetricsProto.ScanEvent.newBuilder()
166                 .setScanEventType(BluetoothMetricsProto.ScanEvent.ScanEventType.SCAN_EVENT_START)
167                 .setScanTechnologyType(
168                         BluetoothMetricsProto.ScanEvent.ScanTechnologyType.SCAN_TECH_TYPE_LE)
169                 .setEventTimeMillis(System.currentTimeMillis())
170                 .setInitiator(truncateAppName(appName)).build();
171         mGattService.addScanEvent(scanEvent);
172 
173         if (!isScanning()) {
174             mScanStartTime = startTime;
175         }
176         try {
177             boolean isUnoptimized = !(scan.filtered || scan.background || scan.opportunistic);
178             mBatteryStats.noteBleScanStarted(mWorkSource, isUnoptimized);
179         } catch (RemoteException e) {
180             /* ignore */
181         }
182         StatsLog.write(StatsLog.BLE_SCAN_STATE_CHANGED, mWorkSource,
183                 StatsLog.BLE_SCAN_STATE_CHANGED__STATE__ON,
184                 scan.filtered, scan.background, scan.opportunistic);
185 
186         mOngoingScans.put(scannerId, scan);
187     }
188 
recordScanStop(int scannerId)189     synchronized void recordScanStop(int scannerId) {
190         LastScan scan = getScanFromScannerId(scannerId);
191         if (scan == null) {
192             return;
193         }
194         this.mScansStopped++;
195         stopTime = SystemClock.elapsedRealtime();
196         long scanDuration = stopTime - scan.timestamp;
197         scan.duration = scanDuration;
198         if (scan.isSuspended) {
199             long suspendDuration = stopTime - scan.suspendStartTime;
200             scan.suspendDuration += suspendDuration;
201             mTotalSuspendTime += suspendDuration;
202         }
203         mOngoingScans.remove(scannerId);
204         if (mLastScans.size() >= NUM_SCAN_DURATIONS_KEPT) {
205             mLastScans.remove(0);
206         }
207         mLastScans.add(scan);
208 
209         BluetoothMetricsProto.ScanEvent scanEvent = BluetoothMetricsProto.ScanEvent.newBuilder()
210                 .setScanEventType(BluetoothMetricsProto.ScanEvent.ScanEventType.SCAN_EVENT_STOP)
211                 .setScanTechnologyType(
212                         BluetoothMetricsProto.ScanEvent.ScanTechnologyType.SCAN_TECH_TYPE_LE)
213                 .setEventTimeMillis(System.currentTimeMillis())
214                 .setInitiator(truncateAppName(appName))
215                 .setNumberResults(scan.results)
216                 .build();
217         mGattService.addScanEvent(scanEvent);
218 
219         if (!isScanning()) {
220             long totalDuration = stopTime - mScanStartTime;
221             mTotalScanTime += totalDuration;
222             mMinScanTime = Math.min(totalDuration, mMinScanTime);
223             mMaxScanTime = Math.max(totalDuration, mMaxScanTime);
224         }
225 
226         try {
227             // Inform battery stats of any results it might be missing on scan stop
228             boolean isUnoptimized = !(scan.filtered || scan.background || scan.opportunistic);
229             mBatteryStats.noteBleScanResults(mWorkSource, scan.results % 100);
230             mBatteryStats.noteBleScanStopped(mWorkSource, isUnoptimized);
231         } catch (RemoteException e) {
232             /* ignore */
233         }
234         StatsLog.write(StatsLog.BLE_SCAN_RESULT_RECEIVED, mWorkSource, scan.results % 100);
235         StatsLog.write(StatsLog.BLE_SCAN_STATE_CHANGED, mWorkSource,
236                 StatsLog.BLE_SCAN_STATE_CHANGED__STATE__OFF,
237                 scan.filtered, scan.background, scan.opportunistic);
238     }
239 
recordScanSuspend(int scannerId)240     synchronized void recordScanSuspend(int scannerId) {
241         LastScan scan = getScanFromScannerId(scannerId);
242         if (scan == null || scan.isSuspended) {
243             return;
244         }
245         scan.suspendStartTime = SystemClock.elapsedRealtime();
246         scan.isSuspended = true;
247     }
248 
recordScanResume(int scannerId)249     synchronized void recordScanResume(int scannerId) {
250         LastScan scan = getScanFromScannerId(scannerId);
251         long suspendDuration = 0;
252         if (scan == null || !scan.isSuspended) {
253             return;
254         }
255         scan.isSuspended = false;
256         stopTime = SystemClock.elapsedRealtime();
257         suspendDuration = stopTime - scan.suspendStartTime;
258         scan.suspendDuration += suspendDuration;
259         mTotalSuspendTime += suspendDuration;
260     }
261 
setScanTimeout(int scannerId)262     synchronized void setScanTimeout(int scannerId) {
263         if (!isScanning()) {
264             return;
265         }
266 
267         LastScan scan = getScanFromScannerId(scannerId);
268         if (scan != null) {
269             scan.timeout = true;
270         }
271     }
272 
isScanningTooFrequently()273     synchronized boolean isScanningTooFrequently() {
274         if (mLastScans.size() < NUM_SCAN_DURATIONS_KEPT) {
275             return false;
276         }
277 
278         return (SystemClock.elapsedRealtime() - mLastScans.get(0).timestamp)
279                 < EXCESSIVE_SCANNING_PERIOD_MS;
280     }
281 
isScanningTooLong()282     synchronized boolean isScanningTooLong() {
283         if (!isScanning()) {
284             return false;
285         }
286         return (SystemClock.elapsedRealtime() - mScanStartTime) > SCAN_TIMEOUT_MS;
287     }
288 
289     // This function truncates the app name for privacy reasons. Apps with
290     // four part package names or more get truncated to three parts, and apps
291     // with three part package names names get truncated to two. Apps with two
292     // or less package names names are untouched.
293     // Examples: one.two.three.four => one.two.three
294     //           one.two.three => one.two
truncateAppName(String name)295     private String truncateAppName(String name) {
296         String initiator = name;
297         String[] nameSplit = initiator.split("\\.");
298         if (nameSplit.length > 3) {
299             initiator = nameSplit[0] + "." + nameSplit[1] + "." + nameSplit[2];
300         } else if (nameSplit.length == 3) {
301             initiator = nameSplit[0] + "." + nameSplit[1];
302         }
303 
304         return initiator;
305     }
306 
dumpToString(StringBuilder sb)307     synchronized void dumpToString(StringBuilder sb) {
308         long currTime = SystemClock.elapsedRealtime();
309         long maxScan = mMaxScanTime;
310         long minScan = mMinScanTime;
311         long scanDuration = 0;
312 
313         if (isScanning()) {
314             scanDuration = currTime - mScanStartTime;
315         }
316         minScan = Math.min(scanDuration, minScan);
317         maxScan = Math.max(scanDuration, maxScan);
318 
319         if (minScan == Long.MAX_VALUE) {
320             minScan = 0;
321         }
322 
323         /*TODO: Average scan time can be skewed for
324          * multiple scan clients. It will show less than
325          * actual value.
326          * */
327         long avgScan = 0;
328         long totalScanTime = mTotalScanTime + scanDuration;
329         if (mScansStarted > 0) {
330             avgScan = totalScanTime / mScansStarted;
331         }
332 
333         sb.append("  " + appName);
334         if (isRegistered) {
335             sb.append(" (Registered)");
336         }
337 
338         if (!mLastScans.isEmpty()) {
339             LastScan lastScan = mLastScans.get(mLastScans.size() - 1);
340             if (lastScan.opportunistic) {
341                 sb.append(" (Opportunistic)");
342             }
343             if (lastScan.background) {
344                 sb.append(" (Background)");
345             }
346             if (lastScan.timeout) {
347                 sb.append(" (Forced-Opportunistic)");
348             }
349             if (lastScan.filtered) {
350                 sb.append(" (Filtered)");
351             }
352         }
353         sb.append("\n");
354 
355         sb.append("  LE scans (started/stopped)         : " + mScansStarted + " / " + mScansStopped
356                 + "\n");
357         sb.append("  Scan time in ms (min/max/avg/total): " + minScan + " / " + maxScan + " / "
358                 + avgScan + " / " + totalScanTime + "\n");
359         if (mTotalSuspendTime != 0) {
360             sb.append("  Total time suspended               : " + mTotalSuspendTime + "ms\n");
361         }
362         sb.append("  Total number of results            : " + results + "\n");
363 
364         long currentTime = System.currentTimeMillis();
365         long elapsedRt = SystemClock.elapsedRealtime();
366         if (!mLastScans.isEmpty()) {
367             sb.append("  Last " + mLastScans.size() + " scans                       :\n");
368 
369             for (int i = 0; i < mLastScans.size(); i++) {
370                 LastScan scan = mLastScans.get(i);
371                 Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
372                 sb.append("    " + DATE_FORMAT.format(timestamp) + " - ");
373                 sb.append(scan.duration + "ms ");
374                 if (scan.opportunistic) {
375                     sb.append("Opp ");
376                 }
377                 if (scan.background) {
378                     sb.append("Back ");
379                 }
380                 if (scan.timeout) {
381                     sb.append("Forced ");
382                 }
383                 if (scan.filtered) {
384                     sb.append("Filter ");
385                 }
386                 sb.append(scan.results + " results");
387                 sb.append(" (" + scan.scannerId + ")");
388                 sb.append("\n");
389                 if (scan.suspendDuration != 0) {
390                     sb.append("      └" + " Suspended Time: " + scan.suspendDuration + "ms\n");
391                 }
392             }
393         }
394 
395         if (!mOngoingScans.isEmpty()) {
396             sb.append("  Ongoing scans                      :\n");
397             for (Integer key : mOngoingScans.keySet()) {
398                 LastScan scan = mOngoingScans.get(key);
399                 Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
400                 sb.append("    " + DATE_FORMAT.format(timestamp) + " - ");
401                 sb.append((elapsedRt - scan.timestamp) + "ms ");
402                 if (scan.opportunistic) {
403                     sb.append("Opp ");
404                 }
405                 if (scan.background) {
406                     sb.append("Back ");
407                 }
408                 if (scan.timeout) {
409                     sb.append("Forced ");
410                 }
411                 if (scan.filtered) {
412                     sb.append("Filter ");
413                 }
414                 if (scan.isSuspended) {
415                     sb.append("Suspended ");
416                 }
417                 sb.append(scan.results + " results");
418                 sb.append(" (" + scan.scannerId + ")");
419                 sb.append("\n");
420                 if (scan.suspendStartTime != 0) {
421                     long duration = scan.suspendDuration + (scan.isSuspended ? (elapsedRt
422                             - scan.suspendStartTime) : 0);
423                     sb.append("      └" + " Suspended Time: " + duration + "ms\n");
424                 }
425             }
426         }
427 
428         ContextMap.App appEntry = mContextMap.getByName(appName);
429         if (appEntry != null && isRegistered) {
430             sb.append("  Application ID                     : " + appEntry.id + "\n");
431             sb.append("  UUID                               : " + appEntry.uuid + "\n");
432 
433             List<ContextMap.Connection> connections = mContextMap.getConnectionByApp(appEntry.id);
434 
435             sb.append("  Connections: " + connections.size() + "\n");
436 
437             Iterator<ContextMap.Connection> ii = connections.iterator();
438             while (ii.hasNext()) {
439                 ContextMap.Connection connection = ii.next();
440                 long connectionTime = elapsedRt - connection.startTime;
441                 Date timestamp = new Date(currentTime - elapsedRt + connection.startTime);
442                 sb.append("    " + DATE_FORMAT.format(timestamp) + " - ");
443                 sb.append((connectionTime) + "ms ");
444                 sb.append(": " + connection.address + " (" + connection.connId + ")\n");
445             }
446         }
447         sb.append("\n");
448     }
449 }
450