AppScanStats.java revision 319aeae6f4ebd13678b4f77375d1804978c4a1e1 
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 */
16package com.android.bluetooth.gatt;
17
18import android.bluetooth.le.ScanSettings;
19import android.os.Binder;
20import android.os.WorkSource;
21import android.os.ServiceManager;
22import android.os.SystemClock;
23import android.os.RemoteException;
24import com.android.internal.app.IBatteryStats;
25import java.text.DateFormat;
26import java.text.SimpleDateFormat;
27import java.util.ArrayList;
28import java.util.Date;
29import java.util.Iterator;
30import java.util.List;
31import java.util.HashMap;
32
33import com.android.bluetooth.btservice.BluetoothProto;
34/**
35 * ScanStats class helps keep track of information about scans
36 * on a per application basis.
37 * @hide
38 */
39/*package*/ class AppScanStats {
40    static final DateFormat dateFormat = new SimpleDateFormat("yyyy/MM/dd HH:mm:ss");
41
42    /* ContextMap here is needed to grab Apps and Connections */
43    ContextMap contextMap;
44
45    /* GattService is needed to add scan event protos to be dumped later */
46    GattService gattService;
47
48    /* Battery stats is used to keep track of scans and result stats */
49    IBatteryStats batteryStats;
50
51    class LastScan {
52        long duration;
53        long suspendDuration;
54        long suspendStartTime;
55        boolean isSuspended;
56        long timestamp;
57        boolean opportunistic;
58        boolean timeout;
59        boolean background;
60        boolean filtered;
61        int results;
62        int scannerId;
63
64        public LastScan(long timestamp, long duration, boolean opportunistic, boolean background,
65                boolean filtered, int scannerId) {
66            this.duration = duration;
67            this.timestamp = timestamp;
68            this.opportunistic = opportunistic;
69            this.background = background;
70            this.filtered = filtered;
71            this.results = 0;
72            this.scannerId = scannerId;
73            this.suspendDuration = 0;
74            this.suspendStartTime = 0;
75            this.isSuspended = false;
76        }
77    }
78
79    static final int NUM_SCAN_DURATIONS_KEPT = 5;
80
81    // This constant defines the time window an app can scan multiple times.
82    // Any single app can scan up to |NUM_SCAN_DURATIONS_KEPT| times during
83    // this window. Once they reach this limit, they must wait until their
84    // earliest recorded scan exits this window.
85    static final long EXCESSIVE_SCANNING_PERIOD_MS = 30 * 1000;
86
87    // Maximum msec before scan gets downgraded to opportunistic
88    static final int SCAN_TIMEOUT_MS = 30 * 60 * 1000;
89
90    String appName;
91    WorkSource workSource; // Used for BatteryStats
92    int scansStarted = 0;
93    int scansStopped = 0;
94    boolean isRegistered = false;
95    long minScanTime = Long.MAX_VALUE;
96    long maxScanTime = 0;
97    long mScanStartTime = 0;
98    long mTotalScanTime = 0;
99    long mTotalSuspendTime = 0;
100    List<LastScan> lastScans = new ArrayList<LastScan>(NUM_SCAN_DURATIONS_KEPT);
101    HashMap<Integer, LastScan> ongoingScans = new HashMap<Integer, LastScan>();
102    long startTime = 0;
103    long stopTime = 0;
104    int results = 0;
105
106    public AppScanStats(String name, WorkSource source, ContextMap map, GattService service) {
107        appName = name;
108        contextMap = map;
109        gattService = service;
110        batteryStats = IBatteryStats.Stub.asInterface(ServiceManager.getService("batterystats"));
111
112        if (source == null) {
113            // Bill the caller if the work source isn't passed through
114            source = new WorkSource(Binder.getCallingUid(), appName);
115        }
116        workSource = source;
117    }
118
119    synchronized void addResult(int scannerId) {
120        LastScan scan = getScanFromScannerId(scannerId);
121        if (scan != null) {
122            scan.results++;
123        }
124
125        results++;
126    }
127
128    boolean isScanning() {
129        return !ongoingScans.isEmpty();
130    }
131
132    LastScan getScanFromScannerId(int scannerId) {
133        return ongoingScans.get(scannerId);
134    }
135
136    synchronized void recordScanStart(ScanSettings settings, boolean filtered, int scannerId) {
137        LastScan existingScan = getScanFromScannerId(scannerId);
138        if (existingScan != null) {
139            return;
140        }
141        this.scansStarted++;
142        startTime = SystemClock.elapsedRealtime();
143
144        LastScan scan = new LastScan(startTime, 0, false, false, filtered, scannerId);
145        if (settings != null) {
146          scan.opportunistic = settings.getScanMode() == ScanSettings.SCAN_MODE_OPPORTUNISTIC;
147          scan.background = (settings.getCallbackType() & ScanSettings.CALLBACK_TYPE_FIRST_MATCH) != 0;
148        }
149
150        BluetoothProto.ScanEvent scanEvent = new BluetoothProto.ScanEvent();
151        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_START);
152        scanEvent.setScanTechnologyType(BluetoothProto.ScanEvent.SCAN_TECH_TYPE_LE);
153        scanEvent.setEventTimeMillis(System.currentTimeMillis());
154        scanEvent.setInitiator(truncateAppName(appName));
155        gattService.addScanEvent(scanEvent);
156
157        if (!isScanning()) {
158            try {
159                mScanStartTime = startTime;
160                batteryStats.noteBleScanStarted(workSource);
161            } catch (RemoteException e) {
162                /* ignore */
163            }
164        }
165
166        ongoingScans.put(scannerId, scan);
167    }
168
169    synchronized void recordScanStop(int scannerId) {
170        LastScan scan = getScanFromScannerId(scannerId);
171        if (scan == null) {
172            return;
173        }
174        this.scansStopped++;
175        stopTime = SystemClock.elapsedRealtime();
176        long scanDuration = stopTime - scan.timestamp;
177        scan.duration = scanDuration;
178        if (scan.isSuspended) {
179            scan.suspendDuration += stopTime - scan.suspendStartTime;
180            mTotalSuspendTime += scan.suspendDuration;
181        }
182        ongoingScans.remove(scannerId);
183        if (lastScans.size() >= NUM_SCAN_DURATIONS_KEPT) {
184            lastScans.remove(0);
185        }
186        lastScans.add(scan);
187
188        BluetoothProto.ScanEvent scanEvent = new BluetoothProto.ScanEvent();
189        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_STOP);
190        scanEvent.setScanTechnologyType(BluetoothProto.ScanEvent.SCAN_TECH_TYPE_LE);
191        scanEvent.setEventTimeMillis(System.currentTimeMillis());
192        scanEvent.setInitiator(truncateAppName(appName));
193        gattService.addScanEvent(scanEvent);
194
195        if (!isScanning()) {
196            try {
197                long totalDuration = stopTime - mScanStartTime;
198                mTotalScanTime += totalDuration;
199                minScanTime = Math.min(totalDuration, minScanTime);
200                maxScanTime = Math.max(totalDuration, maxScanTime);
201                batteryStats.noteBleScanStopped(workSource);
202            } catch (RemoteException e) {
203                /* ignore */
204            }
205        }
206    }
207
208    synchronized void recordScanSuspend(int scannerId) {
209        LastScan scan = getScanFromScannerId(scannerId);
210        if (scan == null || scan.isSuspended) {
211            return;
212        }
213        scan.suspendStartTime = SystemClock.elapsedRealtime();
214        scan.isSuspended = true;
215    }
216
217    synchronized void recordScanResume(int scannerId) {
218        LastScan scan = getScanFromScannerId(scannerId);
219        if (scan == null || !scan.isSuspended) {
220            return;
221        }
222        scan.isSuspended = false;
223        stopTime = SystemClock.elapsedRealtime();
224        scan.suspendDuration += stopTime - scan.suspendStartTime;
225        mTotalSuspendTime += scan.suspendDuration;
226    }
227
228    synchronized void setScanTimeout(int scannerId) {
229        if (!isScanning()) return;
230
231        LastScan scan = getScanFromScannerId(scannerId);
232        if (scan != null) {
233            scan.timeout = true;
234        }
235    }
236
237    synchronized boolean isScanningTooFrequently() {
238        if (lastScans.size() < NUM_SCAN_DURATIONS_KEPT) {
239            return false;
240        }
241
242        return (SystemClock.elapsedRealtime() - lastScans.get(0).timestamp)
243                < EXCESSIVE_SCANNING_PERIOD_MS;
244    }
245
246    synchronized boolean isScanningTooLong() {
247        if (!isScanning()) {
248            return false;
249        }
250        return (SystemClock.elapsedRealtime() - mScanStartTime) > SCAN_TIMEOUT_MS;
251    }
252
253    // This function truncates the app name for privacy reasons. Apps with
254    // four part package names or more get truncated to three parts, and apps
255    // with three part package names names get truncated to two. Apps with two
256    // or less package names names are untouched.
257    // Examples: one.two.three.four => one.two.three
258    //           one.two.three => one.two
259    private String truncateAppName(String name) {
260        String initiator = name;
261        String[] nameSplit = initiator.split("\\.");
262        if (nameSplit.length > 3) {
263            initiator = nameSplit[0] + "." +
264                        nameSplit[1] + "." +
265                        nameSplit[2];
266        } else if (nameSplit.length == 3) {
267            initiator = nameSplit[0] + "." + nameSplit[1];
268        }
269
270        return initiator;
271    }
272
273    synchronized void dumpToString(StringBuilder sb) {
274        long currTime = SystemClock.elapsedRealtime();
275        long maxScan = maxScanTime;
276        long minScan = minScanTime;
277        long scanDuration = 0;
278
279        if (isScanning()) {
280            scanDuration = currTime - mScanStartTime;
281        }
282        minScan = Math.min(scanDuration, minScan);
283        maxScan = Math.max(scanDuration, maxScan);
284
285        if (minScan == Long.MAX_VALUE) {
286            minScan = 0;
287        }
288
289        long avgScan = 0;
290        long totalScanTime = mTotalScanTime + scanDuration;
291        if (scansStarted > 0) {
292            avgScan = totalScanTime / scansStarted;
293        }
294
295        sb.append("  " + appName);
296        if (isRegistered) sb.append(" (Registered)");
297
298        if (!lastScans.isEmpty()) {
299            LastScan lastScan = lastScans.get(lastScans.size() - 1);
300            if (lastScan.opportunistic) sb.append(" (Opportunistic)");
301            if (lastScan.background) sb.append(" (Background)");
302            if (lastScan.timeout) sb.append(" (Forced-Opportunistic)");
303            if (lastScan.filtered) sb.append(" (Filtered)");
304        }
305        sb.append("\n");
306
307        sb.append("  LE scans (started/stopped)         : " +
308                  scansStarted + " / " +
309                  scansStopped + "\n");
310        sb.append("  Scan time in ms (min/max/avg/total): " +
311                  minScan + " / " +
312                  maxScan + " / " +
313                  avgScan + " / " +
314                  totalScanTime + "\n");
315        if (mTotalSuspendTime != 0) {
316            sb.append("  Total time suspended             : " + mTotalSuspendTime + "ms\n");
317        }
318        sb.append("  Total number of results            : " +
319                  results + "\n");
320
321        long currentTime = System.currentTimeMillis();
322        long elapsedRt = SystemClock.elapsedRealtime();
323        if (!lastScans.isEmpty()) {
324            sb.append("  Last " + lastScans.size() + " scans                       :\n");
325
326            for (int i = 0; i < lastScans.size(); i++) {
327                LastScan scan = lastScans.get(i);
328                Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
329                sb.append("    " + dateFormat.format(timestamp) + " - ");
330                sb.append(scan.duration + "ms ");
331                if (scan.opportunistic) sb.append("Opp ");
332                if (scan.background) sb.append("Back ");
333                if (scan.timeout) sb.append("Forced ");
334                if (scan.filtered) sb.append("Filter ");
335                sb.append(scan.results + " results");
336                sb.append(" (" + scan.scannerId + ")");
337                sb.append("\n");
338                if (scan.suspendDuration != 0) {
339                    sb.append("      └"
340                            + " Suspended Time: " + scan.suspendDuration + "ms\n");
341                }
342            }
343        }
344
345        if (!ongoingScans.isEmpty()) {
346            sb.append("  Ongoing scans                      :\n");
347            for (Integer key : ongoingScans.keySet()) {
348                LastScan scan = ongoingScans.get(key);
349                Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
350                sb.append("    " + dateFormat.format(timestamp) + " - ");
351                sb.append((elapsedRt - scan.timestamp) + "ms ");
352                if (scan.opportunistic) sb.append("Opp ");
353                if (scan.background) sb.append("Back ");
354                if (scan.timeout) sb.append("Forced ");
355                if (scan.filtered) sb.append("Filter ");
356                if (scan.isSuspended) sb.append("Suspended ");
357                sb.append(scan.results + " results");
358                sb.append(" (" + scan.scannerId + ")");
359                sb.append("\n");
360                if (scan.suspendStartTime != 0) {
361                    long duration = scan.suspendDuration
362                            + (scan.isSuspended ? (elapsedRt - scan.suspendStartTime) : 0);
363                    sb.append("      └"
364                            + " Suspended Time: " + duration + "ms\n");
365                }
366            }
367        }
368
369        ContextMap.App appEntry = contextMap.getByName(appName);
370        if (appEntry != null && isRegistered) {
371            sb.append("  Application ID                     : " +
372                      appEntry.id + "\n");
373            sb.append("  UUID                               : " +
374                      appEntry.uuid + "\n");
375
376            List<ContextMap.Connection> connections =
377              contextMap.getConnectionByApp(appEntry.id);
378
379            sb.append("  Connections: " + connections.size() + "\n");
380
381            Iterator<ContextMap.Connection> ii = connections.iterator();
382            while(ii.hasNext()) {
383                ContextMap.Connection connection = ii.next();
384                long connectionTime = SystemClock.elapsedRealtime() - connection.startTime;
385                sb.append("    " + connection.connId + ": " +
386                          connection.address + " " + connectionTime + "ms\n");
387            }
388        }
389        sb.append("\n");
390    }
391}
392