Add local log

This change adds a local log buffer to the VcnManagementService,
ensuring that if the system-wide log buffer saturates, some basic VCN
logs are retained

Bug: 188842647
Test: atest FrameworksVcnTests
Test: adb shell dumpsys vcn_management
Change-Id: Ib250e38fc5a034a6d2a327b2ee159e7186a15ada
Merged-In: Ib250e38fc5a034a6d2a327b2ee159e7186a15ada
(cherry picked from commit 370cc2f6a0)
This commit is contained in:
Benedict Wong
2021-05-12 13:43:47 -07:00
parent 61d7ab9455
commit fc3b6231a6
6 changed files with 100 additions and 25 deletions

View File

@@ -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;
}
}
@@ -442,7 +447,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()) {
@@ -545,7 +550,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.
@@ -570,7 +575,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);
@@ -596,7 +601,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());
@@ -622,7 +627,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);
@@ -685,7 +690,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");
}
}
@@ -795,7 +800,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);
@@ -861,10 +866,8 @@ public class VcnManagementService extends IVcnManagementService.Stub {
final VcnUnderlyingNetworkPolicy policy = new VcnUnderlyingNetworkPolicy(
mTrackingNetworkCallback.requiresRestartForCarrierWifi(result), result);
if (VDBG) {
Slog.d(TAG, "getUnderlyingNetworkPolicy() called for caps: " + networkCapabilities
logVdbg("getUnderlyingNetworkPolicy() called for caps: " + networkCapabilities
+ "; and lp: " + linkProperties + "; result = " + policy);
}
return policy;
});
}
@@ -956,14 +959,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 {
@@ -991,6 +994,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.
*
@@ -1031,6 +1071,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);
}

View File

@@ -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();
}

View File

@@ -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;
@@ -425,7 +427,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;
}
@@ -496,7 +498,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;
}
@@ -512,7 +514,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;
}
@@ -527,7 +529,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;
}
@@ -615,7 +617,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;
}
@@ -762,6 +764,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:");

View File

@@ -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);
}
/**

View File

@@ -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;
@@ -1644,7 +1645,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 {
@@ -2133,37 +2134,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);
}
/**

View File

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