WifiService: Logging changes

a) Remove the static |DBG| flag from WifiServiceImpl and move to dynamic
verbose logging control.
b) Move all the simple getter API trace logs to under verbose logging
flag.
c) Added missing trace logs for a couple of API's.

Bug: 77526141
Bug: 73160471
Test: Verified the logs with/without developer option turned on.
Change-Id: I6fd089bda85ac1a84ba4fb9a5a0c79fab2e47c6d
diff --git a/service/java/com/android/server/wifi/WifiServiceImpl.java b/service/java/com/android/server/wifi/WifiServiceImpl.java
index 7d6c109..3dd6834 100644
--- a/service/java/com/android/server/wifi/WifiServiceImpl.java
+++ b/service/java/com/android/server/wifi/WifiServiceImpl.java
@@ -135,7 +135,6 @@
  */
 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 @@
     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 @@
             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 @@
                 }
                 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 @@
                         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 @@
                         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 {
@@ -661,8 +663,10 @@
     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;
     }
 
@@ -863,7 +867,9 @@
     @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();
     }
 
@@ -878,7 +884,9 @@
     @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);
@@ -904,6 +912,7 @@
     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(() -> {
@@ -1121,6 +1130,9 @@
         }
 
         enforceNetworkSettingsPermission();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("registerSoftApCallback uid=%").c(Binder.getCallingUid()).flush();
+        }
 
         // register for binder death
         IBinder.DeathRecipient dr = new IBinder.DeathRecipient() {
@@ -1171,6 +1183,9 @@
     public void unregisterSoftApCallback(int callbackIdentifier) {
 
         enforceNetworkSettingsPermission();
+        if (mVerboseLoggingEnabled) {
+            mLog.info("unregisterSoftApCallback uid=%").c(Binder.getCallingUid()).flush();
+        }
 
         // post operation to handler thread
         mClientHandler.post(() -> {
@@ -1553,7 +1568,9 @@
     @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();
     }
 
@@ -1599,7 +1616,9 @@
     @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 {
@@ -1611,7 +1630,9 @@
     @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);
     }
@@ -1622,7 +1643,9 @@
     @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;
         }
@@ -1694,7 +1717,9 @@
     @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);
@@ -1715,7 +1740,9 @@
     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);
@@ -1737,7 +1764,9 @@
     @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");
@@ -1757,7 +1786,9 @@
     @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");
@@ -1774,7 +1805,9 @@
     @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");
@@ -1931,7 +1964,9 @@
     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();
@@ -1948,8 +1983,6 @@
             } 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);
@@ -1958,6 +1991,10 @@
                 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);
@@ -1974,6 +2011,9 @@
         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<>();
@@ -2041,7 +2081,9 @@
     @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");
@@ -2111,7 +2153,9 @@
     @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;
     }
@@ -2119,7 +2163,9 @@
     @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);
     }
@@ -2134,7 +2180,9 @@
     @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();
@@ -2532,7 +2580,9 @@
     @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();
     }
 
@@ -2549,6 +2599,7 @@
     }
 
     void enableVerboseLoggingInternal(int verbose) {
+        mVerboseLoggingEnabled = verbose > 0;
         mWifiStateMachine.enableVerboseLogging(verbose);
         mWifiLockManager.enableVerboseLogging(verbose);
         mWifiMulticastLockManager.enableVerboseLogging(verbose);
@@ -2558,7 +2609,9 @@
     @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);
     }
@@ -2603,7 +2656,9 @@
     @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();
     }