Merge "Add local log" into sc-dev am: 61b618aa7d

Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/14702007

Change-Id: I5ec5924057809312d47a77598bf235617fabd613

services/core/java/com/android/server/VcnManagementService.java

@@ -64,6 +64,7 @@ import android.telephony.SubscriptionInfo;
 import android.telephony.SubscriptionManager;
 import android.telephony.TelephonyManager;
 import android.util.ArrayMap;
+import android.util.LocalLog;
 import android.util.Log;
 import android.util.Slog;
 
@@ -149,6 +150,10 @@ import java.util.concurrent.TimeUnit;
 public class VcnManagementService extends IVcnManagementService.Stub {
     @NonNull private static final String TAG = VcnManagementService.class.getSimpleName();
     private static final long DUMP_TIMEOUT_MILLIS = TimeUnit.SECONDS.toMillis(5);
+    private static final int LOCAL_LOG_LINE_COUNT = 128;
+
+    // Public for use in all other VCN classes
+    @NonNull public static final LocalLog LOCAL_LOG = new LocalLog(LOCAL_LOG_LINE_COUNT);
 
     public static final boolean VDBG = false; // STOPSHIP: if true
 
@@ -242,13 +247,13 @@ public class VcnManagementService extends IVcnManagementService.Stub {
             try {
                 configBundle = mConfigDiskRwHelper.readFromDisk();
             } catch (IOException e1) {
-                Slog.e(TAG, "Failed to read configs from disk; retrying", e1);
+                logErr("Failed to read configs from disk; retrying", e1);
 
                 // Retry immediately. The IOException may have been transient.
                 try {
                     configBundle = mConfigDiskRwHelper.readFromDisk();
                 } catch (IOException e2) {
-                    Slog.wtf(TAG, "Failed to read configs from disk", e2);
+                    logWtf("Failed to read configs from disk", e2);
                     return;
                 }
             }
@@ -440,7 +445,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
             synchronized (mLock) {
                 final TelephonySubscriptionSnapshot oldSnapshot = mLastSnapshot;
                 mLastSnapshot = snapshot;
-                Slog.d(TAG, "new snapshot: " + mLastSnapshot);
+                logDbg("new snapshot: " + mLastSnapshot);
 
                 // Start any VCN instances as necessary
                 for (Entry<ParcelUuid, VcnConfig> entry : mConfigs.entrySet()) {
@@ -543,7 +548,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
 
     @GuardedBy("mLock")
     private void startVcnLocked(@NonNull ParcelUuid subscriptionGroup, @NonNull VcnConfig config) {
-        Slog.d(TAG, "Starting VCN config for subGrp: " + subscriptionGroup);
+        logDbg("Starting VCN config for subGrp: " + subscriptionGroup);
 
         // TODO(b/176939047): Support multiple VCNs active at the same time, or limit to one active
         //                    VCN.
@@ -568,7 +573,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
     @GuardedBy("mLock")
     private void startOrUpdateVcnLocked(
             @NonNull ParcelUuid subscriptionGroup, @NonNull VcnConfig config) {
-        Slog.d(TAG, "Starting or updating VCN config for subGrp: " + subscriptionGroup);
+        logDbg("Starting or updating VCN config for subGrp: " + subscriptionGroup);
 
         if (mVcns.containsKey(subscriptionGroup)) {
             final Vcn vcn = mVcns.get(subscriptionGroup);
@@ -594,7 +599,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
         if (!config.getProvisioningPackageName().equals(opPkgName)) {
             throw new IllegalArgumentException("Mismatched caller and VcnConfig creator");
         }
-        Slog.d(TAG, "VCN config updated for subGrp: " + subscriptionGroup);
+        logDbg("VCN config updated for subGrp: " + subscriptionGroup);
 
         mContext.getSystemService(AppOpsManager.class)
                 .checkPackage(mDeps.getBinderCallingUid(), config.getProvisioningPackageName());
@@ -620,7 +625,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
     public void clearVcnConfig(@NonNull ParcelUuid subscriptionGroup, @NonNull String opPkgName) {
         requireNonNull(subscriptionGroup, "subscriptionGroup was null");
         requireNonNull(opPkgName, "opPkgName was null");
-        Slog.d(TAG, "VCN config cleared for subGrp: " + subscriptionGroup);
+        logDbg("VCN config cleared for subGrp: " + subscriptionGroup);
 
         mContext.getSystemService(AppOpsManager.class)
                 .checkPackage(mDeps.getBinderCallingUid(), opPkgName);
@@ -683,7 +688,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
                             VcnConfig::toPersistableBundle);
             mConfigDiskRwHelper.writeToDisk(bundle);
         } catch (IOException e) {
-            Slog.e(TAG, "Failed to save configs to disk", e);
+            logErr("Failed to save configs to disk", e);
             throw new ServiceSpecificException(0, "Failed to save configs");
         }
     }
@@ -793,7 +798,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
         for (int subId : networkCapabilities.getSubscriptionIds()) {
             // Verify that all subscriptions point to the same group
             if (subGrp != null && !subGrp.equals(snapshot.getGroupForSubId(subId))) {
-                Slog.wtf(TAG, "Got multiple subscription groups for a single network");
+                logWtf("Got multiple subscription groups for a single network");
             }
 
             subGrp = snapshot.getGroupForSubId(subId);
@@ -859,10 +864,8 @@ public class VcnManagementService extends IVcnManagementService.Stub {
             final VcnUnderlyingNetworkPolicy policy = new VcnUnderlyingNetworkPolicy(
                     mTrackingNetworkCallback.requiresRestartForCarrierWifi(result), result);
 
-            if (VDBG) {
+            logVdbg("getUnderlyingNetworkPolicy() called for caps: " + networkCapabilities
-                Slog.d(TAG, "getUnderlyingNetworkPolicy() called for caps: " + networkCapabilities
                         + "; and lp: " + linkProperties + "; result = " + policy);
-            }
             return policy;
         });
     }
@@ -954,14 +957,14 @@ public class VcnManagementService extends IVcnManagementService.Stub {
                         || vcnStatus == VCN_STATUS_CODE_SAFE_MODE) {
                     resultStatus = vcnStatus;
                 } else {
-                    Slog.wtf(TAG, "Unknown VCN status: " + vcnStatus);
+                    logWtf("Unknown VCN status: " + vcnStatus);
                     resultStatus = VCN_STATUS_CODE_NOT_CONFIGURED;
                 }
 
                 try {
                     cbInfo.mCallback.onVcnStatusChanged(resultStatus);
                 } catch (RemoteException e) {
-                    Slog.d(TAG, "VcnStatusCallback threw on VCN status change", e);
+                    logDbg("VcnStatusCallback threw on VCN status change", e);
                 }
             }
         } finally {
@@ -989,6 +992,43 @@ public class VcnManagementService extends IVcnManagementService.Stub {
         }
     }
 
+    private void logVdbg(String msg) {
+        if (VDBG) {
+            Slog.v(TAG, msg);
+            LOCAL_LOG.log(TAG + " VDBG: " + msg);
+        }
+    }
+
+    private void logDbg(String msg) {
+        Slog.d(TAG, msg);
+        LOCAL_LOG.log(TAG + " DBG: " + msg);
+    }
+
+    private void logDbg(String msg, Throwable tr) {
+        Slog.d(TAG, msg, tr);
+        LOCAL_LOG.log(TAG + " DBG: " + msg + tr);
+    }
+
+    private void logErr(String msg) {
+        Slog.e(TAG, msg);
+        LOCAL_LOG.log(TAG + " ERR: " + msg);
+    }
+
+    private void logErr(String msg, Throwable tr) {
+        Slog.e(TAG, msg, tr);
+        LOCAL_LOG.log(TAG + " ERR: " + msg + tr);
+    }
+
+    private void logWtf(String msg) {
+        Slog.wtf(TAG, msg);
+        LOCAL_LOG.log(TAG + " WTF: " + msg);
+    }
+
+    private void logWtf(String msg, Throwable tr) {
+        Slog.wtf(TAG, msg, tr);
+        LOCAL_LOG.log(TAG + " WTF: " + msg + tr);
+    }
+
     /**
      * Dumps the state of the VcnManagementService for logging and debugging purposes.
      *
@@ -1029,6 +1069,12 @@ public class VcnManagementService extends IVcnManagementService.Stub {
                 pw.decreaseIndent();
                 pw.println();
             }
+
+            pw.println("Local log:");
+            pw.increaseIndent();
+            LOCAL_LOG.dump(pw);
+            pw.decreaseIndent();
+            pw.println();
         }, DUMP_TIMEOUT_MILLIS);
     }
 

services/core/java/com/android/server/vcn/TelephonySubscriptionTracker.java

@@ -39,7 +39,6 @@ import android.telephony.SubscriptionManager.OnSubscriptionsChangedListener;
 import android.telephony.TelephonyManager;
 import android.util.ArrayMap;
 import android.util.ArraySet;
-import android.util.Slog;
 
 import com.android.internal.annotations.VisibleForTesting;
 import com.android.internal.annotations.VisibleForTesting.Visibility;
@@ -222,12 +221,10 @@ public class TelephonySubscriptionTracker extends BroadcastReceiver {
         if (SubscriptionManager.isValidSubscriptionId(subId)) {
             final PersistableBundle carrierConfigs = mCarrierConfigManager.getConfigForSubId(subId);
             if (mDeps.isConfigForIdentifiedCarrier(carrierConfigs)) {
-                Slog.v(TAG, String.format("SubId %s ready for SlotId %s", subId, slotId));
                 mReadySubIdsBySlotId.put(slotId, subId);
                 handleSubscriptionsChanged();
             }
         } else {
-            Slog.v(TAG, "Slot unloaded: " + slotId);
             mReadySubIdsBySlotId.remove(slotId);
             handleSubscriptionsChanged();
         }

services/core/java/com/android/server/vcn/UnderlyingNetworkTracker.java

@@ -20,6 +20,8 @@ import static android.net.NetworkCapabilities.TRANSPORT_CELLULAR;
 import static android.net.NetworkCapabilities.TRANSPORT_WIFI;
 import static android.telephony.TelephonyCallback.ActiveDataSubscriptionIdListener;
 
+import static com.android.server.VcnManagementService.LOCAL_LOG;
+
 import android.annotation.NonNull;
 import android.annotation.Nullable;
 import android.net.ConnectivityManager;
@@ -433,7 +435,7 @@ public class UnderlyingNetworkTracker {
     private static boolean isOpportunistic(
             @NonNull TelephonySubscriptionSnapshot snapshot, Set<Integer> subIds) {
         if (snapshot == null) {
-            Slog.wtf(TAG, "Got null snapshot");
+            logWtf("Got null snapshot");
             return false;
         }
 
@@ -504,7 +506,7 @@ public class UnderlyingNetworkTracker {
             final UnderlyingNetworkRecord.Builder builder =
                     mUnderlyingNetworkRecordBuilders.get(network);
             if (builder == null) {
-                Slog.wtf(TAG, "Got capabilities change for unknown key: " + network);
+                logWtf("Got capabilities change for unknown key: " + network);
                 return;
             }
 
@@ -520,7 +522,7 @@ public class UnderlyingNetworkTracker {
             final UnderlyingNetworkRecord.Builder builder =
                     mUnderlyingNetworkRecordBuilders.get(network);
             if (builder == null) {
-                Slog.wtf(TAG, "Got link properties change for unknown key: " + network);
+                logWtf("Got link properties change for unknown key: " + network);
                 return;
             }
 
@@ -535,7 +537,7 @@ public class UnderlyingNetworkTracker {
             final UnderlyingNetworkRecord.Builder builder =
                     mUnderlyingNetworkRecordBuilders.get(network);
             if (builder == null) {
-                Slog.wtf(TAG, "Got blocked status change for unknown key: " + network);
+                logWtf("Got blocked status change for unknown key: " + network);
                 return;
             }
 
@@ -623,7 +625,7 @@ public class UnderlyingNetworkTracker {
             // mRouteSelectionNetworkRequest requires a network be both VALIDATED and NOT_SUSPENDED
 
             if (isBlocked) {
-                Slog.wtf(TAG, "Network blocked for System Server: " + network);
+                logWtf("Network blocked for System Server: " + network);
                 return PRIORITY_ANY;
             }
 
@@ -770,6 +772,16 @@ public class UnderlyingNetworkTracker {
         }
     }
 
+    private static void logWtf(String msg) {
+        Slog.wtf(TAG, msg);
+        LOCAL_LOG.log(TAG + " WTF: " + msg);
+    }
+
+    private static void logWtf(String msg, Throwable tr) {
+        Slog.wtf(TAG, msg, tr);
+        LOCAL_LOG.log(TAG + " WTF: " + msg + tr);
+    }
+
     /** Dumps the state of this record for logging and debugging purposes. */
     public void dump(IndentingPrintWriter pw) {
         pw.println("UnderlyingNetworkTracker:");

services/core/java/com/android/server/vcn/Vcn.java

@@ -24,6 +24,7 @@ import static android.net.vcn.VcnManager.VCN_STATUS_CODE_ACTIVE;
 import static android.net.vcn.VcnManager.VCN_STATUS_CODE_INACTIVE;
 import static android.net.vcn.VcnManager.VCN_STATUS_CODE_SAFE_MODE;
 
+import static com.android.server.VcnManagementService.LOCAL_LOG;
 import static com.android.server.VcnManagementService.VDBG;
 
 import android.annotation.NonNull;
@@ -513,37 +514,44 @@ public class Vcn extends Handler {
     }
 
     private String getLogPrefix() {
-        return "[" + LogUtils.getHashedSubscriptionGroup(mSubscriptionGroup) + "]: ";
+        return "[" + LogUtils.getHashedSubscriptionGroup(mSubscriptionGroup) + "] ";
     }
 
     private void logVdbg(String msg) {
         if (VDBG) {
             Slog.v(TAG, getLogPrefix() + msg);
+            LOCAL_LOG.log(getLogPrefix() + "VDBG: " + msg);
         }
     }
 
     private void logDbg(String msg) {
         Slog.d(TAG, getLogPrefix() + msg);
+        LOCAL_LOG.log(getLogPrefix() + "DBG: " + msg);
     }
 
     private void logDbg(String msg, Throwable tr) {
         Slog.d(TAG, getLogPrefix() + msg, tr);
+        LOCAL_LOG.log(getLogPrefix() + "DBG: " + msg + tr);
     }
 
     private void logErr(String msg) {
         Slog.e(TAG, getLogPrefix() + msg);
+        LOCAL_LOG.log(getLogPrefix() + "ERR: " + msg);
     }
 
     private void logErr(String msg, Throwable tr) {
         Slog.e(TAG, getLogPrefix() + msg, tr);
+        LOCAL_LOG.log(getLogPrefix() + "ERR: " + msg + tr);
     }
 
     private void logWtf(String msg) {
         Slog.wtf(TAG, getLogPrefix() + msg);
+        LOCAL_LOG.log(getLogPrefix() + "WTF: " + msg);
     }
 
     private void logWtf(String msg, Throwable tr) {
         Slog.wtf(TAG, getLogPrefix() + msg, tr);
+        LOCAL_LOG.log(getLogPrefix() + "WTF: " + msg + tr);
     }
 
     /**

services/core/java/com/android/server/vcn/VcnGatewayConnection.java

@@ -30,6 +30,7 @@ import static android.net.vcn.VcnManager.VCN_ERROR_CODE_CONFIG_ERROR;
 import static android.net.vcn.VcnManager.VCN_ERROR_CODE_INTERNAL_ERROR;
 import static android.net.vcn.VcnManager.VCN_ERROR_CODE_NETWORK_ERROR;
 
+import static com.android.server.VcnManagementService.LOCAL_LOG;
 import static com.android.server.VcnManagementService.VDBG;
 
 import android.annotation.NonNull;
@@ -1645,7 +1646,7 @@ public class VcnGatewayConnection extends StateMachine {
                 @NonNull IpSecTransform transform,
                 int direction) {
             if (direction != IpSecManager.DIRECTION_IN && direction != IpSecManager.DIRECTION_OUT) {
-                Slog.wtf(TAG, "Applying transform for unexpected direction: " + direction);
+                logWtf("Applying transform for unexpected direction: " + direction);
             }
 
             try {
@@ -2134,37 +2135,44 @@ public class VcnGatewayConnection extends StateMachine {
                 + LogUtils.getHashedSubscriptionGroup(mSubscriptionGroup)
                 + "-"
                 + mConnectionConfig.getGatewayConnectionName()
-                + "]: ";
+                + "] ";
     }
 
     private void logVdbg(String msg) {
         if (VDBG) {
             Slog.v(TAG, getLogPrefix() + msg);
+            LOCAL_LOG.log(getLogPrefix() + "VDBG: " + msg);
         }
     }
 
     private void logDbg(String msg) {
         Slog.d(TAG, getLogPrefix() + msg);
+        LOCAL_LOG.log(getLogPrefix() + "DBG: " + msg);
     }
 
     private void logDbg(String msg, Throwable tr) {
         Slog.d(TAG, getLogPrefix() + msg, tr);
+        LOCAL_LOG.log(getLogPrefix() + "DBG: " + msg + tr);
     }
 
     private void logErr(String msg) {
         Slog.e(TAG, getLogPrefix() + msg);
+        LOCAL_LOG.log(getLogPrefix() + "ERR: " + msg);
     }
 
     private void logErr(String msg, Throwable tr) {
         Slog.e(TAG, getLogPrefix() + msg, tr);
+        LOCAL_LOG.log(getLogPrefix() + "ERR: " + msg + tr);
     }
 
     private void logWtf(String msg) {
         Slog.wtf(TAG, getLogPrefix() + msg);
+        LOCAL_LOG.log(getLogPrefix() + "WTF: " + msg);
     }
 
     private void logWtf(String msg, Throwable tr) {
         Slog.wtf(TAG, getLogPrefix() + msg, tr);
+        LOCAL_LOG.log(getLogPrefix() + "WTF: " + msg + tr);
     }
 
     /**

services/core/java/com/android/server/vcn/VcnNetworkProvider.java

@@ -172,6 +172,10 @@ public class VcnNetworkProvider extends NetworkProvider {
     }
 
     private void handleNetworkRequestWithdrawn(@NonNull NetworkRequest request) {
+        if (VDBG) {
+            Slog.v(TAG, "Network request withdrawn: Request = " + request);
+        }
+
         mRequests.remove(request);
     }