Refactor and improve logging.
Test: as follows
- build
- flashed
- booted
- "runtest frameworks-net" passed
- "dumpsys connectivity" shows new log output
Bug: 32163131
Bug: 36504926
Merged-In: Ieb9a8e3f85f41d18056a7827997f12986ff13ca1
Merged-In: I744b048224e0b8bf6fe4da763833b755441c0911
Merged-In: Ic0c384547687572058d5ef62977163b2560bfc69
Merged-In: Iae91c43d1bfd9fbedc88821a0bd3a5168ad3b719
Merged-In: I52606d4375c9b16de03123995737a994ba58b4d7
Merged-In: I35110b6479280abc650e0ee257045d241923faf9
Change-Id: I14d6da18660223f7cace156cb6594ee18928a7b0
(cherry picked from commit 1fdc2e23b5d8136e06cafd7de896b49e5f929c7f)
diff --git a/services/core/java/com/android/server/connectivity/Tethering.java b/services/core/java/com/android/server/connectivity/Tethering.java
index 9c5930b..81a1458 100644
--- a/services/core/java/com/android/server/connectivity/Tethering.java
+++ b/services/core/java/com/android/server/connectivity/Tethering.java
@@ -62,6 +62,7 @@
import android.telephony.TelephonyManager;
import android.text.TextUtils;
import android.util.ArrayMap;
+import android.util.LocalLog;
import android.util.Log;
import android.util.SparseArray;
@@ -146,6 +147,10 @@
}
}
+ private final static int MAX_LOG_RECORDS = 500;
+
+ private final LocalLog mLocalLog = new LocalLog(MAX_LOG_RECORDS);
+
// used to synchronize public access to members
private final Object mPublicSync;
private final Context mContext;
@@ -175,6 +180,7 @@
public Tethering(Context context, INetworkManagementService nmService,
INetworkStatsService statsService, INetworkPolicyManager policyManager,
Looper looper, MockableSystemProperties systemProperties) {
+ mLocalLog.log("CONSTRUCTED");
mContext = context;
mNMService = nmService;
mStatsService = statsService;
@@ -952,7 +958,7 @@
return ConnectivityManager.TETHER_ERROR_NO_ERROR;
}
- // TODO review API - maybe return ArrayList<String> here and below?
+ // TODO review API - figure out how to delete these entirely.
public String[] getTetheredIfaces() {
ArrayList<String> list = new ArrayList<String>();
synchronized (mPublicSync) {
@@ -1072,19 +1078,19 @@
//Add states
mInitialState = new InitialState();
- addState(mInitialState);
mTetherModeAliveState = new TetherModeAliveState();
- addState(mTetherModeAliveState);
-
mSetIpForwardingEnabledErrorState = new SetIpForwardingEnabledErrorState();
- addState(mSetIpForwardingEnabledErrorState);
mSetIpForwardingDisabledErrorState = new SetIpForwardingDisabledErrorState();
- addState(mSetIpForwardingDisabledErrorState);
mStartTetheringErrorState = new StartTetheringErrorState();
- addState(mStartTetheringErrorState);
mStopTetheringErrorState = new StopTetheringErrorState();
- addState(mStopTetheringErrorState);
mSetDnsForwardersErrorState = new SetDnsForwardersErrorState();
+
+ addState(mInitialState);
+ addState(mTetherModeAliveState);
+ addState(mSetIpForwardingEnabledErrorState);
+ addState(mSetIpForwardingDisabledErrorState);
+ addState(mStartTetheringErrorState);
+ addState(mStopTetheringErrorState);
addState(mSetDnsForwardersErrorState);
mNotifyList = new ArrayList<>();
@@ -1092,6 +1098,29 @@
setInitialState(mInitialState);
}
+ class InitialState extends State {
+ @Override
+ public boolean processMessage(Message message) {
+ maybeLogMessage(this, message.what);
+ switch (message.what) {
+ case EVENT_IFACE_SERVING_STATE_ACTIVE:
+ TetherInterfaceStateMachine who = (TetherInterfaceStateMachine)message.obj;
+ if (VDBG) Log.d(TAG, "Tether Mode requested by " + who);
+ handleInterfaceServingStateActive(message.arg1, who);
+ transitionTo(mTetherModeAliveState);
+ break;
+ case EVENT_IFACE_SERVING_STATE_INACTIVE:
+ who = (TetherInterfaceStateMachine)message.obj;
+ if (VDBG) Log.d(TAG, "Tether Mode unrequested by " + who);
+ handleInterfaceServingStateInactive(who);
+ break;
+ default:
+ return NOT_HANDLED;
+ }
+ return HANDLED;
+ }
+ }
+
class TetherMasterUtilState extends State {
@Override
public boolean processMessage(Message m) {
@@ -1112,6 +1141,7 @@
try {
mNMService.setIpForwardingEnabled(true);
} catch (Exception e) {
+ mLocalLog.log("ERROR " + e);
transitionTo(mSetIpForwardingEnabledErrorState);
return false;
}
@@ -1124,10 +1154,12 @@
mNMService.stopTethering();
mNMService.startTethering(cfg.dhcpRanges);
} catch (Exception ee) {
+ mLocalLog.log("ERROR " + ee);
transitionTo(mStartTetheringErrorState);
return false;
}
}
+ mLocalLog.log("SET master tether settings: ON");
return true;
}
@@ -1135,16 +1167,19 @@
try {
mNMService.stopTethering();
} catch (Exception e) {
+ mLocalLog.log("ERROR " + e);
transitionTo(mStopTetheringErrorState);
return false;
}
try {
mNMService.setIpForwardingEnabled(false);
} catch (Exception e) {
+ mLocalLog.log("ERROR " + e);
transitionTo(mSetIpForwardingDisabledErrorState);
return false;
}
transitionTo(mInitialState);
+ mLocalLog.log("SET master tether settings: OFF");
return true;
}
@@ -1268,16 +1303,15 @@
// TODO: remove this invocation of NetworkUtils.makeStrings().
dnsServers = NetworkUtils.makeStrings(dnses);
}
- if (VDBG) {
- Log.d(TAG, "Setting DNS forwarders: Network=" + network +
- ", dnsServers=" + Arrays.toString(dnsServers));
- }
try {
mNMService.setDnsForwarders(network, dnsServers);
+ mLocalLog.log(String.format(
+ "SET DNS forwarders: network=%s dnsServers=[%s]",
+ network, Arrays.toString(dnsServers)));
} catch (Exception e) {
// TODO: Investigate how this can fail and what exactly
// happens if/when such failures occur.
- Log.e(TAG, "Setting DNS forwarders failed!");
+ mLocalLog.log("ERROR setting DNS forwarders failed, " + e);
transitionTo(mSetDnsForwardersErrorState);
}
}
@@ -1463,31 +1497,6 @@
}
}
- class InitialState extends State {
- @Override
- public boolean processMessage(Message message) {
- maybeLogMessage(this, message.what);
- boolean retValue = true;
- switch (message.what) {
- case EVENT_IFACE_SERVING_STATE_ACTIVE:
- TetherInterfaceStateMachine who = (TetherInterfaceStateMachine)message.obj;
- if (VDBG) Log.d(TAG, "Tether Mode requested by " + who);
- handleInterfaceServingStateActive(message.arg1, who);
- transitionTo(mTetherModeAliveState);
- break;
- case EVENT_IFACE_SERVING_STATE_INACTIVE:
- who = (TetherInterfaceStateMachine)message.obj;
- if (VDBG) Log.d(TAG, "Tether Mode unrequested by " + who);
- handleInterfaceServingStateInactive(who);
- break;
- default:
- retValue = false;
- break;
- }
- return retValue;
- }
- }
-
class TetherModeAliveState extends TetherMasterUtilState {
final SimChangeListener simChange = new SimChangeListener(mContext);
boolean mUpstreamWanted = false;
@@ -1495,8 +1504,12 @@
@Override
public void enter() {
- // TODO: examine if we should check the return value.
- turnOnMasterTetherSettings(); // may transition us out
+ // If turning on master tether settings fails, we have already
+ // transitioned to an error state; exit early.
+ if (!turnOnMasterTetherSettings()) {
+ return;
+ }
+
simChange.startListening();
mUpstreamNetworkMonitor.start();
mOffloadController.start();
@@ -1549,14 +1562,16 @@
handleInterfaceServingStateInactive(who);
if (mNotifyList.isEmpty()) {
- turnOffMasterTetherSettings(); // transitions appropriately
- } else {
- if (DBG) {
- Log.d(TAG, "TetherModeAlive still has " + mNotifyList.size() +
- " live requests:");
- for (TetherInterfaceStateMachine o : mNotifyList) {
- Log.d(TAG, " " + o);
- }
+ // transitions appropriately
+ turnOffMasterTetherSettings();
+ break;
+ }
+
+ if (DBG) {
+ Log.d(TAG, "TetherModeAlive still has " + mNotifyList.size() +
+ " live requests:");
+ for (TetherInterfaceStateMachine o : mNotifyList) {
+ Log.d(TAG, " " + o);
}
}
// If there has been a change and an upstream is no
@@ -1770,6 +1785,12 @@
pw.println("Upstream wanted: " + upstreamWanted());
pw.decreaseIndent();
}
+
+ pw.println("Log:");
+ pw.increaseIndent();
+ mLocalLog.readOnlyLocalLog().dump(fd, pw, args);
+ pw.decreaseIndent();
+
pw.decreaseIndent();
}
@@ -1786,10 +1807,8 @@
}
}
- if (DBG) {
- Log.d(TAG, "iface " + iface + " notified that it was in state " + state +
- " with error " + error);
- }
+ mLocalLog.log(String.format("OBSERVED iface=%s state=%s error=%s",
+ iface, state, error));
try {
// Notify that we're tethering (or not) this interface.
diff --git a/tests/net/java/com/android/server/connectivity/TetheringTest.java b/tests/net/java/com/android/server/connectivity/TetheringTest.java
index 7a1c239..3172c6e 100644
--- a/tests/net/java/com/android/server/connectivity/TetheringTest.java
+++ b/tests/net/java/com/android/server/connectivity/TetheringTest.java
@@ -18,12 +18,13 @@
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertTrue;
-import static org.mockito.Mockito.any;
import static org.mockito.Matchers.anyBoolean;
import static org.mockito.Matchers.anyInt;
import static org.mockito.Matchers.anyString;
import static org.mockito.Matchers.eq;
+import static org.mockito.Mockito.any;
import static org.mockito.Mockito.atLeastOnce;
+import static org.mockito.Mockito.doThrow;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.verifyNoMoreInteractions;
@@ -47,6 +48,7 @@
import android.os.Handler;
import android.os.INetworkManagementService;
import android.os.PersistableBundle;
+import android.os.RemoteException;
import android.os.test.TestLooper;
import android.os.UserHandle;
import android.support.test.filters.SmallTest;
@@ -352,6 +354,56 @@
mTethering.getLastTetherError(mTestIfname));
}
- // TODO: Test that a request for hotspot mode doesn't interface with an
+ @Test
+ public void failureEnablingIpForwarding() throws Exception {
+ when(mConnectivityManager.isTetheringSupported()).thenReturn(true);
+ when(mWifiManager.startSoftAp(any(WifiConfiguration.class))).thenReturn(true);
+ doThrow(new RemoteException()).when(mNMService).setIpForwardingEnabled(true);
+
+ // Emulate pressing the WiFi tethering button.
+ mTethering.startTethering(ConnectivityManager.TETHERING_WIFI, null, false);
+ mLooper.dispatchAll();
+ verify(mWifiManager, times(1)).startSoftAp(null);
+ verifyNoMoreInteractions(mWifiManager);
+ verifyNoMoreInteractions(mConnectivityManager);
+ verifyNoMoreInteractions(mNMService);
+
+ // Emulate externally-visible WifiManager effects, causing the
+ // per-interface state machine to start up, and telling us that
+ // tethering mode is to be started.
+ mTethering.interfaceStatusChanged(mTestIfname, true);
+ sendWifiApStateChanged(WifiManager.WIFI_AP_STATE_ENABLED);
+ mLooper.dispatchAll();
+
+ // Activity caused by test_wlan0 becoming available.
+ verify(mNMService, times(1)).listInterfaces();
+ // We verify get/set called twice here: once for setup and once during
+ // teardown because all events happen over the course of the single
+ // dispatchAll() above.
+ verify(mNMService, times(2)).getInterfaceConfig(mTestIfname);
+ verify(mNMService, times(2))
+ .setInterfaceConfig(eq(mTestIfname), any(InterfaceConfiguration.class));
+ verify(mNMService, times(1)).tetherInterface(mTestIfname);
+ verify(mWifiManager).updateInterfaceIpState(
+ mTestIfname, WifiManager.IFACE_IP_MODE_TETHERED);
+ verify(mConnectivityManager, atLeastOnce()).isTetheringSupported();
+ verifyTetheringBroadcast(mTestIfname, ConnectivityManager.EXTRA_AVAILABLE_TETHER);
+ // This is called, but will throw.
+ verify(mNMService, times(1)).setIpForwardingEnabled(true);
+ // This never gets called because of the exception thrown above.
+ verify(mNMService, times(0)).startTethering(any(String[].class));
+ // When the master state machine transitions to an error state it tells
+ // downstream interfaces, which causes us to tell Wi-Fi about the error
+ // so it can take down AP mode.
+ verify(mNMService, times(1)).untetherInterface(mTestIfname);
+ verify(mWifiManager).updateInterfaceIpState(
+ mTestIfname, WifiManager.IFACE_IP_MODE_CONFIGURATION_ERROR);
+
+ verifyNoMoreInteractions(mWifiManager);
+ verifyNoMoreInteractions(mConnectivityManager);
+ verifyNoMoreInteractions(mNMService);
+ }
+
+ // TODO: Test that a request for hotspot mode doesn't interfere with an
// already operating tethering mode interface.
}