Add debug to TelephonyRegistry.

Also change all debug to use the new log method and send the debug
to Rlog rather than Slog. This way we don't spam the main log buffer
just our radio log buffer while we're debugging 16148026.

Bug: 16148026
Change-Id: I5571f7d07405ddb3c208efd1756106b78343c843
diff --git a/services/core/java/com/android/server/TelephonyRegistry.java b/services/core/java/com/android/server/TelephonyRegistry.java
index 1bd837b..b9467f1 100644
--- a/services/core/java/com/android/server/TelephonyRegistry.java
+++ b/services/core/java/com/android/server/TelephonyRegistry.java
@@ -33,6 +33,7 @@
 import android.os.UserHandle;
 import android.telephony.CellLocation;
 import android.telephony.DataConnectionRealTimeInfo;
+import android.telephony.Rlog;
 import android.telephony.TelephonyManager;
 import android.telephony.SubscriptionManager;
 import android.telephony.PhoneStateListener;
@@ -46,7 +47,6 @@
 import android.telephony.PreciseDataConnectionState;
 import android.telephony.PreciseDisconnectCause;
 import android.text.TextUtils;
-import android.util.Slog;
 
 import java.util.ArrayList;
 import java.util.List;
@@ -177,7 +177,7 @@
         public void handleMessage(Message msg) {
             switch (msg.what) {
                 case MSG_USER_SWITCHED: {
-                    Slog.d(TAG, "MSG_USER_SWITCHED userId=" + msg.arg1);
+                    log("MSG_USER_SWITCHED userId=" + msg.arg1);
                     int numPhones = TelephonyManager.getDefault().getPhoneCount();
                     for (int sub = 0; sub < numPhones; sub++) {
                         TelephonyRegistry.this.notifyCellLocationUsingSubId(sub, mCellLocation[sub]);
@@ -185,7 +185,7 @@
                     break;
                 }
                 case MSG_UPDATE_DEFAULT_SUB: {
-                    Slog.d(TAG, "MSG_UPDATE_DEFAULT_SUB subid=" + mDefaultSubId);
+                    log("MSG_UPDATE_DEFAULT_SUB subid=" + mDefaultSubId);
                     // Default subscription id changed, update the changed default subscription
                     // id in  all the legacy application listener records.
                     synchronized (mRecords) {
@@ -206,15 +206,15 @@
         @Override
         public void onReceive(Context context, Intent intent) {
             String action = intent.getAction();
-            Slog.d(TAG, "mBroadcastReceiver: action=" + action);
+            log("mBroadcastReceiver: action=" + action);
             if (Intent.ACTION_USER_SWITCHED.equals(action)) {
                 int userHandle = intent.getIntExtra(Intent.EXTRA_USER_HANDLE, 0);
-                if (DBG) Slog.d(TAG, "onReceive: userHandle=" + userHandle);
+                if (DBG) log("onReceive: userHandle=" + userHandle);
                 mHandler.sendMessage(mHandler.obtainMessage(MSG_USER_SWITCHED, userHandle, 0));
             } else if (action.equals(TelephonyIntents.ACTION_DEFAULT_SUBSCRIPTION_CHANGED)) {
                 mDefaultSubId = intent.getLongExtra(PhoneConstants.SUBSCRIPTION_KEY,
                         SubscriptionManager.getDefaultSubId());
-                if (DBG) Slog.d(TAG, "onReceive: mDefaultSubId=" + mDefaultSubId);
+                if (DBG) log("onReceive: mDefaultSubId=" + mDefaultSubId);
                 mHandler.sendMessage(mHandler.obtainMessage(MSG_UPDATE_DEFAULT_SUB, 0, 0));
             }
         }
@@ -238,7 +238,7 @@
         mDefaultSubId = SubscriptionManager.getDefaultSubId();
 
         int numPhones = TelephonyManager.getDefault().getPhoneCount();
-        if (DBG) Slog.d(TAG, "TelephonyRegistor: ctor numPhones=" + numPhones);
+        if (DBG) log("TelephonyRegistor: ctor numPhones=" + numPhones);
         mNumPhones = numPhones;
         mCallState = new int[numPhones];
         mDataActivity = new int[numPhones];
@@ -288,7 +288,7 @@
         filter.addAction(Intent.ACTION_USER_SWITCHED);
         filter.addAction(Intent.ACTION_USER_REMOVED);
         filter.addAction(TelephonyIntents.ACTION_DEFAULT_SUBSCRIPTION_CHANGED);
-        Slog.d(TAG, "systemRunning register for intents");
+        log("systemRunning register for intents");
         mContext.registerReceiver(mBroadcastReceiver, filter);
     }
 
@@ -308,8 +308,8 @@
             boolean notifyNow, long subId, boolean isLegacyApp) {
         int callerUid = UserHandle.getCallingUserId();
         int myUid = UserHandle.myUserId();
-        if (VDBG) {
-            Slog.d(TAG, "listen: E pkg=" + pkgForDebug + " events=0x" + Integer.toHexString(events)
+        if (true /*VDBG*/) {
+            log("listen: E pkg=" + pkgForDebug + " events=0x" + Integer.toHexString(events)
                 + " notifyNow=" + notifyNow + " subId=" + subId
                 + " isLegacyApp=" + isLegacyApp
                 + " myUid=" + myUid
@@ -347,14 +347,14 @@
                     if (r.subId == SubscriptionManager.DEFAULT_SUB_ID) {
                         r.subId = mDefaultSubId;
                         r.isLegacyApp = true; // r.subId is to be update when default changes.
-                        if (DBG) Slog.i(TAG, "listen: DEFAULT_SUB_ID");
+                        if (true/*DBG*/) log("listen: DEFAULT_SUB_ID");
                     }
                     mRecords.add(r);
-                    if (DBG) Slog.i(TAG, "listen: add new record");
+                    if (true/*DBG*/) log("listen: add new record");
                 }
                 int phoneId = SubscriptionManager.getPhoneId(subId);
                 r.events = events;
-                if (DBG) Slog.i(TAG, "listen: set events record=" + r);
+                if (true/*DBG*/) log("listen: set events record=" + r);
                 if (notifyNow && validatePhoneId(phoneId)) {
                     if ((events & PhoneStateListener.LISTEN_SERVICE_STATE) != 0) {
                         try {
@@ -392,7 +392,7 @@
                     }
                     if (validateEventsAndUserLocked(r, PhoneStateListener.LISTEN_CELL_LOCATION)) {
                         try {
-                            if (DBG_LOC) Slog.d(TAG, "listen: mCellLocation = "
+                            if (DBG_LOC) log("listen: mCellLocation = "
                                     + mCellLocation[phoneId]);
                             r.callback.onCellLocationChanged(
                                     new Bundle(mCellLocation[phoneId]));
@@ -439,7 +439,7 @@
                     }
                     if (validateEventsAndUserLocked(r, PhoneStateListener.LISTEN_CELL_INFO)) {
                         try {
-                            if (DBG_LOC) Slog.d(TAG, "listen: mCellInfo[" + phoneId + "] = "
+                            if (DBG_LOC) log("listen: mCellInfo[" + phoneId + "] = "
                                     + mCellInfo.get(phoneId));
                             r.callback.onCellInfoChanged(mCellInfo.get(phoneId));
                         } catch (RemoteException ex) {
@@ -512,8 +512,8 @@
         if (!checkNotifyPermission("notifyCallState()")) {
             return;
         }
-        if (VDBG) {
-            Slog.d(TAG, "notifyCallStateUsingSubId: subId=" + subId
+        if (true /*VDBG*/) {
+            log("notifyCallStateUsingSubId: subId=" + subId
                 + " state=" + state + " incomingNumber=" + incomingNumber);
         }
         synchronized (mRecords) {
@@ -548,10 +548,10 @@
         }
         if (subId == SubscriptionManager.DEFAULT_SUB_ID) {
             subId = mDefaultSubId;
-            Slog.d(TAG, "notifyServiceStateUsingSubId: using mDefaultSubId=" + mDefaultSubId);
+            log("notifyServiceStateUsingSubId: using mDefaultSubId=" + mDefaultSubId);
         }
-        if (VDBG) {
-            Slog.d(TAG, "notifyServiceStateUsingSubId: subId=" + subId
+        if (true/*VDBG*/) {
+            log("notifyServiceStateUsingSubId: subId=" + subId
                 + " state=" + state);
         }
         synchronized (mRecords) {
@@ -559,10 +559,13 @@
             if (validatePhoneId(phoneId)) {
                 mServiceState[phoneId] = state;
                 for (Record r : mRecords) {
+                    // log("notifyServiceStateUsingSubId: r.events=0x" + Integer.toHexString(r.events) + " r.subId=" + r.subId + " subId=" + subId + " state=" + state);
                     // FIXME: use DEFAULT_SUB_ID instead??
                     if (((r.events & PhoneStateListener.LISTEN_SERVICE_STATE) != 0) &&
                             (r.subId == subId)) {
                         try {
+                            log("notifyServiceStateUsingSubId: call onSSC subId=" + subId
+                                    + " state=" + state);
                             r.callback.onServiceStateChanged(new ServiceState(state));
                         } catch (RemoteException ex) {
                             mRemoveList.add(r.binder);
@@ -570,7 +573,7 @@
                     }
                 }
             } else {
-                Slog.d(TAG, "notifyServiceStateUsingSubId: INVALID phoneId=" + phoneId);
+                log("notifyServiceStateUsingSubId: INVALID phoneId=" + phoneId);
             }
             handleRemoveListLocked();
         }
@@ -585,18 +588,21 @@
         if (!checkNotifyPermission("notifySignalStrength()")) {
             return;
         }
-        if (VDBG) {
-            Slog.d(TAG, "notifySignalStrengthUsingSubId: subId=" + subId
+        if (true/*VDBG*/) {
+            log("notifySignalStrengthUsingSubId: subId=" + subId
                 + " signalStrength=" + signalStrength);
         }
         synchronized (mRecords) {
             int phoneId = SubscriptionManager.getPhoneId(subId);
             if (validatePhoneId(phoneId)) {
+                log("notifySignalStrengthUsingSubId: valid phoneId=" + phoneId);
                 mSignalStrength[phoneId] = signalStrength;
                 for (Record r : mRecords) {
+                    //log("notifySignalStrengthUsingSubId: r.events=0x" + Integer.toHexString(r.events) + " r.subId=" + r.subId + " subId=" + subId);
                     if (((r.events & PhoneStateListener.LISTEN_SIGNAL_STRENGTHS) != 0) &&
                         (r.subId == subId)){
                         try {
+                            log("notifySignalStrengthUsingSubId: callback.onSsS ss=" + signalStrength);
                             r.callback.onSignalStrengthsChanged(new SignalStrength(signalStrength));
                         } catch (RemoteException ex) {
                             mRemoveList.add(r.binder);
@@ -606,13 +612,16 @@
                         (r.subId == subId)) {
                         try {
                             int gsmSignalStrength = signalStrength.getGsmSignalStrength();
-                            r.callback.onSignalStrengthChanged((gsmSignalStrength == 99 ? -1
-                                    : gsmSignalStrength));
+                            int ss = (gsmSignalStrength == 99 ? -1 : gsmSignalStrength);
+                            log("notifySignalStrengthUsingSubId: callback.onSS gsmSS=" + gsmSignalStrength + " ss=" + ss);
+                            r.callback.onSignalStrengthChanged(ss);
                         } catch (RemoteException ex) {
                             mRemoveList.add(r.binder);
                         }
                     }
                 }
+            } else {
+                log("notifySignalStrengthUsingSubId: invalid phoneId=" + phoneId);
             }
             handleRemoveListLocked();
         }
@@ -628,7 +637,7 @@
             return;
         }
         if (VDBG) {
-            Slog.d(TAG, "notifyCellInfoUsingSubId: subId=" + subId
+            log("notifyCellInfoUsingSubId: subId=" + subId
                 + " cellInfo=" + cellInfo);
         }
 
@@ -641,7 +650,7 @@
                             && r.subId == subId) {
                         try {
                             if (DBG_LOC) {
-                                Slog.d(TAG, "notifyCellInfo: mCellInfo=" + cellInfo + " r=" + r);
+                                log("notifyCellInfo: mCellInfo=" + cellInfo + " r=" + r);
                             }
                             r.callback.onCellInfoChanged(cellInfo);
                         } catch (RemoteException ex) {
@@ -666,7 +675,7 @@
                         PhoneStateListener.LISTEN_DATA_CONNECTION_REAL_TIME_INFO)) {
                     try {
                         if (DBG_LOC) {
-                            Slog.d(TAG, "notifyDataConnectionRealTimeInfo: mDcRtInfo="
+                            log("notifyDataConnectionRealTimeInfo: mDcRtInfo="
                                     + mDcRtInfo + " r=" + r);
                         }
                         r.callback.onDataConnectionRealTimeInfoChanged(mDcRtInfo);
@@ -688,7 +697,7 @@
             return;
         }
         if (VDBG) {
-            Slog.d(TAG, "notifyMessageWaitingChangedUsingSubId: subId=" + subId
+            log("notifyMessageWaitingChangedUsingSubId: subId=" + subId
                 + " mwi=" + mwi);
         }
         synchronized (mRecords) {
@@ -719,7 +728,7 @@
             return;
         }
         if (VDBG) {
-            Slog.d(TAG, "notifyCallForwardingChangedUsingSubId: subId=" + subId
+            log("notifyCallForwardingChangedUsingSubId: subId=" + subId
                 + " cfi=" + cfi);
         }
         synchronized (mRecords) {
@@ -781,7 +790,7 @@
             return;
         }
         if (VDBG) {
-            Slog.i(TAG, "notifyDataConnectionUsingSubId: subId=" + subId
+            log("notifyDataConnectionUsingSubId: subId=" + subId
                 + " state=" + state + " isDataConnectivityPossible=" + isDataConnectivityPossible
                 + " reason='" + reason
                 + "' apn='" + apn + "' apnType=" + apnType + " networkType=" + networkType
@@ -820,14 +829,14 @@
             }
             if (modified) {
                 if (DBG) {
-                    Slog.d(TAG, "onDataConnectionStateChanged(" + mDataConnectionState[phoneId]
+                    log("onDataConnectionStateChanged(" + mDataConnectionState[phoneId]
                         + ", " + mDataConnectionNetworkType[phoneId] + ")");
                 }
                 for (Record r : mRecords) {
                     if (((r.events & PhoneStateListener.LISTEN_DATA_CONNECTION_STATE) != 0) &&
                             (r.subId == subId)) {
                         try {
-                            Slog.d(TAG,"Notify data connection state changed on sub: " +
+                            log("Notify data connection state changed on sub: " +
                                     subId);
                             r.callback.onDataConnectionStateChanged(mDataConnectionState[phoneId],
                                     mDataConnectionNetworkType[phoneId]);
@@ -867,7 +876,7 @@
             return;
         }
         if (VDBG) {
-            Slog.d(TAG, "notifyDataConnectionFailedUsingSubId: subId=" + subId
+            log("notifyDataConnectionFailedUsingSubId: subId=" + subId
                 + " reason=" + reason + " apnType=" + apnType);
         }
         synchronized (mRecords) {
@@ -895,13 +904,13 @@
     }
 
     public void notifyCellLocationUsingSubId(long subId, Bundle cellLocation) {
-        Slog.d(TAG, "notifyCellLocationUsingSubId: subId=" + subId
+        log("notifyCellLocationUsingSubId: subId=" + subId
                 + " cellLocation=" + cellLocation);
         if (!checkNotifyPermission("notifyCellLocation()")) {
             return;
         }
         if (VDBG) {
-            Slog.d(TAG, "notifyCellLocationUsingSubId: subId=" + subId
+            log("notifyCellLocationUsingSubId: subId=" + subId
                 + " cellLocation=" + cellLocation);
         }
         synchronized (mRecords) {
@@ -913,7 +922,7 @@
                             && r.subId == subId) {
                         try {
                             if (DBG_LOC) {
-                                Slog.d(TAG, "notifyCellLocation: cellLocation=" + cellLocation
+                                log("notifyCellLocation: cellLocation=" + cellLocation
                                         + " r=" + r);
                             }
                             r.callback.onCellLocationChanged(new Bundle(cellLocation));
@@ -1221,7 +1230,7 @@
         }
         String msg = "Modify Phone State Permission Denial: " + method + " from pid="
                 + Binder.getCallingPid() + ", uid=" + Binder.getCallingUid();
-        if (DBG) Slog.w(TAG, msg);
+        if (DBG) log(msg);
         return false;
     }
 
@@ -1267,7 +1276,7 @@
             foregroundUser = ActivityManager.getCurrentUser();
             valid = r.callerUid ==  foregroundUser && (r.events & events) != 0;
             if (DBG | DBG_LOC) {
-                Slog.d(TAG, "validateEventsAndUserLocked: valid=" + valid
+                log("validateEventsAndUserLocked: valid=" + valid
                         + " r.callerUid=" + r.callerUid + " foregroundUser=" + foregroundUser
                         + " r.events=" + r.events + " events=" + events);
             }
@@ -1279,7 +1288,11 @@
 
     private boolean validatePhoneId(int phoneId) {
         boolean valid = (phoneId >= 0) && (phoneId < mNumPhones);
-        if (VDBG) Slog.d(TAG, "validatePhoneId: " + valid);
+        if (VDBG) log("validatePhoneId: " + valid);
         return valid;
     }
+
+    private static void log(String s) {
+        Rlog.d(TAG, s);
+    }
 }