From 1fdc2e23b5d8136e06cafd7de896b49e5f929c7f Mon Sep 17 00:00:00 2001 From: Erik Kline Date: Mon, 8 May 2017 17:56:35 +0900 Subject: [PATCH] Refactor and improve logging. Test: as follows - build - flashed - booted - "runtest frameworks-net" passed - "dumpsys connectivity" shows new log output Bug: 32163131 Bug: 36504926 Change-Id: I14d6da18660223f7cace156cb6594ee18928a7b0 --- .../com/android/server/connectivity/Tethering.java | 123 ++++++++++++--------- .../android/server/connectivity/TetheringTest.java | 56 +++++++++- 2 files changed, 125 insertions(+), 54 deletions(-) diff --git a/services/core/java/com/android/server/connectivity/Tethering.java b/services/core/java/com/android/server/connectivity/Tethering.java index 9edc35e20564..4dae36411844 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.CarrierConfigManager; import android.telephony.TelephonyManager; import android.text.TextUtils; import android.util.ArrayMap; +import android.util.LocalLog; import android.util.Log; import android.util.SparseArray; @@ -144,6 +145,10 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering } } + 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; @@ -174,6 +179,7 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering public Tethering(Context context, INetworkManagementService nmService, INetworkStatsService statsService, INetworkPolicyManager policyManager, Looper looper, MockableSystemProperties systemProperties) { + mLocalLog.log("CONSTRUCTED"); mContext = context; mNMService = nmService; mStatsService = statsService; @@ -963,7 +969,7 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering return ConnectivityManager.TETHER_ERROR_NO_ERROR; } - // TODO review API - maybe return ArrayList here and below? + // TODO review API - figure out how to delete these entirely. public String[] getTetheredIfaces() { ArrayList list = new ArrayList(); synchronized (mPublicSync) { @@ -1106,19 +1112,19 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering //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<>(); @@ -1126,6 +1132,29 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering 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) { @@ -1146,6 +1175,7 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering try { mNMService.setIpForwardingEnabled(true); } catch (Exception e) { + mLocalLog.log("ERROR " + e); transitionTo(mSetIpForwardingEnabledErrorState); return false; } @@ -1158,10 +1188,12 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering 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; } @@ -1169,16 +1201,19 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering 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; } @@ -1302,16 +1337,15 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering // 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); } } @@ -1376,39 +1410,18 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering } } - 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 { boolean mUpstreamWanted = false; boolean mTryCell = true; @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; + } + mSimChange.startListening(); mUpstreamNetworkMonitor.start(); mOffloadController.start(); @@ -1461,14 +1474,16 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering 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 @@ -1688,6 +1703,12 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering pw.println("Upstream wanted: " + upstreamWanted()); pw.decreaseIndent(); } + + pw.println("Log:"); + pw.increaseIndent(); + mLocalLog.readOnlyLocalLog().dump(fd, pw, args); + pw.decreaseIndent(); + pw.decreaseIndent(); } @@ -1704,10 +1725,8 @@ public class Tethering extends BaseNetworkObserver implements IControlsTethering } } - 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 7a1c2395c438..3172c6ec856a 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 @@ package com.android.server.connectivity; 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.net.wifi.WifiManager; 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 @@ public class TetheringTest { 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. } -- 2.11.0