Bluetooth: track enabling in dumpsys

Move basic state dumpsys to here from AdapterService.

Track which apps are enabling and disabling Bluetooth, including BLE
apps, and show the apps in the dumpsys logs.

Test: start phone and enable/disable, take bug report
Bug: 33692282
Change-Id: I6ea62ebdcfd7873d0be1bb5c5c520bbce3737a40
(cherry picked from commit 5980456040217f330289e3fa59df4efaafb1c6c5)
diff --git a/core/java/android/bluetooth/BluetoothAdapter.java b/core/java/android/bluetooth/BluetoothAdapter.java
index 5ced03b..e04f1e1 100644
--- a/core/java/android/bluetooth/BluetoothAdapter.java
+++ b/core/java/android/bluetooth/BluetoothAdapter.java
@@ -684,30 +684,7 @@
     }
 
     /**
-     * Performs action based on user action to turn BT ON
-     * or OFF if BT is in BLE_ON state
-     */
-    private void notifyUserAction(boolean enable) {
-        try {
-            mServiceLock.readLock().lock();
-            if (mService == null) {
-                Log.e(TAG, "mService is null");
-                return;
-            }
-            if (enable) {
-                mService.onLeServiceUp(); //NA:TODO implementation pending
-            } else {
-                mService.onBrEdrDown(); //NA:TODO implementation pending
-            }
-        } catch (RemoteException e) {
-            Log.e(TAG, "", e);
-        } finally {
-            mServiceLock.readLock().unlock();
-        }
-    }
-
-    /**
-     * Turns off Bluetooth LE which was earlier turned on by calling EnableBLE().
+     * Turns off Bluetooth LE which was earlier turned on by calling enableBLE().
      *
      * <p> If the internal Adapter state is STATE_BLE_ON, this would trigger the transition
      * to STATE_OFF and completely shut-down Bluetooth
@@ -737,61 +714,50 @@
         if (!isBleScanAlwaysAvailable()) return false;
 
         int state = getLeState();
-        if (state == BluetoothAdapter.STATE_ON) {
-            if (DBG) Log.d (TAG, "STATE_ON: shouldn't disable");
+        if (state == BluetoothAdapter.STATE_ON || state == BluetoothAdapter.STATE_BLE_ON) {
+            String packageName = ActivityThread.currentPackageName();
+            if (DBG) Log.d (TAG, "disableBLE(): de-registering " + packageName);
             try {
-                mManagerService.updateBleAppCount(mToken, false);
+                mManagerService.updateBleAppCount(mToken, false, packageName);
             } catch (RemoteException e) {
                 Log.e(TAG, "", e);
             }
             return true;
-
-        } else if (state == BluetoothAdapter.STATE_BLE_ON) {
-            if (DBG) Log.d (TAG, "STATE_BLE_ON");
-            int bleAppCnt = 0;
-            try {
-                bleAppCnt = mManagerService.updateBleAppCount(mToken, false);
-            } catch (RemoteException e) {
-                Log.e(TAG, "", e);
-            }
-            if (bleAppCnt == 0) {
-                // Disable only if there are no other clients
-                notifyUserAction(false);
-            }
-            return true;
         }
 
-        if (DBG) Log.d (TAG, "STATE_OFF: Already disabled");
+        if (DBG) Log.d (TAG, "disableBLE(): Already disabled");
         return false;
     }
 
     /**
-     * Special Applications who want to only turn on Bluetooth Low Energy (BLE) would
-     * EnableBLE, EnableBLE brings-up Bluetooth so that application can access
-     * only LE related feature (Bluetooth GATT layers interfaces using the respective class)
-     * EnableBLE in turn registers the existance of a special App which wants to
-     * turn on Bluetooth Low enrgy part without making it visible at the settings UI
-     * as Bluetooth ON.
-     * <p>Invoking EnableBLE when Bluetooth is already in ON state, would just registers
-     * the existance of special Application and doesn't do anything to current BT state.
-     * when user turn OFF Bluetooth from UI, if there is an existance of special app, Bluetooth
-     * would stay in BLE_ON state so that LE features are still acessible to the special
-     * Applications.
+     * Applications who want to only use Bluetooth Low Energy (BLE) can call enableBLE.
      *
-     * <p>This is an asynchronous call: it will return immediately, and
+     * enableBLE registers the existence of an app using only LE functions.
+     *
+     * enableBLE may enable Bluetooth to an LE only mode so that an app can use
+     * LE related features (BluetoothGatt or BluetoothGattServer classes)
+     *
+     * If the user disables Bluetooth while an app is registered to use LE only features,
+     * Bluetooth will remain on in LE only mode for the app.
+     *
+     * When Bluetooth is in LE only mode, it is not shown as ON to the UI.
+     *
+     * <p>This is an asynchronous call: it returns immediately, and
      * clients should listen for {@link #ACTION_BLE_STATE_CHANGED}
-     * to be notified of subsequent adapter state changes. If this call returns
-     * true, then the adapter state will immediately transition from {@link
-     * #STATE_OFF} to {@link #STATE_BLE_TURNING_ON}, and some time
-     * later transition to either {@link #STATE_OFF} or {@link
-     * #STATE_BLE_ON}. If this call returns false then there was an
-     * immediate problem that will prevent the adapter from being turned on -
-     * such as Airplane mode, or the adapter is already turned on.
-     * (@link #ACTION_BLE_STATE_CHANGED) returns the Bluetooth Adapter's various
+     * to be notified of adapter state changes.
+     *
+     * If this call returns * true, then the adapter state is either in a mode where
+     * LE is available, or will transition from {@link #STATE_OFF} to {@link #STATE_BLE_TURNING_ON},
+     * and some time later transition to either {@link #STATE_OFF} or {@link #STATE_BLE_ON}.
+     *
+     * If this call returns false then there was an immediate problem that prevents the
+     * adapter from being turned on - such as Airplane mode.
+     *
+     * {@link #ACTION_BLE_STATE_CHANGED} returns the Bluetooth Adapter's various
      * states, It includes all the classic Bluetooth Adapter states along with
      * internal BLE only states
      *
-     * @return true to indicate Bluetooth LE start-up has begun, or false on
+     * @return true to indicate Bluetooth LE will be available, or false on
      *         immediate error
      * @hide
      */
@@ -800,13 +766,14 @@
         if (!isBleScanAlwaysAvailable()) return false;
 
         try {
-            mManagerService.updateBleAppCount(mToken, true);
+            String packageName = ActivityThread.currentPackageName();
+            mManagerService.updateBleAppCount(mToken, true, packageName);
             if (isLeEnabled()) {
                 if (DBG) Log.d(TAG, "enableBLE(): Bluetooth already enabled");
                 return true;
             }
             if (DBG) Log.d(TAG, "enableBLE(): Calling enable");
-            return mManagerService.enable(ActivityThread.currentPackageName());
+            return mManagerService.enable(packageName);
         } catch (RemoteException e) {
             Log.e(TAG, "", e);
         }
@@ -2102,7 +2069,7 @@
             return true;
         }
         try {
-            return mManagerService.enableNoAutoConnect();
+            return mManagerService.enableNoAutoConnect(ActivityThread.currentPackageName());
         } catch (RemoteException e) {Log.e(TAG, "", e);}
         return false;
     }
diff --git a/core/java/android/bluetooth/IBluetoothManager.aidl b/core/java/android/bluetooth/IBluetoothManager.aidl
index 90f0085..5afd774 100644
--- a/core/java/android/bluetooth/IBluetoothManager.aidl
+++ b/core/java/android/bluetooth/IBluetoothManager.aidl
@@ -35,7 +35,7 @@
     void unregisterStateChangeCallback(in IBluetoothStateChangeCallback callback);
     boolean isEnabled();
     boolean enable(String packageName);
-    boolean enableNoAutoConnect();
+    boolean enableNoAutoConnect(String packageName);
     boolean disable(String packageName, boolean persist);
     int getState();
     IBluetoothGatt getBluetoothGatt();
@@ -47,6 +47,6 @@
     String getName();
 
     boolean isBleScanAlwaysAvailable();
-    int updateBleAppCount(IBinder b, boolean enable);
+    int updateBleAppCount(IBinder b, boolean enable, String packageName);
     boolean isBleAppPresent();
 }
diff --git a/services/core/java/com/android/server/BluetoothManagerService.java b/services/core/java/com/android/server/BluetoothManagerService.java
index 2682cd1..677d378 100644
--- a/services/core/java/com/android/server/BluetoothManagerService.java
+++ b/services/core/java/com/android/server/BluetoothManagerService.java
@@ -54,14 +54,16 @@
 import android.provider.Settings;
 import android.provider.Settings.SettingNotFoundException;
 import android.util.Slog;
-import java.util.concurrent.locks.ReentrantReadWriteLock;
 
 import java.io.FileDescriptor;
 import java.io.PrintWriter;
 import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.locks.ReentrantReadWriteLock;
 import java.util.HashMap;
+import java.util.LinkedList;
 import java.util.Map;
 
+
 class BluetoothManagerService extends IBluetoothManager.Stub {
     private static final String TAG = "BluetoothManagerService";
     private static final boolean DBG = true;
@@ -134,16 +136,46 @@
         new ReentrantReadWriteLock();
     private boolean mBinding;
     private boolean mUnbinding;
+
     // used inside handler thread
     private boolean mQuietEnable = false;
-    // configuarion from external IBinder call which is used to
+    private boolean mEnable;
+
+    /**
+     * Used for tracking apps that enabled / disabled Bluetooth.
+     */
+    private class ActiveLog {
+        private String mPackageName;
+        private boolean mEnable;
+        private long mTimestamp;
+
+        public ActiveLog(String packageName, boolean enable, long timestamp) {
+            mPackageName = packageName;
+            mEnable = enable;
+            mTimestamp = timestamp;
+        }
+
+        public long getTime() {
+            return mTimestamp;
+        }
+
+        public String toString() {
+            return android.text.format.DateFormat.format("MM-dd hh:mm:ss ", mTimestamp) +
+                    (mEnable ? "  Enabled " : " Disabled ") + " by " + mPackageName;
+        }
+
+    }
+
+    private LinkedList<ActiveLog> mActiveLogs;
+
+    // configuration from external IBinder call which is used to
     // synchronize with broadcast receiver.
     private boolean mQuietEnableExternal;
-    // configuarion from external IBinder call which is used to
-    // synchronize with broadcast receiver.
     private boolean mEnableExternal;
-    // used inside handler thread
-    private boolean mEnable;
+
+    // Map of apps registered to keep BLE scanning on.
+    private Map<IBinder, ClientDeathRecipient> mBleApps = new ConcurrentHashMap<IBinder, ClientDeathRecipient>();
+
     private int mState;
     private final BluetoothHandler mHandler;
     private int mErrorRecoveryRetryCounter;
@@ -169,7 +201,7 @@
         }
     }
 
-    private final IBluetoothCallback mBluetoothCallback =  new IBluetoothCallback.Stub() {
+    private final IBluetoothCallback mBluetoothCallback = new IBluetoothCallback.Stub() {
         @Override
         public void onBluetoothStateChange(int prevState, int newState) throws RemoteException  {
             Message msg = mHandler.obtainMessage(MESSAGE_BLUETOOTH_STATE_CHANGE,prevState,newState);
@@ -230,12 +262,12 @@
                         } else if (st == BluetoothAdapter.STATE_ON){
                             // disable without persisting the setting
                             Slog.d(TAG, "Calling disable");
-                            sendDisableMsg();
+                            sendDisableMsg("airplane mode");
                         }
                     } else if (mEnableExternal) {
                         // enable without persisting the setting
                         Slog.d(TAG, "Calling enable");
-                        sendEnableMsg(mQuietEnableExternal);
+                        sendEnableMsg(mQuietEnableExternal, "airplane mode");
                     }
                 }
             }
@@ -251,6 +283,7 @@
                     || context.getResources().getBoolean(
                 com.android.internal.R.bool.config_permissionReviewRequired);
 
+        mActiveLogs = new LinkedList<ActiveLog>();
         mBluetooth = null;
         mBluetoothBinder = null;
         mBluetoothGatt = null;
@@ -278,15 +311,15 @@
             mEnableExternal = true;
         }
 
-        int sysUiUid = -1;
+        int systemUiUid = -1;
         try {
-            sysUiUid = mContext.getPackageManager().getPackageUidAsUser("com.android.systemui",
+            systemUiUid = mContext.getPackageManager().getPackageUidAsUser("com.android.systemui",
                     PackageManager.MATCH_SYSTEM_ONLY, UserHandle.USER_SYSTEM);
         } catch (PackageManager.NameNotFoundException e) {
             // Some platforms, such as wearables do not have a system ui.
             Slog.w(TAG, "Unable to resolve SystemUI's UID.", e);
         }
-        mSystemUiUid = sysUiUid;
+        mSystemUiUid = systemUiUid;
     }
 
     /**
@@ -466,8 +499,14 @@
     }
 
     class ClientDeathRecipient implements IBinder.DeathRecipient {
+        private String mPackageName;
+
+        public ClientDeathRecipient(String packageName) {
+            mPackageName = packageName;
+        }
+
         public void binderDied() {
-            if (DBG) Slog.d(TAG, "Binder is dead - unregister Ble App");
+            if (DBG) Slog.d(TAG, "Binder is dead - unregister " + mPackageName);
             if (isBleAppPresent()) {
               // Nothing to do, another app is here.
               return;
@@ -486,10 +525,11 @@
                 mBluetoothLock.readLock().unlock();
             }
         }
-    }
 
-    /** Internal death rec list */
-    Map<IBinder, ClientDeathRecipient> mBleApps = new ConcurrentHashMap<IBinder, ClientDeathRecipient>();
+        public String getPackageName() {
+            return mPackageName;
+        }
+    }
 
     @Override
     public boolean isBleScanAlwaysAvailable() {
@@ -547,28 +587,22 @@
         }
     }
 
-    public int updateBleAppCount(IBinder token, boolean enable) {
-        if (enable) {
-            ClientDeathRecipient r = mBleApps.get(token);
-            if (r == null) {
-                ClientDeathRecipient deathRec = new ClientDeathRecipient();
-                try {
-                    token.linkToDeath(deathRec, 0);
-                } catch (RemoteException ex) {
-                    throw new IllegalArgumentException("Wake lock is already dead.");
-                }
-                mBleApps.put(token, deathRec);
-                if (DBG) Slog.d(TAG, "Registered for death Notification");
+    public int updateBleAppCount(IBinder token, boolean enable, String packageName) {
+        ClientDeathRecipient r = mBleApps.get(token);
+        if (r == null && enable) {
+            ClientDeathRecipient deathRec = new ClientDeathRecipient(packageName);
+            try {
+                token.linkToDeath(deathRec, 0);
+            } catch (RemoteException ex) {
+                throw new IllegalArgumentException("BLE app (" + packageName + ") already dead!");
             }
-
-        } else  {
-            ClientDeathRecipient r = mBleApps.get(token);
-            if (r != null) {
-                // Unregister death recipient as the app goes away.
-                token.unlinkToDeath(r, 0);
-                mBleApps.remove(token);
-                if (DBG) Slog.d(TAG, "Unregistered for death Notification");
-            }
+            mBleApps.put(token, deathRec);
+            if (DBG) Slog.d(TAG, "Registered for death of " + packageName);
+        } else if (!enable && r != null) {
+            // Unregister death recipient as the app goes away.
+            token.unlinkToDeath(r, 0);
+            mBleApps.remove(token);
+            if (DBG) Slog.d(TAG, "Unregistered for death of " + packageName);
         }
         int appCount = mBleApps.size();
         if (DBG) Slog.d(TAG, appCount + " registered Ble Apps");
@@ -583,7 +617,7 @@
         mBleApps.clear();
     }
 
-    /** @hide*/
+    /** @hide */
     public boolean isBleAppPresent() {
         if (DBG) Slog.d(TAG, "isBleAppPresent() count: " + mBleApps.size());
         return mBleApps.size() > 0;
@@ -649,7 +683,7 @@
         }
     }
 
-    public boolean enableNoAutoConnect()
+    public boolean enableNoAutoConnect(String packageName)
     {
         mContext.enforceCallingOrSelfPermission(BLUETOOTH_ADMIN_PERM,
                                                 "Need BLUETOOTH ADMIN permission");
@@ -667,7 +701,7 @@
         synchronized(mReceiver) {
             mQuietEnableExternal = true;
             mEnableExternal = true;
-            sendEnableMsg(true);
+            sendEnableMsg(true, packageName);
         }
         return true;
     }
@@ -692,7 +726,7 @@
         }
 
         if (DBG) {
-            Slog.d(TAG,"enable():  mBluetooth =" + mBluetooth +
+            Slog.d(TAG,"enable(" + packageName + "):  mBluetooth =" + mBluetooth +
                     " mBinding = " + mBinding + " mState = " +
                     BluetoothAdapter.nameForState(mState));
         }
@@ -701,7 +735,7 @@
             mQuietEnableExternal = false;
             mEnableExternal = true;
             // waive WRITE_SECURE_SETTINGS permission check
-            sendEnableMsg(false);
+            sendEnableMsg(false, packageName);
         }
         if (DBG) Slog.d(TAG, "enable returning");
         return true;
@@ -736,7 +770,7 @@
                 persistBluetoothSetting(BLUETOOTH_OFF);
             }
             mEnableExternal = false;
-            sendDisableMsg();
+            sendDisableMsg(packageName);
         }
         return true;
     }
@@ -871,7 +905,7 @@
         if (DBG) Slog.d(TAG, "Bluetooth boot completed");
         if (mEnableExternal && isBluetoothPersistedStateOnBluetooth()) {
             if (DBG) Slog.d(TAG, "Auto-enabling Bluetooth.");
-            sendEnableMsg(mQuietEnableExternal);
+            sendEnableMsg(mQuietEnableExternal, "system boot");
         } else if (!isNameAndAddressSet()) {
             if (DBG) Slog.d(TAG, "Getting adapter name and address");
             Message getMsg = mHandler.obtainMessage(MESSAGE_GET_NAME_AND_ADDRESS);
@@ -1839,13 +1873,24 @@
         return false;
     }
 
-    private void sendDisableMsg() {
+    private void sendDisableMsg(String packageName) {
         mHandler.sendMessage(mHandler.obtainMessage(MESSAGE_DISABLE));
+        addActiveLog(packageName, false);
     }
 
-    private void sendEnableMsg(boolean quietMode) {
+    private void sendEnableMsg(boolean quietMode, String packageName) {
         mHandler.sendMessage(mHandler.obtainMessage(MESSAGE_ENABLE,
                              quietMode ? 1 : 0, 0));
+        addActiveLog(packageName, true);
+    }
+
+    private void addActiveLog(String packageName, boolean enable) {
+        synchronized (mActiveLogs) {
+            if (mActiveLogs.size() > 10) {
+                mActiveLogs.remove();
+            }
+            mActiveLogs.add(new ActiveLog(packageName, enable, System.currentTimeMillis()));
+        }
     }
 
     private void recoverBluetoothServiceFromError(boolean clearBle) {
@@ -1906,19 +1951,50 @@
     public void dump(FileDescriptor fd, PrintWriter writer, String[] args) {
         mContext.enforceCallingOrSelfPermission(android.Manifest.permission.DUMP, TAG);
         String errorMsg = null;
+
+        boolean protoOut = (args.length > 0) && args[0].startsWith("--proto");
+
+        if (!protoOut) {
+            writer.println("Bluetooth Status");
+            writer.println("  enabled: " + isEnabled());
+            writer.println("  state: " + BluetoothAdapter.nameForState(mState));
+            writer.println("  address: " + mAddress);
+            writer.println("  name: " + mName);
+            if (mEnable) {
+                long onDuration = System.currentTimeMillis() - mActiveLogs.getLast().getTime();
+                String onDurationString = String.format("%02d:%02d:%02d.%03d",
+                                          (int)(onDuration / (1000 * 60 * 60)),
+                                          (int)((onDuration / (1000 * 60)) % 60),
+                                          (int)((onDuration / 1000) % 60),
+                                          (int)(onDuration % 1000));
+                writer.println("  time since enabled: " + onDurationString + "\n");
+            }
+
+            writer.println("Enable log:");
+            for (ActiveLog log : mActiveLogs) {
+                writer.println(log);
+            }
+
+            writer.println("\n" + mBleApps.size() + " BLE Apps registered:");
+            for (ClientDeathRecipient app : mBleApps.values()) {
+                writer.println(app.getPackageName());
+            }
+
+            writer.flush();
+        }
+
         if (mBluetoothBinder == null) {
             errorMsg = "Bluetooth Service not connected";
         } else {
             try {
                 mBluetoothBinder.dump(fd, args);
             } catch (RemoteException re) {
-                errorMsg = "RemoteException while calling Bluetooth Service";
+                errorMsg = "RemoteException while dumping Bluetooth Service";
             }
         }
         if (errorMsg != null) {
             // Silently return if we are extracting metrics in Protobuf format
-            if ((args.length > 0) && args[0].startsWith("--proto"))
-                return;
+            if (protoOut) return;
             writer.println(errorMsg);
         }
     }