Skip to content

Commit 1ed1de7

Browse files
Robert GreenwaltAndroid (Google) Code Review
authored andcommitted
Merge "Modify logging to debug this issue" into jb-dev
2 parents 90fb2dd + 5a0c320 commit 1ed1de7

File tree

3 files changed

+114
-92
lines changed

3 files changed

+114
-92
lines changed

services/java/com/android/server/ConnectivityService.java

Lines changed: 106 additions & 89 deletions
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,7 @@
6666
import android.os.PowerManager;
6767
import android.os.RemoteException;
6868
import android.os.ServiceManager;
69+
import android.os.SystemClock;
6970
import android.os.SystemProperties;
7071
import android.provider.Settings;
7172
import android.text.TextUtils;
@@ -995,120 +996,136 @@ public String toString() {
995996
// javadoc from interface
996997
public int startUsingNetworkFeature(int networkType, String feature,
997998
IBinder binder) {
999+
long startTime = 0;
1000+
if (DBG) {
1001+
startTime = SystemClock.elapsedRealtime();
1002+
}
9981003
if (VDBG) {
9991004
log("startUsingNetworkFeature for net " + networkType + ": " + feature + ", uid="
10001005
+ Binder.getCallingUid());
10011006
}
10021007
enforceChangePermission();
1003-
if (!ConnectivityManager.isNetworkTypeValid(networkType) ||
1004-
mNetConfigs[networkType] == null) {
1005-
return Phone.APN_REQUEST_FAILED;
1006-
}
1007-
1008-
FeatureUser f = new FeatureUser(networkType, feature, binder);
1009-
1010-
// TODO - move this into individual networktrackers
1011-
int usedNetworkType = convertFeatureToNetworkType(networkType, feature);
1008+
try {
1009+
if (!ConnectivityManager.isNetworkTypeValid(networkType) ||
1010+
mNetConfigs[networkType] == null) {
1011+
return Phone.APN_REQUEST_FAILED;
1012+
}
10121013

1013-
if (mProtectedNetworks.contains(usedNetworkType)) {
1014-
enforceConnectivityInternalPermission();
1015-
}
1014+
FeatureUser f = new FeatureUser(networkType, feature, binder);
10161015

1017-
// if UID is restricted, don't allow them to bring up metered APNs
1018-
final boolean networkMetered = isNetworkMeteredUnchecked(usedNetworkType);
1019-
final int uidRules;
1020-
synchronized (mRulesLock) {
1021-
uidRules = mUidRules.get(Binder.getCallingUid(), RULE_ALLOW_ALL);
1022-
}
1023-
if (networkMetered && (uidRules & RULE_REJECT_METERED) != 0) {
1024-
return Phone.APN_REQUEST_FAILED;
1025-
}
1016+
// TODO - move this into individual networktrackers
1017+
int usedNetworkType = convertFeatureToNetworkType(networkType, feature);
10261018

1027-
NetworkStateTracker network = mNetTrackers[usedNetworkType];
1028-
if (network != null) {
1029-
Integer currentPid = new Integer(getCallingPid());
1030-
if (usedNetworkType != networkType) {
1031-
NetworkInfo ni = network.getNetworkInfo();
1019+
if (mProtectedNetworks.contains(usedNetworkType)) {
1020+
enforceConnectivityInternalPermission();
1021+
}
10321022

1033-
if (ni.isAvailable() == false) {
1034-
if (!TextUtils.equals(feature,Phone.FEATURE_ENABLE_DUN_ALWAYS)) {
1035-
if (DBG) log("special network not available ni=" + ni.getTypeName());
1036-
return Phone.APN_TYPE_NOT_AVAILABLE;
1037-
} else {
1038-
// else make the attempt anyway - probably giving REQUEST_STARTED below
1039-
if (DBG) {
1040-
log("special network not available, but try anyway ni=" +
1041-
ni.getTypeName());
1023+
// if UID is restricted, don't allow them to bring up metered APNs
1024+
final boolean networkMetered = isNetworkMeteredUnchecked(usedNetworkType);
1025+
final int uidRules;
1026+
synchronized (mRulesLock) {
1027+
uidRules = mUidRules.get(Binder.getCallingUid(), RULE_ALLOW_ALL);
1028+
}
1029+
if (networkMetered && (uidRules & RULE_REJECT_METERED) != 0) {
1030+
return Phone.APN_REQUEST_FAILED;
1031+
}
1032+
1033+
NetworkStateTracker network = mNetTrackers[usedNetworkType];
1034+
if (network != null) {
1035+
Integer currentPid = new Integer(getCallingPid());
1036+
if (usedNetworkType != networkType) {
1037+
NetworkInfo ni = network.getNetworkInfo();
1038+
1039+
if (ni.isAvailable() == false) {
1040+
if (!TextUtils.equals(feature,Phone.FEATURE_ENABLE_DUN_ALWAYS)) {
1041+
if (DBG) log("special network not available ni=" + ni.getTypeName());
1042+
return Phone.APN_TYPE_NOT_AVAILABLE;
1043+
} else {
1044+
// else make the attempt anyway - probably giving REQUEST_STARTED below
1045+
if (DBG) {
1046+
log("special network not available, but try anyway ni=" +
1047+
ni.getTypeName());
1048+
}
10421049
}
10431050
}
1044-
}
10451051

1046-
int restoreTimer = getRestoreDefaultNetworkDelay(usedNetworkType);
1047-
1048-
synchronized(this) {
1049-
boolean addToList = true;
1050-
if (restoreTimer < 0) {
1051-
// In case there is no timer is specified for the feature,
1052-
// make sure we don't add duplicate entry with the same request.
1053-
for (FeatureUser u : mFeatureUsers) {
1054-
if (u.isSameUser(f)) {
1055-
// Duplicate user is found. Do not add.
1056-
addToList = false;
1057-
break;
1052+
int restoreTimer = getRestoreDefaultNetworkDelay(usedNetworkType);
1053+
1054+
synchronized(this) {
1055+
boolean addToList = true;
1056+
if (restoreTimer < 0) {
1057+
// In case there is no timer is specified for the feature,
1058+
// make sure we don't add duplicate entry with the same request.
1059+
for (FeatureUser u : mFeatureUsers) {
1060+
if (u.isSameUser(f)) {
1061+
// Duplicate user is found. Do not add.
1062+
addToList = false;
1063+
break;
1064+
}
10581065
}
10591066
}
1060-
}
10611067

1062-
if (addToList) mFeatureUsers.add(f);
1063-
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
1064-
// this gets used for per-pid dns when connected
1065-
mNetRequestersPids[usedNetworkType].add(currentPid);
1068+
if (addToList) mFeatureUsers.add(f);
1069+
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
1070+
// this gets used for per-pid dns when connected
1071+
mNetRequestersPids[usedNetworkType].add(currentPid);
1072+
}
10661073
}
1067-
}
10681074

1069-
if (restoreTimer >= 0) {
1070-
mHandler.sendMessageDelayed(
1071-
mHandler.obtainMessage(EVENT_RESTORE_DEFAULT_NETWORK, f), restoreTimer);
1072-
}
1075+
if (restoreTimer >= 0) {
1076+
mHandler.sendMessageDelayed(mHandler.obtainMessage(
1077+
EVENT_RESTORE_DEFAULT_NETWORK, f), restoreTimer);
1078+
}
10731079

1074-
if ((ni.isConnectedOrConnecting() == true) &&
1075-
!network.isTeardownRequested()) {
1076-
if (ni.isConnected() == true) {
1077-
final long token = Binder.clearCallingIdentity();
1078-
try {
1079-
// add the pid-specific dns
1080-
handleDnsConfigurationChange(usedNetworkType);
1081-
if (VDBG) log("special network already active");
1082-
} finally {
1083-
Binder.restoreCallingIdentity(token);
1080+
if ((ni.isConnectedOrConnecting() == true) &&
1081+
!network.isTeardownRequested()) {
1082+
if (ni.isConnected() == true) {
1083+
final long token = Binder.clearCallingIdentity();
1084+
try {
1085+
// add the pid-specific dns
1086+
handleDnsConfigurationChange(usedNetworkType);
1087+
if (VDBG) log("special network already active");
1088+
} finally {
1089+
Binder.restoreCallingIdentity(token);
1090+
}
1091+
return Phone.APN_ALREADY_ACTIVE;
10841092
}
1085-
return Phone.APN_ALREADY_ACTIVE;
1093+
if (VDBG) log("special network already connecting");
1094+
return Phone.APN_REQUEST_STARTED;
10861095
}
1087-
if (VDBG) log("special network already connecting");
1088-
return Phone.APN_REQUEST_STARTED;
1089-
}
10901096

1091-
// check if the radio in play can make another contact
1092-
// assume if cannot for now
1097+
// check if the radio in play can make another contact
1098+
// assume if cannot for now
10931099

1094-
if (DBG) {
1095-
log("startUsingNetworkFeature reconnecting to " + networkType + ": " + feature);
1096-
}
1097-
network.reconnect();
1098-
return Phone.APN_REQUEST_STARTED;
1099-
} else {
1100-
// need to remember this unsupported request so we respond appropriately on stop
1101-
synchronized(this) {
1102-
mFeatureUsers.add(f);
1103-
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
1104-
// this gets used for per-pid dns when connected
1105-
mNetRequestersPids[usedNetworkType].add(currentPid);
1100+
if (DBG) {
1101+
log("startUsingNetworkFeature reconnecting to " + networkType + ": " +
1102+
feature);
1103+
}
1104+
network.reconnect();
1105+
return Phone.APN_REQUEST_STARTED;
1106+
} else {
1107+
// need to remember this unsupported request so we respond appropriately on stop
1108+
synchronized(this) {
1109+
mFeatureUsers.add(f);
1110+
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
1111+
// this gets used for per-pid dns when connected
1112+
mNetRequestersPids[usedNetworkType].add(currentPid);
1113+
}
11061114
}
1115+
return -1;
11071116
}
1108-
return -1;
11091117
}
1110-
}
1111-
return Phone.APN_TYPE_NOT_AVAILABLE;
1118+
return Phone.APN_TYPE_NOT_AVAILABLE;
1119+
} finally {
1120+
if (DBG) {
1121+
final long execTime = SystemClock.elapsedRealtime() - startTime;
1122+
if (execTime > 250) {
1123+
loge("startUsingNetworkFeature took too long: " + execTime + "ms");
1124+
} else {
1125+
if (VDBG) log("startUsingNetworkFeature took " + execTime + "ms");
1126+
}
1127+
}
1128+
}
11121129
}
11131130

11141131
// javadoc from interface

services/java/com/android/server/NativeDaemonConnector.java

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -58,6 +58,7 @@ final class NativeDaemonConnector implements Runnable, Handler.Callback, Watchdo
5858
private AtomicInteger mSequenceNumber;
5959

6060
private static final int DEFAULT_TIMEOUT = 1 * 60 * 1000; /* 1 minute */
61+
private static final long WARN_EXECUTE_DELAY_MS = 500; /* .5 sec */
6162

6263
/** Lock held whenever communicating with native daemon. */
6364
private final Object mDaemonLock = new Object();
@@ -148,7 +149,6 @@ private void listenToSocket() throws IOException {
148149
mCallbackHandler.sendMessage(mCallbackHandler.obtainMessage(
149150
event.getCode(), event.getRawEvent()));
150151
} else {
151-
log("POST<- {" + rawEvent + "}");
152152
mResponseQueue.add(event.getCmdNumber(), event);
153153
}
154154
} catch (IllegalArgumentException e) {
@@ -300,6 +300,7 @@ public NativeDaemonEvent[] execute(int timeout, String cmd, Object... args)
300300
final int sequenceNumber = mSequenceNumber.incrementAndGet();
301301
final StringBuilder cmdBuilder =
302302
new StringBuilder(Integer.toString(sequenceNumber)).append(' ');
303+
final long startTime = SystemClock.elapsedRealtime();
303304

304305
makeCommand(cmdBuilder, cmd, args);
305306

@@ -332,14 +333,18 @@ public NativeDaemonEvent[] execute(int timeout, String cmd, Object... args)
332333
events.add(event);
333334
} while (event.isClassContinue());
334335

336+
final long endTime = SystemClock.elapsedRealtime();
337+
if (endTime - startTime > WARN_EXECUTE_DELAY_MS) {
338+
loge("NDC Command {" + logCmd + "} took too long (" + (endTime - startTime) + "ms)");
339+
}
340+
335341
if (event.isClassClientError()) {
336342
throw new NativeDaemonArgumentException(logCmd, event);
337343
}
338344
if (event.isClassServerError()) {
339345
throw new NativeDaemonFailureException(logCmd, event);
340346
}
341347

342-
log("RTN <- {" + logCmd + "}");
343348
return events.toArray(new NativeDaemonEvent[events.size()]);
344349
}
345350

services/java/com/android/server/NetworkManagementService.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -166,7 +166,7 @@ private NetworkManagementService(Context context) {
166166
}
167167

168168
mConnector = new NativeDaemonConnector(
169-
new NetdCallbackReceiver(), "netd", 10, NETD_TAG, 80);
169+
new NetdCallbackReceiver(), "netd", 10, NETD_TAG, 160);
170170
mThread = new Thread(mConnector, NETD_TAG);
171171

172172
// Add ourself to the Watchdog monitors.

0 commit comments

Comments
 (0)