Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Add additional logging to improve debugability of VcnManagementService" am: 3996048bad

Browse Source 
Original change: https://android-review.googlesource.com/c/platform/frameworks/base/+/1692661

Change-Id: I1597db8e8f437b797abdb70253f7b7a0fc6b77dd
This commit is contained in:
Benedict Wong
2021-05-10 21:44:38 +00:00
committed by Automerger Merge Worker
parent e8d7017b66 3996048bad
commit 30b760733b
5 changed files with 130 additions and 18 deletions
Download Patch File Download Diff File Expand all files Collapse all files

10
core/java/android/net/vcn/VcnNetworkPolicyResult.java
View File

@@ -87,6 +87,16 @@ public final class VcnNetworkPolicyResult implements Parcelable {
&& mNetworkCapabilities.equals(that.mNetworkCapabilities);
}
@Override
public String toString() {
return "VcnNetworkPolicyResult { "
+ "mIsTeardownRequested = "
+ mIsTearDownRequested
+ ", mNetworkCapabilities"
+ mNetworkCapabilities
+ " }";
}
/** {@inheritDoc} */
@Override
public int describeContents() {

5
core/java/android/net/vcn/VcnUnderlyingNetworkPolicy.java
View File

@@ -85,6 +85,11 @@ public final class VcnUnderlyingNetworkPolicy implements Parcelable {
return mVcnNetworkPolicyResult.equals(that.mVcnNetworkPolicyResult);
}
@Override
public String toString() {
return mVcnNetworkPolicyResult.toString();
}
/** {@inheritDoc} */
@Override
public int describeContents() {

17
services/core/java/com/android/server/VcnManagementService.java
View File

@@ -434,6 +434,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
synchronized (mLock) {
final TelephonySubscriptionSnapshot oldSnapshot = mLastSnapshot;
mLastSnapshot = snapshot;
Slog.d(TAG, "new snapshot: " + mLastSnapshot);
// Start any VCN instances as necessary
for (Entry<ParcelUuid, VcnConfig> entry : mConfigs.entrySet()) {
@@ -536,7 +537,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
@GuardedBy("mLock")
private void startVcnLocked(@NonNull ParcelUuid subscriptionGroup, @NonNull VcnConfig config) {
Slog.v(TAG, "Starting VCN config for subGrp: " + subscriptionGroup);
Slog.d(TAG, "Starting VCN config for subGrp: " + subscriptionGroup);
// TODO(b/176939047): Support multiple VCNs active at the same time, or limit to one active
// VCN.
@@ -558,7 +559,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
@GuardedBy("mLock")
private void startOrUpdateVcnLocked(
@NonNull ParcelUuid subscriptionGroup, @NonNull VcnConfig config) {
Slog.v(TAG, "Starting or updating VCN config for subGrp: " + subscriptionGroup);
Slog.d(TAG, "Starting or updating VCN config for subGrp: " + subscriptionGroup);
if (mVcns.containsKey(subscriptionGroup)) {
final Vcn vcn = mVcns.get(subscriptionGroup);
@@ -584,7 +585,7 @@ public class VcnManagementService extends IVcnManagementService.Stub {
if (!config.getProvisioningPackageName().equals(opPkgName)) {
throw new IllegalArgumentException("Mismatched caller and VcnConfig creator");
}
Slog.v(TAG, "VCN config updated for subGrp: " + subscriptionGroup);
Slog.d(TAG, "VCN config updated for subGrp: " + subscriptionGroup);
mContext.getSystemService(AppOpsManager.class)
.checkPackage(mDeps.getBinderCallingUid(), config.getProvisioningPackageName());
@@ -609,7 +610,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.v(TAG, "VCN config cleared for subGrp: " + subscriptionGroup);
Slog.d(TAG, "VCN config cleared for subGrp: " + subscriptionGroup);
mContext.getSystemService(AppOpsManager.class)
.checkPackage(mDeps.getBinderCallingUid(), opPkgName);
@@ -845,8 +846,14 @@ public class VcnManagementService extends IVcnManagementService.Stub {
}
final NetworkCapabilities result = ncBuilder.build();
return new VcnUnderlyingNetworkPolicy(
final VcnUnderlyingNetworkPolicy policy = new VcnUnderlyingNetworkPolicy(
mTrackingNetworkCallback.requiresRestartForCarrierWifi(result), result);
if (VDBG) {
Slog.d(TAG, "getUnderlyingNetworkPolicy() called for caps: " + networkCapabilities
+ "; and lp: " + linkProperties + "; result = " + policy);
}
return policy;
});
}

36
services/core/java/com/android/server/vcn/Vcn.java
View File

@@ -311,7 +311,9 @@ public class Vcn extends Handler {
private void handleConfigUpdated(@NonNull VcnConfig config) {
// TODO: Add a dump function in VcnConfig that omits PII. Until then, use hashCode()
Slog.v(getLogTag(), "Config updated: config = " + config.hashCode());
Slog.d(
getLogTag(),
"Config updated: old = " + mConfig.hashCode() + "; new = " + config.hashCode());
mConfig = config;
@@ -340,6 +342,7 @@ public class Vcn extends Handler {
}
private void handleTeardown() {
Slog.d(getLogTag(), "Tearing down");
mVcnContext.getVcnNetworkProvider().unregisterListener(mRequestListener);
for (VcnGatewayConnection gatewayConnection : mVcnGatewayConnections.values()) {
@@ -350,6 +353,7 @@ public class Vcn extends Handler {
}
private void handleSafeModeStatusChanged() {
Slog.d(getLogTag(), "VcnGatewayConnection safe mode status changed");
boolean hasSafeModeGatewayConnection = false;
// If any VcnGatewayConnection is in safe mode, mark the entire VCN as being in safe mode
@@ -365,21 +369,24 @@ public class Vcn extends Handler {
hasSafeModeGatewayConnection ? VCN_STATUS_CODE_SAFE_MODE : VCN_STATUS_CODE_ACTIVE;
if (oldStatus != mCurrentStatus) {
mVcnCallback.onSafeModeStatusChanged(hasSafeModeGatewayConnection);
Slog.d(
getLogTag(),
"Safe mode "
+ (mCurrentStatus == VCN_STATUS_CODE_SAFE_MODE ? "entered" : "exited"));
}
}
private void handleNetworkRequested(@NonNull NetworkRequest request) {
Slog.v(getLogTag(), "Received request " + request);
if (VDBG) {
Slog.v(getLogTag(), "Received request " + request);
}
// If preexisting VcnGatewayConnection(s) satisfy request, return
for (VcnGatewayConnectionConfig gatewayConnectionConfig : mVcnGatewayConnections.keySet()) {
if (isRequestSatisfiedByGatewayConnectionConfig(request, gatewayConnectionConfig)) {
if (VDBG) {
Slog.v(
getLogTag(),
"Request already satisfied by existing VcnGatewayConnection: "
+ request);
}
Slog.d(
getLogTag(),
"Request already satisfied by existing VcnGatewayConnection: " + request);
return;
}
}
@@ -389,7 +396,7 @@ public class Vcn extends Handler {
for (VcnGatewayConnectionConfig gatewayConnectionConfig :
mConfig.getGatewayConnectionConfigs()) {
if (isRequestSatisfiedByGatewayConnectionConfig(request, gatewayConnectionConfig)) {
Slog.v(getLogTag(), "Bringing up new VcnGatewayConnection for request " + request);
Slog.d(getLogTag(), "Bringing up new VcnGatewayConnection for request " + request);
if (getExposedCapabilitiesForMobileDataState(gatewayConnectionConfig).isEmpty()) {
// Skip; this network does not provide any services if mobile data is disabled.
@@ -414,8 +421,14 @@ public class Vcn extends Handler {
new VcnGatewayStatusCallbackImpl(gatewayConnectionConfig),
mIsMobileDataEnabled);
mVcnGatewayConnections.put(gatewayConnectionConfig, vcnGatewayConnection);
return;
}
}
if (VDBG) {
Slog.v(getLogTag(), "Request could not be fulfilled by VCN: " + request);
}
}
private Set<Integer> getExposedCapabilitiesForMobileDataState(
@@ -432,7 +445,7 @@ public class Vcn extends Handler {
}
private void handleGatewayConnectionQuit(VcnGatewayConnectionConfig config) {
Slog.v(getLogTag(), "VcnGatewayConnection quit: " + config);
Slog.d(getLogTag(), "VcnGatewayConnection quit: " + config);
mVcnGatewayConnections.remove(config);
// Trigger a re-evaluation of all NetworkRequests (to make sure any that can be satisfied
@@ -479,6 +492,8 @@ public class Vcn extends Handler {
// Trigger re-evaluation of all requests; mobile data state impacts supported caps.
mVcnContext.getVcnNetworkProvider().resendAllRequests(mRequestListener);
Slog.d(getLogTag(), "Mobile data " + (mIsMobileDataEnabled ? "enabled" : "disabled"));
}
}
@@ -521,6 +536,7 @@ public class Vcn extends Handler {
pw.increaseIndent();
pw.println("mCurrentStatus: " + mCurrentStatus);
pw.println("mIsMobileDataEnabled: " + mIsMobileDataEnabled);
pw.println("mVcnGatewayConnections:");
for (VcnGatewayConnection gw : mVcnGatewayConnections.values()) {

80
services/core/java/com/android/server/vcn/VcnGatewayConnection.java
View File

@@ -701,6 +701,7 @@ public class VcnGatewayConnection extends StateMachine {
* <p>Once torn down, this VcnTunnel CANNOT be started again.
*/
public void teardownAsynchronously() {
Slog.d(TAG, "Triggering async teardown");
sendDisconnectRequestedAndAcquireWakelock(
DISCONNECT_REASON_TEARDOWN, true /* shouldQuit */);
@@ -710,6 +711,8 @@ public class VcnGatewayConnection extends StateMachine {
@Override
protected void onQuitting() {
Slog.d(TAG, "Quitting VcnGatewayConnection");
// No need to call setInterfaceDown(); the IpSecInterface is being fully torn down.
if (mTunnelIface != null) {
mTunnelIface.close();
@@ -750,6 +753,11 @@ public class VcnGatewayConnection extends StateMachine {
// TODO(b/180132994): explore safely removing this Thread check
mVcnContext.ensureRunningOnLooperThread();
Slog.d(
TAG,
"Selected underlying network changed: "
+ (underlying == null ? null : underlying.network));
// TODO(b/179091925): Move the delayed-message handling to BaseState
// If underlying is null, all underlying networks have been lost. Disconnect VCN after a
@@ -774,6 +782,10 @@ public class VcnGatewayConnection extends StateMachine {
if (!mIsQuitting) {
mWakeLock.acquire();
if (VDBG) {
Slog.v(TAG, "Wakelock acquired: " + mWakeLock);
}
}
}
@@ -781,6 +793,10 @@ public class VcnGatewayConnection extends StateMachine {
mVcnContext.ensureRunningOnLooperThread();
mWakeLock.release();
if (VDBG) {
Slog.v(TAG, "Wakelock released: " + mWakeLock);
}
}
/**
@@ -935,10 +951,17 @@ public class VcnGatewayConnection extends StateMachine {
}
private void setTeardownTimeoutAlarm() {
if (VDBG) {
Slog.v(TAG, "Setting teardown timeout alarm; mCurrentToken: " + mCurrentToken);
}
// Safe to assign this alarm because it is either 1) already null, or 2) already fired. In
// either case, there is nothing to cancel.
if (mTeardownTimeoutAlarm != null) {
Slog.wtf(TAG, "mTeardownTimeoutAlarm should be null before being set");
Slog.wtf(
TAG,
"mTeardownTimeoutAlarm should be null before being set; mCurrentToken: "
+ mCurrentToken);
}
final Message delayedMessage = obtainMessage(EVENT_TEARDOWN_TIMEOUT_EXPIRED, mCurrentToken);
@@ -950,6 +973,10 @@ public class VcnGatewayConnection extends StateMachine {
}
private void cancelTeardownTimeoutAlarm() {
if (VDBG) {
Slog.v(TAG, "Cancelling teardown timeout alarm; mCurrentToken: " + mCurrentToken);
}
if (mTeardownTimeoutAlarm != null) {
mTeardownTimeoutAlarm.cancel();
mTeardownTimeoutAlarm = null;
@@ -960,6 +987,13 @@ public class VcnGatewayConnection extends StateMachine {
}
private void setDisconnectRequestAlarm() {
if (VDBG) {
Slog.v(
TAG,
"Setting alarm to disconnect due to underlying network loss; mCurrentToken: "
+ mCurrentToken);
}
// Only schedule a NEW alarm if none is already set.
if (mDisconnectRequestAlarm != null) {
return;
@@ -980,6 +1014,13 @@ public class VcnGatewayConnection extends StateMachine {
}
private void cancelDisconnectRequestAlarm() {
if (VDBG) {
Slog.v(
TAG,
"Cancelling alarm to disconnect due to underlying network loss; mCurrentToken: "
+ mCurrentToken);
}
if (mDisconnectRequestAlarm != null) {
mDisconnectRequestAlarm.cancel();
mDisconnectRequestAlarm = null;
@@ -993,10 +1034,17 @@ public class VcnGatewayConnection extends StateMachine {
}
private void setRetryTimeoutAlarm(long delay) {
if (VDBG) {
Slog.v(TAG, "Setting retry alarm; mCurrentToken: " + mCurrentToken);
}
// Safe to assign this alarm because it is either 1) already null, or 2) already fired. In
// either case, there is nothing to cancel.
if (mRetryTimeoutAlarm != null) {
Slog.wtf(TAG, "mRetryTimeoutAlarm should be null before being set");
Slog.wtf(
TAG,
"mRetryTimeoutAlarm should be null before being set; mCurrentToken: "
+ mCurrentToken);
}
final Message delayedMessage = obtainMessage(EVENT_RETRY_TIMEOUT_EXPIRED, mCurrentToken);
@@ -1004,6 +1052,10 @@ public class VcnGatewayConnection extends StateMachine {
}
private void cancelRetryTimeoutAlarm() {
if (VDBG) {
Slog.v(TAG, "Cancel retry alarm; mCurrentToken: " + mCurrentToken);
}
if (mRetryTimeoutAlarm != null) {
mRetryTimeoutAlarm.cancel();
mRetryTimeoutAlarm = null;
@@ -1014,6 +1066,10 @@ public class VcnGatewayConnection extends StateMachine {
@VisibleForTesting(visibility = Visibility.PRIVATE)
void setSafeModeAlarm() {
if (VDBG) {
Slog.v(TAG, "Setting safe mode alarm; mCurrentToken: " + mCurrentToken);
}
// Only schedule a NEW alarm if none is already set.
if (mSafeModeTimeoutAlarm != null) {
return;
@@ -1028,6 +1084,10 @@ public class VcnGatewayConnection extends StateMachine {
}
private void cancelSafeModeAlarm() {
if (VDBG) {
Slog.v(TAG, "Cancel safe mode alarm; mCurrentToken: " + mCurrentToken);
}
if (mSafeModeTimeoutAlarm != null) {
mSafeModeTimeoutAlarm.cancel();
mSafeModeTimeoutAlarm = null;
@@ -1092,6 +1152,15 @@ public class VcnGatewayConnection extends StateMachine {
+ exception.getMessage();
}
Slog.d(
TAG,
"Encountered error; code="
+ errorCode
+ ", exceptionClass="
+ exceptionClass
+ ", exceptionMessage="
+ exceptionMessage);
mGatewayStatusCallback.onGatewayConnectionError(
mConnectionConfig.getGatewayConnectionName(),
errorCode,
@@ -1234,7 +1303,7 @@ public class VcnGatewayConnection extends StateMachine {
protected void handleDisconnectRequested(EventDisconnectRequestedInfo info) {
// TODO(b/180526152): notify VcnStatusCallback for Network loss
Slog.v(TAG, "Tearing down. Cause: " + info.reason);
Slog.d(TAG, "Tearing down. Cause: " + info.reason);
mIsQuitting = info.shouldQuit;
teardownNetwork();
@@ -1250,6 +1319,7 @@ public class VcnGatewayConnection extends StateMachine {
protected void handleSafeModeTimeoutExceeded() {
mSafeModeTimeoutAlarm = null;
Slog.d(TAG, "Entering safe mode after timeout exceeded");
// Connectivity for this GatewayConnection is broken; tear down the Network.
teardownNetwork();
@@ -1722,6 +1792,8 @@ public class VcnGatewayConnection extends StateMachine {
}
private void handleMigrationCompleted(EventMigrationCompletedInfo migrationCompletedInfo) {
Slog.v(TAG, "Migration completed: " + mUnderlying.network);
applyTransform(
mCurrentToken,
mTunnelIface,
@@ -1744,6 +1816,8 @@ public class VcnGatewayConnection extends StateMachine {
mUnderlying = ((EventUnderlyingNetworkChangedInfo) msg.obj).newUnderlying;
if (mUnderlying == null) {
Slog.v(TAG, "Underlying network lost");
// Ignored for now; a new network may be coming up. If none does, the delayed
// NETWORK_LOST disconnect will be fired, and tear down the session + network.
return;