AppScanStats.java revision cb5786ffece533c1aa4d6622ba896bba0cdc4e71 
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            long suspendDuration = stopTime - scan.suspendStartTime;
180            scan.suspendDuration += suspendDuration;
181            mTotalSuspendTime += suspendDuration;
182        }
183        ongoingScans.remove(scannerId);
184        if (lastScans.size() >= NUM_SCAN_DURATIONS_KEPT) {
185            lastScans.remove(0);
186        }
187        lastScans.add(scan);
188
189        BluetoothProto.ScanEvent scanEvent = new BluetoothProto.ScanEvent();
190        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_STOP);
191        scanEvent.setScanTechnologyType(BluetoothProto.ScanEvent.SCAN_TECH_TYPE_LE);
192        scanEvent.setEventTimeMillis(System.currentTimeMillis());
193        scanEvent.setInitiator(truncateAppName(appName));
194        gattService.addScanEvent(scanEvent);
195
196        if (!isScanning()) {
197            try {
198                long totalDuration = stopTime - mScanStartTime;
199                mTotalScanTime += totalDuration;
200                minScanTime = Math.min(totalDuration, minScanTime);
201                maxScanTime = Math.max(totalDuration, maxScanTime);
202                batteryStats.noteBleScanStopped(workSource);
203            } catch (RemoteException e) {
204                /* ignore */
205            }
206        }
207    }
208
209    synchronized void recordScanSuspend(int scannerId) {
210        LastScan scan = getScanFromScannerId(scannerId);
211        if (scan == null || scan.isSuspended) {
212            return;
213        }
214        scan.suspendStartTime = SystemClock.elapsedRealtime();
215        scan.isSuspended = true;
216    }
217
218    synchronized void recordScanResume(int scannerId) {
219        LastScan scan = getScanFromScannerId(scannerId);
220        long suspendDuration = 0;
221        if (scan == null || !scan.isSuspended) {
222            return;
223        }
224        scan.isSuspended = false;
225        stopTime = SystemClock.elapsedRealtime();
226        suspendDuration = stopTime - scan.suspendStartTime;
227        scan.suspendDuration += suspendDuration;
228        mTotalSuspendTime += suspendDuration;
229    }
230
231    synchronized void setScanTimeout(int scannerId) {
232        if (!isScanning()) return;
233
234        LastScan scan = getScanFromScannerId(scannerId);
235        if (scan != null) {
236            scan.timeout = true;
237        }
238    }
239
240    synchronized boolean isScanningTooFrequently() {
241        if (lastScans.size() < NUM_SCAN_DURATIONS_KEPT) {
242            return false;
243        }
244
245        return (SystemClock.elapsedRealtime() - lastScans.get(0).timestamp)
246                < EXCESSIVE_SCANNING_PERIOD_MS;
247    }
248
249    synchronized boolean isScanningTooLong() {
250        if (!isScanning()) {
251            return false;
252        }
253        return (SystemClock.elapsedRealtime() - mScanStartTime) > SCAN_TIMEOUT_MS;
254    }
255
256    // This function truncates the app name for privacy reasons. Apps with
257    // four part package names or more get truncated to three parts, and apps
258    // with three part package names names get truncated to two. Apps with two
259    // or less package names names are untouched.
260    // Examples: one.two.three.four => one.two.three
261    //           one.two.three => one.two
262    private String truncateAppName(String name) {
263        String initiator = name;
264        String[] nameSplit = initiator.split("\\.");
265        if (nameSplit.length > 3) {
266            initiator = nameSplit[0] + "." +
267                        nameSplit[1] + "." +
268                        nameSplit[2];
269        } else if (nameSplit.length == 3) {
270            initiator = nameSplit[0] + "." + nameSplit[1];
271        }
272
273        return initiator;
274    }
275
276    synchronized void dumpToString(StringBuilder sb) {
277        long currTime = SystemClock.elapsedRealtime();
278        long maxScan = maxScanTime;
279        long minScan = minScanTime;
280        long scanDuration = 0;
281
282        if (isScanning()) {
283            scanDuration = currTime - mScanStartTime;
284        }
285        minScan = Math.min(scanDuration, minScan);
286        maxScan = Math.max(scanDuration, maxScan);
287
288        if (minScan == Long.MAX_VALUE) {
289            minScan = 0;
290        }
291
292        long avgScan = 0;
293        long totalScanTime = mTotalScanTime + scanDuration;
294        if (scansStarted > 0) {
295            avgScan = totalScanTime / scansStarted;
296        }
297
298        sb.append("  " + appName);
299        if (isRegistered) sb.append(" (Registered)");
300
301        if (!lastScans.isEmpty()) {
302            LastScan lastScan = lastScans.get(lastScans.size() - 1);
303            if (lastScan.opportunistic) sb.append(" (Opportunistic)");
304            if (lastScan.background) sb.append(" (Background)");
305            if (lastScan.timeout) sb.append(" (Forced-Opportunistic)");
306            if (lastScan.filtered) sb.append(" (Filtered)");
307        }
308        sb.append("\n");
309
310        sb.append("  LE scans (started/stopped)         : " +
311                  scansStarted + " / " +
312                  scansStopped + "\n");
313        sb.append("  Scan time in ms (min/max/avg/total): " +
314                  minScan + " / " +
315                  maxScan + " / " +
316                  avgScan + " / " +
317                  totalScanTime + "\n");
318        if (mTotalSuspendTime != 0) {
319            sb.append("  Total time suspended               : " + mTotalSuspendTime + "ms\n");
320        }
321        sb.append("  Total number of results            : " +
322                  results + "\n");
323
324        long currentTime = System.currentTimeMillis();
325        long elapsedRt = SystemClock.elapsedRealtime();
326        if (!lastScans.isEmpty()) {
327            sb.append("  Last " + lastScans.size() + " scans                       :\n");
328
329            for (int i = 0; i < lastScans.size(); i++) {
330                LastScan scan = lastScans.get(i);
331                Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
332                sb.append("    " + dateFormat.format(timestamp) + " - ");
333                sb.append(scan.duration + "ms ");
334                if (scan.opportunistic) sb.append("Opp ");
335                if (scan.background) sb.append("Back ");
336                if (scan.timeout) sb.append("Forced ");
337                if (scan.filtered) sb.append("Filter ");
338                sb.append(scan.results + " results");
339                sb.append(" (" + scan.scannerId + ")");
340                sb.append("\n");
341                if (scan.suspendDuration != 0) {
342                    sb.append("      └"
343                            + " Suspended Time: " + scan.suspendDuration + "ms\n");
344                }
345            }
346        }
347
348        if (!ongoingScans.isEmpty()) {
349            sb.append("  Ongoing scans                      :\n");
350            for (Integer key : ongoingScans.keySet()) {
351                LastScan scan = ongoingScans.get(key);
352                Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
353                sb.append("    " + dateFormat.format(timestamp) + " - ");
354                sb.append((elapsedRt - scan.timestamp) + "ms ");
355                if (scan.opportunistic) sb.append("Opp ");
356                if (scan.background) sb.append("Back ");
357                if (scan.timeout) sb.append("Forced ");
358                if (scan.filtered) sb.append("Filter ");
359                if (scan.isSuspended) sb.append("Suspended ");
360                sb.append(scan.results + " results");
361                sb.append(" (" + scan.scannerId + ")");
362                sb.append("\n");
363                if (scan.suspendStartTime != 0) {
364                    long duration = scan.suspendDuration
365                            + (scan.isSuspended ? (elapsedRt - scan.suspendStartTime) : 0);
366                    sb.append("      └"
367                            + " Suspended Time: " + duration + "ms\n");
368                }
369            }
370        }
371
372        ContextMap.App appEntry = contextMap.getByName(appName);
373        if (appEntry != null && isRegistered) {
374            sb.append("  Application ID                     : " +
375                      appEntry.id + "\n");
376            sb.append("  UUID                               : " +
377                      appEntry.uuid + "\n");
378
379            List<ContextMap.Connection> connections =
380              contextMap.getConnectionByApp(appEntry.id);
381
382            sb.append("  Connections: " + connections.size() + "\n");
383
384            Iterator<ContextMap.Connection> ii = connections.iterator();
385            while(ii.hasNext()) {
386                ContextMap.Connection connection = ii.next();
387                long connectionTime = SystemClock.elapsedRealtime() - connection.startTime;
388                sb.append("    " + connection.connId + ": " +
389                          connection.address + " " + connectionTime + "ms\n");
390            }
391        }
392        sb.append("\n");
393    }
394}
395