am 1ed1de7a: Merge "Modify logging to debug this issue" into jb-dev

* commit '1ed1de7ab2ae03f82500dbf6272bf036d89bd0c9':
  Modify logging to debug this issue
This commit is contained in:
Robert Greenwalt
2012-05-24 12:30:20 -07:00
committed by Android Git Automerger
3 changed files with 117 additions and 95 deletions

View File

@@ -66,6 +66,7 @@ import android.os.ParcelFileDescriptor;
import android.os.PowerManager; import android.os.PowerManager;
import android.os.RemoteException; import android.os.RemoteException;
import android.os.ServiceManager; import android.os.ServiceManager;
import android.os.SystemClock;
import android.os.SystemProperties; import android.os.SystemProperties;
import android.provider.Settings; import android.provider.Settings;
import android.text.TextUtils; import android.text.TextUtils;
@@ -995,120 +996,136 @@ private NetworkStateTracker makeWimaxStateTracker() {
// javadoc from interface // javadoc from interface
public int startUsingNetworkFeature(int networkType, String feature, public int startUsingNetworkFeature(int networkType, String feature,
IBinder binder) { IBinder binder) {
long startTime = 0;
if (DBG) {
startTime = SystemClock.elapsedRealtime();
}
if (VDBG) { if (VDBG) {
log("startUsingNetworkFeature for net " + networkType + ": " + feature + ", uid=" log("startUsingNetworkFeature for net " + networkType + ": " + feature + ", uid="
+ Binder.getCallingUid()); + Binder.getCallingUid());
} }
enforceChangePermission(); enforceChangePermission();
if (!ConnectivityManager.isNetworkTypeValid(networkType) || try {
mNetConfigs[networkType] == null) { if (!ConnectivityManager.isNetworkTypeValid(networkType) ||
return Phone.APN_REQUEST_FAILED; mNetConfigs[networkType] == null) {
} return Phone.APN_REQUEST_FAILED;
}
FeatureUser f = new FeatureUser(networkType, feature, binder); FeatureUser f = new FeatureUser(networkType, feature, binder);
// TODO - move this into individual networktrackers // TODO - move this into individual networktrackers
int usedNetworkType = convertFeatureToNetworkType(networkType, feature); int usedNetworkType = convertFeatureToNetworkType(networkType, feature);
if (mProtectedNetworks.contains(usedNetworkType)) { if (mProtectedNetworks.contains(usedNetworkType)) {
enforceConnectivityInternalPermission(); enforceConnectivityInternalPermission();
} }
// if UID is restricted, don't allow them to bring up metered APNs // if UID is restricted, don't allow them to bring up metered APNs
final boolean networkMetered = isNetworkMeteredUnchecked(usedNetworkType); final boolean networkMetered = isNetworkMeteredUnchecked(usedNetworkType);
final int uidRules; final int uidRules;
synchronized (mRulesLock) { synchronized (mRulesLock) {
uidRules = mUidRules.get(Binder.getCallingUid(), RULE_ALLOW_ALL); uidRules = mUidRules.get(Binder.getCallingUid(), RULE_ALLOW_ALL);
} }
if (networkMetered && (uidRules & RULE_REJECT_METERED) != 0) { if (networkMetered && (uidRules & RULE_REJECT_METERED) != 0) {
return Phone.APN_REQUEST_FAILED; return Phone.APN_REQUEST_FAILED;
} }
NetworkStateTracker network = mNetTrackers[usedNetworkType]; NetworkStateTracker network = mNetTrackers[usedNetworkType];
if (network != null) { if (network != null) {
Integer currentPid = new Integer(getCallingPid()); Integer currentPid = new Integer(getCallingPid());
if (usedNetworkType != networkType) { if (usedNetworkType != networkType) {
NetworkInfo ni = network.getNetworkInfo(); NetworkInfo ni = network.getNetworkInfo();
if (ni.isAvailable() == false) { if (ni.isAvailable() == false) {
if (!TextUtils.equals(feature,Phone.FEATURE_ENABLE_DUN_ALWAYS)) { if (!TextUtils.equals(feature,Phone.FEATURE_ENABLE_DUN_ALWAYS)) {
if (DBG) log("special network not available ni=" + ni.getTypeName()); if (DBG) log("special network not available ni=" + ni.getTypeName());
return Phone.APN_TYPE_NOT_AVAILABLE; return Phone.APN_TYPE_NOT_AVAILABLE;
} else { } else {
// else make the attempt anyway - probably giving REQUEST_STARTED below // else make the attempt anyway - probably giving REQUEST_STARTED below
if (DBG) { if (DBG) {
log("special network not available, but try anyway ni=" + log("special network not available, but try anyway ni=" +
ni.getTypeName()); ni.getTypeName());
}
}
}
int restoreTimer = getRestoreDefaultNetworkDelay(usedNetworkType);
synchronized(this) {
boolean addToList = true;
if (restoreTimer < 0) {
// In case there is no timer is specified for the feature,
// make sure we don't add duplicate entry with the same request.
for (FeatureUser u : mFeatureUsers) {
if (u.isSameUser(f)) {
// Duplicate user is found. Do not add.
addToList = false;
break;
} }
} }
} }
if (addToList) mFeatureUsers.add(f); int restoreTimer = getRestoreDefaultNetworkDelay(usedNetworkType);
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
// this gets used for per-pid dns when connected
mNetRequestersPids[usedNetworkType].add(currentPid);
}
}
if (restoreTimer >= 0) { synchronized(this) {
mHandler.sendMessageDelayed( boolean addToList = true;
mHandler.obtainMessage(EVENT_RESTORE_DEFAULT_NETWORK, f), restoreTimer); if (restoreTimer < 0) {
} // In case there is no timer is specified for the feature,
// make sure we don't add duplicate entry with the same request.
if ((ni.isConnectedOrConnecting() == true) && for (FeatureUser u : mFeatureUsers) {
!network.isTeardownRequested()) { if (u.isSameUser(f)) {
if (ni.isConnected() == true) { // Duplicate user is found. Do not add.
final long token = Binder.clearCallingIdentity(); addToList = false;
try { break;
// add the pid-specific dns }
handleDnsConfigurationChange(usedNetworkType); }
if (VDBG) log("special network already active"); }
} finally {
Binder.restoreCallingIdentity(token); if (addToList) mFeatureUsers.add(f);
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
// this gets used for per-pid dns when connected
mNetRequestersPids[usedNetworkType].add(currentPid);
} }
return Phone.APN_ALREADY_ACTIVE;
} }
if (VDBG) log("special network already connecting");
if (restoreTimer >= 0) {
mHandler.sendMessageDelayed(mHandler.obtainMessage(
EVENT_RESTORE_DEFAULT_NETWORK, f), restoreTimer);
}
if ((ni.isConnectedOrConnecting() == true) &&
!network.isTeardownRequested()) {
if (ni.isConnected() == true) {
final long token = Binder.clearCallingIdentity();
try {
// add the pid-specific dns
handleDnsConfigurationChange(usedNetworkType);
if (VDBG) log("special network already active");
} finally {
Binder.restoreCallingIdentity(token);
}
return Phone.APN_ALREADY_ACTIVE;
}
if (VDBG) log("special network already connecting");
return Phone.APN_REQUEST_STARTED;
}
// check if the radio in play can make another contact
// assume if cannot for now
if (DBG) {
log("startUsingNetworkFeature reconnecting to " + networkType + ": " +
feature);
}
network.reconnect();
return Phone.APN_REQUEST_STARTED; return Phone.APN_REQUEST_STARTED;
} } else {
// need to remember this unsupported request so we respond appropriately on stop
// check if the radio in play can make another contact synchronized(this) {
// assume if cannot for now mFeatureUsers.add(f);
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
if (DBG) { // this gets used for per-pid dns when connected
log("startUsingNetworkFeature reconnecting to " + networkType + ": " + feature); mNetRequestersPids[usedNetworkType].add(currentPid);
} }
network.reconnect();
return Phone.APN_REQUEST_STARTED;
} else {
// need to remember this unsupported request so we respond appropriately on stop
synchronized(this) {
mFeatureUsers.add(f);
if (!mNetRequestersPids[usedNetworkType].contains(currentPid)) {
// this gets used for per-pid dns when connected
mNetRequestersPids[usedNetworkType].add(currentPid);
} }
return -1;
} }
return -1;
} }
} return Phone.APN_TYPE_NOT_AVAILABLE;
return Phone.APN_TYPE_NOT_AVAILABLE; } finally {
if (DBG) {
final long execTime = SystemClock.elapsedRealtime() - startTime;
if (execTime > 250) {
loge("startUsingNetworkFeature took too long: " + execTime + "ms");
} else {
if (VDBG) log("startUsingNetworkFeature took " + execTime + "ms");
}
}
}
} }
// javadoc from interface // javadoc from interface

View File

@@ -58,6 +58,7 @@ final class NativeDaemonConnector implements Runnable, Handler.Callback, Watchdo
private AtomicInteger mSequenceNumber; private AtomicInteger mSequenceNumber;
private static final int DEFAULT_TIMEOUT = 1 * 60 * 1000; /* 1 minute */ private static final int DEFAULT_TIMEOUT = 1 * 60 * 1000; /* 1 minute */
private static final long WARN_EXECUTE_DELAY_MS = 500; /* .5 sec */
/** Lock held whenever communicating with native daemon. */ /** Lock held whenever communicating with native daemon. */
private final Object mDaemonLock = new Object(); private final Object mDaemonLock = new Object();
@@ -148,7 +149,6 @@ final class NativeDaemonConnector implements Runnable, Handler.Callback, Watchdo
mCallbackHandler.sendMessage(mCallbackHandler.obtainMessage( mCallbackHandler.sendMessage(mCallbackHandler.obtainMessage(
event.getCode(), event.getRawEvent())); event.getCode(), event.getRawEvent()));
} else { } else {
log("POST<- {" + rawEvent + "}");
mResponseQueue.add(event.getCmdNumber(), event); mResponseQueue.add(event.getCmdNumber(), event);
} }
} catch (IllegalArgumentException e) { } catch (IllegalArgumentException e) {
@@ -300,6 +300,7 @@ final class NativeDaemonConnector implements Runnable, Handler.Callback, Watchdo
final int sequenceNumber = mSequenceNumber.incrementAndGet(); final int sequenceNumber = mSequenceNumber.incrementAndGet();
final StringBuilder cmdBuilder = final StringBuilder cmdBuilder =
new StringBuilder(Integer.toString(sequenceNumber)).append(' '); new StringBuilder(Integer.toString(sequenceNumber)).append(' ');
final long startTime = SystemClock.elapsedRealtime();
makeCommand(cmdBuilder, cmd, args); makeCommand(cmdBuilder, cmd, args);
@@ -332,6 +333,11 @@ final class NativeDaemonConnector implements Runnable, Handler.Callback, Watchdo
events.add(event); events.add(event);
} while (event.isClassContinue()); } while (event.isClassContinue());
final long endTime = SystemClock.elapsedRealtime();
if (endTime - startTime > WARN_EXECUTE_DELAY_MS) {
loge("NDC Command {" + logCmd + "} took too long (" + (endTime - startTime) + "ms)");
}
if (event.isClassClientError()) { if (event.isClassClientError()) {
throw new NativeDaemonArgumentException(logCmd, event); throw new NativeDaemonArgumentException(logCmd, event);
} }
@@ -339,7 +345,6 @@ final class NativeDaemonConnector implements Runnable, Handler.Callback, Watchdo
throw new NativeDaemonFailureException(logCmd, event); throw new NativeDaemonFailureException(logCmd, event);
} }
log("RTN <- {" + logCmd + "}");
return events.toArray(new NativeDaemonEvent[events.size()]); return events.toArray(new NativeDaemonEvent[events.size()]);
} }

View File

@@ -166,7 +166,7 @@ public class NetworkManagementService extends INetworkManagementService.Stub
} }
mConnector = new NativeDaemonConnector( mConnector = new NativeDaemonConnector(
new NetdCallbackReceiver(), "netd", 10, NETD_TAG, 80); new NetdCallbackReceiver(), "netd", 10, NETD_TAG, 160);
mThread = new Thread(mConnector, NETD_TAG); mThread = new Thread(mConnector, NETD_TAG);
// Add ourself to the Watchdog monitors. // Add ourself to the Watchdog monitors.