diff options
5 files changed, 130 insertions, 18 deletions
diff --git a/core/java/android/net/vcn/VcnNetworkPolicyResult.java b/core/java/android/net/vcn/VcnNetworkPolicyResult.java index 5e938200639c..14e70cfeb18a 100644 --- a/core/java/android/net/vcn/VcnNetworkPolicyResult.java +++ b/core/java/android/net/vcn/VcnNetworkPolicyResult.java @@ -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() { diff --git a/core/java/android/net/vcn/VcnUnderlyingNetworkPolicy.java b/core/java/android/net/vcn/VcnUnderlyingNetworkPolicy.java index b47d5642419e..b0d4f3be248f 100644 --- a/core/java/android/net/vcn/VcnUnderlyingNetworkPolicy.java +++ b/core/java/android/net/vcn/VcnUnderlyingNetworkPolicy.java @@ -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() { diff --git a/services/core/java/com/android/server/VcnManagementService.java b/services/core/java/com/android/server/VcnManagementService.java index 471d2af2784f..1fd637ad20c4 100644 --- a/services/core/java/com/android/server/VcnManagementService.java +++ b/services/core/java/com/android/server/VcnManagementService.java @@ -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; }); } diff --git a/services/core/java/com/android/server/vcn/Vcn.java b/services/core/java/com/android/server/vcn/Vcn.java index e1747f71d5a9..edb042fd344e 100644 --- a/services/core/java/com/android/server/vcn/Vcn.java +++ b/services/core/java/com/android/server/vcn/Vcn.java @@ -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()) { diff --git a/services/core/java/com/android/server/vcn/VcnGatewayConnection.java b/services/core/java/com/android/server/vcn/VcnGatewayConnection.java index 65b947c1fcdd..46fd22810a58 100644 --- a/services/core/java/com/android/server/vcn/VcnGatewayConnection.java +++ b/services/core/java/com/android/server/vcn/VcnGatewayConnection.java @@ -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; |