Merge "WifiService: Logging changes" into pi-dev

1 files changed, 85 insertions, 30 deletions

diff --git a/service/java/com/android/server/wifi/WifiServiceImpl.java b/service/java/com/android/server/wifi/WifiServiceImpl.java
index 49f00f88f..e0d839bb3 100644
--- a/service/java/com/android/server/wifi/WifiServiceImpl.java
+++ b/service/java/com/android/server/wifi/WifiServiceImpl.java
@@ -135,7 +135,6 @@ import java.util.concurrent.ConcurrentHashMap;
  */
 public class WifiServiceImpl extends IWifiManager.Stub {
     private static final String TAG = "WifiService";
-    private static final boolean DBG = true;
     private static final boolean VDBG = false;
 
     // Default scan background throttling interval if not overriden in settings
@@ -175,6 +174,10 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     private final WifiBackupRestore mWifiBackupRestore;
 
     private WifiLog mLog;
+    /**
+     * Verbose logging flag. Toggled by developer options.
+     */
+    private boolean mVerboseLoggingEnabled = false;
 
     /**
      * Asynchronous channel to WifiStateMachine
@@ -250,7 +253,7 @@ public class WifiServiceImpl extends IWifiManager.Stub {
             switch (msg.what) {
                 case AsyncChannel.CMD_CHANNEL_HALF_CONNECTED: {
                     if (msg.arg1 == AsyncChannel.STATUS_SUCCESSFUL) {
-                        if (DBG) Slog.d(TAG, "New client listening to asynchronous messages");
+                        Slog.d(TAG, "New client listening to asynchronous messages");
                         // We track the clients by the Messenger
                         // since it is expected to be always available
                         mTrafficPoller.addClient(msg.replyTo);
@@ -261,9 +264,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
                 }
                 case AsyncChannel.CMD_CHANNEL_DISCONNECTED: {
                     if (msg.arg1 == AsyncChannel.STATUS_SEND_UNSUCCESSFUL) {
-                        if (DBG) Slog.d(TAG, "Send failed, client connection lost");
+                        Slog.w(TAG, "Send failed, client connection lost");
                     } else {
-                        if (DBG) Slog.d(TAG, "Client connection lost with reason: " + msg.arg1);
+                        Slog.w(TAG, "Client connection lost with reason: " + msg.arg1);
                     }
                     mTrafficPoller.removeClient(msg.replyTo);
                     break;
@@ -280,16 +283,15 @@ public class WifiServiceImpl extends IWifiManager.Stub {
                         int networkId = msg.arg1;
                         Slog.d(TAG, "CONNECT "
                                 + " nid=" + Integer.toString(networkId)
+                                + " config=" + config
                                 + " uid=" + msg.sendingUid
                                 + " name="
                                 + mContext.getPackageManager().getNameForUid(msg.sendingUid));
                         if (config != null) {
-                            if (DBG) Slog.d(TAG, "Connect with config " + config);
                             /* Command is forwarded to state machine */
                             mWifiStateMachine.sendMessage(Message.obtain(msg));
                         } else if (config == null
                                 && networkId != WifiConfiguration.INVALID_NETWORK_ID) {
-                            if (DBG) Slog.d(TAG, "Connect with networkId " + networkId);
                             mWifiStateMachine.sendMessage(Message.obtain(msg));
                         } else {
                             Slog.e(TAG, "ClientHandler.handleMessage ignoring invalid msg=" + msg);
@@ -306,11 +308,11 @@ public class WifiServiceImpl extends IWifiManager.Stub {
                         int networkId = msg.arg1;
                         Slog.d(TAG, "SAVE"
                                 + " nid=" + Integer.toString(networkId)
+                                + " config=" + config
                                 + " uid=" + msg.sendingUid
                                 + " name="
                                 + mContext.getPackageManager().getNameForUid(msg.sendingUid));
                         if (config != null) {
-                            if (DBG) Slog.d(TAG, "Save network with config " + config);
                             /* Command is forwarded to state machine */
                             mWifiStateMachine.sendMessage(Message.obtain(msg));
                         } else {
@@ -660,8 +662,10 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     public String getCurrentNetworkWpsNfcConfigurationToken() {
         // while CLs are in flight, return null here, will be removed (b/72423090)
         enforceConnectivityInternalPermission();
-        mLog.info("getCurrentNetworkWpsNfcConfigurationToken uid=%")
-                .c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getCurrentNetworkWpsNfcConfigurationToken uid=%")
+                    .c(Binder.getCallingUid()).flush();
+        }
         return null;
     }
 
@@ -862,7 +866,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public int getWifiEnabledState() {
         enforceAccessPermission();
-        mLog.info("getWifiEnabledState uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getWifiEnabledState uid=%").c(Binder.getCallingUid()).flush();
+        }
         return mWifiStateMachine.syncGetWifiState();
     }
 
@@ -877,7 +883,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public int getWifiApEnabledState() {
         enforceAccessPermission();
-        mLog.info("getWifiApEnabledState uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getWifiApEnabledState uid=%").c(Binder.getCallingUid()).flush();
+        }
 
         // hand off work to our handler thread
         MutableInt apState = new MutableInt(WifiManager.WIFI_AP_STATE_DISABLED);
@@ -903,6 +911,7 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     public void updateInterfaceIpState(String ifaceName, int mode) {
         // NETWORK_STACK is a signature only permission.
         enforceNetworkStackPermission();
+        mLog.info("updateInterfaceIpState uid=%").c(Binder.getCallingUid()).flush();
 
         // hand off the work to our handler thread
         mClientHandler.post(() -> {
@@ -1120,6 +1129,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
         }
 
         enforceNetworkSettingsPermission();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("registerSoftApCallback uid=%").c(Binder.getCallingUid()).flush();
+        }
 
         // register for binder death
         IBinder.DeathRecipient dr = new IBinder.DeathRecipient() {
@@ -1170,6 +1182,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     public void unregisterSoftApCallback(int callbackIdentifier) {
 
         enforceNetworkSettingsPermission();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("unregisterSoftApCallback uid=%").c(Binder.getCallingUid()).flush();
+        }
 
         // post operation to handler thread
         mClientHandler.post(() -> {
@@ -1552,7 +1567,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public boolean isScanAlwaysAvailable() {
         enforceAccessPermission();
-        mLog.info("isScanAlwaysAvailable uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("isScanAlwaysAvailable uid=%").c(Binder.getCallingUid()).flush();
+        }
         return mSettingsStore.isScanAlwaysAvailable();
     }
 
@@ -1598,7 +1615,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public int getSupportedFeatures() {
         enforceAccessPermission();
-        mLog.info("getSupportedFeatures uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getSupportedFeatures uid=%").c(Binder.getCallingUid()).flush();
+        }
         if (mWifiStateMachineChannel != null) {
             return mWifiStateMachine.syncGetSupportedFeatures(mWifiStateMachineChannel);
         } else {
@@ -1610,7 +1629,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public void requestActivityInfo(ResultReceiver result) {
         Bundle bundle = new Bundle();
-        mLog.info("requestActivityInfo uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("requestActivityInfo uid=%").c(Binder.getCallingUid()).flush();
+        }
         bundle.putParcelable(BatteryStats.RESULT_RECEIVER_CONTROLLER_KEY, reportActivityInfo());
         result.send(0, bundle);
     }
@@ -1621,7 +1642,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public WifiActivityEnergyInfo reportActivityInfo() {
         enforceAccessPermission();
-        mLog.info("reportActivityInfo uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("reportActivityInfo uid=%").c(Binder.getCallingUid()).flush();
+        }
         if ((getSupportedFeatures() & WifiManager.WIFI_FEATURE_LINK_LAYER_STATS) == 0) {
             return null;
         }
@@ -1693,7 +1716,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public ParceledListSlice<WifiConfiguration> getConfiguredNetworks() {
         enforceAccessPermission();
-        mLog.info("getConfiguredNetworks uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getConfiguredNetworks uid=%").c(Binder.getCallingUid()).flush();
+        }
         if (mWifiStateMachineChannel != null) {
             List<WifiConfiguration> configs = mWifiStateMachine.syncGetConfiguredNetworks(
                     Binder.getCallingUid(), mWifiStateMachineChannel);
@@ -1714,7 +1739,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     public ParceledListSlice<WifiConfiguration> getPrivilegedConfiguredNetworks() {
         enforceReadCredentialPermission();
         enforceAccessPermission();
-        mLog.info("getPrivilegedConfiguredNetworks uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getPrivilegedConfiguredNetworks uid=%").c(Binder.getCallingUid()).flush();
+        }
         if (mWifiStateMachineChannel != null) {
             List<WifiConfiguration> configs =
                     mWifiStateMachine.syncGetPrivilegedConfiguredNetwork(mWifiStateMachineChannel);
@@ -1736,7 +1763,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public WifiConfiguration getMatchingWifiConfig(ScanResult scanResult) {
         enforceAccessPermission();
-        mLog.info("getMatchingWifiConfig uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getMatchingWifiConfig uid=%").c(Binder.getCallingUid()).flush();
+        }
         if (!mContext.getPackageManager().hasSystemFeature(
                 PackageManager.FEATURE_WIFI_PASSPOINT)) {
             throw new UnsupportedOperationException("Passpoint not enabled");
@@ -1756,7 +1785,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public List<WifiConfiguration> getAllMatchingWifiConfigs(ScanResult scanResult) {
         enforceAccessPermission();
-        mLog.info("getMatchingPasspointConfigurations uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getMatchingPasspointConfigurations uid=%").c(Binder.getCallingUid()).flush();
+        }
         if (!mContext.getPackageManager().hasSystemFeature(
                 PackageManager.FEATURE_WIFI_PASSPOINT)) {
             throw new UnsupportedOperationException("Passpoint not enabled");
@@ -1773,7 +1804,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public List<OsuProvider> getMatchingOsuProviders(ScanResult scanResult) {
         enforceAccessPermission();
-        mLog.info("getMatchingOsuProviders uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getMatchingOsuProviders uid=%").c(Binder.getCallingUid()).flush();
+        }
         if (!mContext.getPackageManager().hasSystemFeature(
                 PackageManager.FEATURE_WIFI_PASSPOINT)) {
             throw new UnsupportedOperationException("Passpoint not enabled");
@@ -1930,7 +1963,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     public WifiInfo getConnectionInfo(String callingPackage) {
         enforceAccessPermission();
         int uid = Binder.getCallingUid();
-        mLog.info("getConnectionInfo uid=%").c(uid).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getConnectionInfo uid=%").c(uid).flush();
+        }
         long ident = Binder.clearCallingIdentity();
         try {
             WifiInfo result = mWifiStateMachine.syncRequestConnectionInfo();
@@ -1947,8 +1982,6 @@ public class WifiServiceImpl extends IWifiManager.Stub {
             } catch (RemoteException e) {
                 Log.e(TAG, "Error checking receiver permission", e);
             } catch (SecurityException e) {
-                Log.e(TAG, "Security exception checking receiver permission"
-                        + ", hiding ssid and bssid", e);
             }
             if (hideDefaultMacAddress) {
                 result.setMacAddress(WifiInfo.DEFAULT_MAC_ADDRESS);
@@ -1957,6 +1990,10 @@ public class WifiServiceImpl extends IWifiManager.Stub {
                 result.setBSSID(WifiInfo.DEFAULT_MAC_ADDRESS);
                 result.setSSID(WifiSsid.createFromHex(null));
             }
+            if (mVerboseLoggingEnabled && (hideBssidAndSsid || hideDefaultMacAddress)) {
+                mLog.v("getConnectionInfo: hideBssidAndSSid=" + hideBssidAndSsid
+                        + ", hideDefaultMacAddress=" + hideDefaultMacAddress);
+            }
             return result;
         } finally {
             Binder.restoreCallingIdentity(ident);
@@ -1973,6 +2010,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
         enforceAccessPermission();
         int uid = Binder.getCallingUid();
         long ident = Binder.clearCallingIdentity();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getScanResults uid=%").c(uid).flush();
+        }
         try {
             mWifiPermissionsUtil.enforceCanAccessScanResults(callingPackage, uid);
             final List<ScanResult> scanResults = new ArrayList<>();
@@ -2040,7 +2080,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public List<PasspointConfiguration> getPasspointConfigurations() {
         enforceAccessPermission();
-        mLog.info("getPasspointConfigurations uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getPasspointConfigurations uid=%").c(Binder.getCallingUid()).flush();
+        }
         if (!mContext.getPackageManager().hasSystemFeature(
                 PackageManager.FEATURE_WIFI_PASSPOINT)) {
             throw new UnsupportedOperationException("Passpoint not enabled");
@@ -2110,7 +2152,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public String getCountryCode() {
         enforceConnectivityInternalPermission();
-        mLog.info("getCountryCode uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getCountryCode uid=%").c(Binder.getCallingUid()).flush();
+        }
         String country = mCountryCode.getCountryCode();
         return country;
     }
@@ -2118,7 +2162,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public boolean isDualBandSupported() {
         //TODO: Should move towards adding a driver API that checks at runtime
-        mLog.info("isDualBandSupported uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("isDualBandSupported uid=%").c(Binder.getCallingUid()).flush();
+        }
         return mContext.getResources().getBoolean(
                 com.android.internal.R.bool.config_wifi_dual_band_support);
     }
@@ -2133,7 +2179,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Deprecated
     public DhcpInfo getDhcpInfo() {
         enforceAccessPermission();
-        mLog.info("getDhcpInfo uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getDhcpInfo uid=%").c(Binder.getCallingUid()).flush();
+        }
         DhcpResults dhcpResults = mWifiStateMachine.syncGetDhcpResults();
 
         DhcpInfo info = new DhcpInfo();
@@ -2522,7 +2570,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public boolean isMulticastEnabled() {
         enforceAccessPermission();
-        mLog.info("isMulticastEnabled uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("isMulticastEnabled uid=%").c(Binder.getCallingUid()).flush();
+        }
         return mWifiMulticastLockManager.isMulticastEnabled();
     }
 
@@ -2539,6 +2589,7 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     }
 
     void enableVerboseLoggingInternal(int verbose) {
+        mVerboseLoggingEnabled = verbose > 0;
         mWifiStateMachine.enableVerboseLogging(verbose);
         mWifiLockManager.enableVerboseLogging(verbose);
         mWifiMulticastLockManager.enableVerboseLogging(verbose);
@@ -2548,7 +2599,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public int getVerboseLoggingLevel() {
         enforceAccessPermission();
-        mLog.info("getVerboseLoggingLevel uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getVerboseLoggingLevel uid=%").c(Binder.getCallingUid()).flush();
+        }
         return mFacade.getIntegerSetting(
                 mContext, Settings.Global.WIFI_VERBOSE_LOGGING_ENABLED, 0);
     }
@@ -2593,7 +2646,9 @@ public class WifiServiceImpl extends IWifiManager.Stub {
     @Override
     public Network getCurrentNetwork() {
         enforceAccessPermission();
-        mLog.info("getCurrentNetwork uid=%").c(Binder.getCallingUid()).flush();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("getCurrentNetwork uid=%").c(Binder.getCallingUid()).flush();
+        }
         return mWifiStateMachine.getCurrentNetwork();
     }