diff options
6 files changed, 100 insertions, 25 deletions
diff --git a/services/core/java/com/android/server/VcnManagementService.java b/services/core/java/com/android/server/VcnManagementService.java index 57adcb6e3966..7e2274b65f55 100644 --- a/services/core/java/com/android/server/VcnManagementService.java +++ b/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) { - Slog.d(TAG, "getUnderlyingNetworkPolicy() called for caps: " + networkCapabilities + logVdbg("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); } diff --git a/services/core/java/com/android/server/vcn/TelephonySubscriptionTracker.java b/services/core/java/com/android/server/vcn/TelephonySubscriptionTracker.java index 5565ccb6cf7c..fca706b707fa 100644 --- a/services/core/java/com/android/server/vcn/TelephonySubscriptionTracker.java +++ b/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(); } diff --git a/services/core/java/com/android/server/vcn/UnderlyingNetworkTracker.java b/services/core/java/com/android/server/vcn/UnderlyingNetworkTracker.java index 5414a5206abb..732035951462 100644 --- a/services/core/java/com/android/server/vcn/UnderlyingNetworkTracker.java +++ b/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:"); diff --git a/services/core/java/com/android/server/vcn/Vcn.java b/services/core/java/com/android/server/vcn/Vcn.java index 6b4ee693c936..f7d61367c81e 100644 --- a/services/core/java/com/android/server/vcn/Vcn.java +++ b/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); } /** diff --git a/services/core/java/com/android/server/vcn/VcnGatewayConnection.java b/services/core/java/com/android/server/vcn/VcnGatewayConnection.java index fbbae973538a..55e3ed620160 100644 --- a/services/core/java/com/android/server/vcn/VcnGatewayConnection.java +++ b/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); } /** diff --git a/services/core/java/com/android/server/vcn/VcnNetworkProvider.java b/services/core/java/com/android/server/vcn/VcnNetworkProvider.java index 72cd7880325f..31ee2477fa64 100644 --- a/services/core/java/com/android/server/vcn/VcnNetworkProvider.java +++ b/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); } |