Put client logs into SharedLog and dump more logs

- Put client logs into SharedLog and dump them to the bugreport
- Adjust log format in bugreport.
- Also dump DiscoveryManager, Advertiser and SocketProvider logs

Before:
  NsdService:
   total records=9
   rec[0]: time=04-12 14:54:31.742 processed=DefaultState org=EnabledState dest=<null> what=REGISTER_CLIENT
   rec[1]: time=04-12 14:54:31.744 processed=EnabledState org=EnabledState dest=<null> what=REGISTER_SERVICE
   rec[2]: time=04-12 14:54:32.649 processed=EnabledState org=EnabledState dest=<null> what=DISCOVER_SERVICES
  curState=EnabledState

After:
NsdService:
 total records=9
 rec[0]: time=04-17 15:05:26.408 processed=DefaultState org=EnabledState dest=<null> what=REGISTER_CLIENT
 rec[1]: time=04-17 15:05:26.409 processed=EnabledState org=EnabledState dest=<null> what=REGISTER_SERVICE
 rec[2]: time=04-17 15:05:27.409 processed=EnabledState org=EnabledState dest=<null> what=DISCOVER_SERVICES
 rec[3]: time=04-17 15:05:28.236 processed=EnabledState org=EnabledState dest=<null> what=MDNS_DISCOVERY_MANAGER_EVENT
 rec[4]: time=04-17 15:05:28.241 processed=EnabledState org=EnabledState dest=<null> what=RESOLVE_SERVICE
 rec[5]: time=04-17 15:05:28.248 processed=EnabledState org=EnabledState dest=<null> what=MDNS_DISCOVERY_MANAGER_EVENT
 rec[6]: time=04-17 15:05:28.255 processed=EnabledState org=EnabledState dest=<null> what=UNREGISTER_SERVICE
 rec[7]: time=04-17 15:05:28.428 processed=DefaultState org=EnabledState dest=<null> what=UNREGISTER_CLIENT
curState=EnabledState

  2023-04-17T15:05:28.428230 - [Client10082-1] Client unregistered. expungeAllRequests!
  2023-04-17T15:05:28.241837 - [Client10082-1] Register a ResolutionListener 4 for service type:_nmt274981618._tcp.local
  2023-04-17T15:05:27.409895 - [Client10082-1] Register a DiscoveryListener 3 for service type:_nmt274981618._tcp.local
  2023-04-17T15:05:26.408015 - [Client10082-1] New client. useJavaBackend=true

Advertiser:
  2023-04-17T15:05:28.252545 - Removing service with ID 2
  2023-04-17T15:05:27.213023 - [testtap0] Probing finished for service 2
  2023-04-17T15:05:26.409607 - Adding service name: ^Nsd.Test|Non-#AsCiI\Characters&\ufffe テスト 測試, type: _nmt274981618._tcp, hostAddresses: , port: 12345, network: null, txtRecord:  with ID 2

DiscoveryManager:
  2023-04-17T15:05:28.428369 - Unregistering listener for serviceType:_nmt274981618._tcp.local
  2023-04-17T15:05:28.247622 - Unregistering listener for serviceType:_nmt274981618._tcp.local
  2023-04-17T15:05:28.241062 - Registering listener for serviceType: _nmt274981618._tcp.local
  2023-04-17T15:05:28.228777 - [_nmt274981618._tcp.local-102] onServiceFound: ^Nsd.Test|Non-#AsCiI\Characters&\ufffe テスト 測試
  2023-04-17T15:05:28.227786 - [_nmt274981618._tcp.local-102] onServiceNameDiscovered: ^Nsd.Test|Non-#AsCiI\Characters&\ufffe テスト 測試
  2023-04-17T15:05:27.409104 - createServiceTypeClient for serviceType:_nmt274981618._tcp.local network:102
  2023-04-17T15:05:27.398075 - Registering listener for serviceType: _nmt274981618._tcp.local

SocketProvider:
  2023-04-17T15:05:34.377599 - Stop monitoring sockets.
  2023-04-17T15:05:28.292106 - Remove socket on net:102
  2023-04-17T15:05:26.441517 - Create socket on net:NetworkAsKey{ network=102 }, ifName:testtap0
  2023-04-17T15:05:26.409005 - Start monitoring sockets.

Bug: 275004614
Test: atest FrameworksNetTests android.net.cts.NsdManagerTest
Change-Id: I41743f47abe5ca75c2a33da674d24d3a7f997d93
This commit is contained in:
Paul Hu
2023-04-13 09:09:30 +08:00
parent 1571df639a
commit eaa99274bd

View File

@@ -44,6 +44,7 @@ import android.net.nsd.INsdServiceConnector;
import android.net.nsd.MDnsManager;
import android.net.nsd.NsdManager;
import android.net.nsd.NsdServiceInfo;
import android.os.Binder;
import android.os.Handler;
import android.os.HandlerThread;
import android.os.IBinder;
@@ -56,10 +57,12 @@ import android.util.Log;
import android.util.SparseArray;
import com.android.internal.annotations.VisibleForTesting;
import com.android.internal.util.IndentingPrintWriter;
import com.android.internal.util.State;
import com.android.internal.util.StateMachine;
import com.android.net.module.util.DeviceConfigUtils;
import com.android.net.module.util.PermissionUtils;
import com.android.net.module.util.SharedLog;
import com.android.server.connectivity.mdns.ExecutorProvider;
import com.android.server.connectivity.mdns.MdnsAdvertiser;
import com.android.server.connectivity.mdns.MdnsDiscoveryManager;
@@ -159,6 +162,7 @@ public class NsdService extends INsdManager.Stub {
private final MdnsSocketProvider mMdnsSocketProvider;
@NonNull
private final MdnsAdvertiser mAdvertiser;
private final SharedLog mServiceLogs = new SharedLog(TAG);
// WARNING : Accessing these values in any thread is not safe, it must only be changed in the
// state machine thread. If change this outside state machine, it will need to introduce
// synchronization.
@@ -179,6 +183,8 @@ public class NsdService extends INsdManager.Stub {
private int mUniqueId = 1;
// The count of the connected legacy clients.
private int mLegacyClientCount = 0;
// The number of client that ever connected.
private int mClientNumberId = 1;
private static class MdnsListener implements MdnsServiceBrowserListener {
protected final int mClientId;
@@ -332,6 +338,7 @@ public class NsdService extends INsdManager.Stub {
mMDnsManager.startDaemon();
mIsDaemonStarted = true;
maybeScheduleStop();
mServiceLogs.log("Start mdns_responder daemon");
}
private void maybeStopDaemon() {
@@ -342,6 +349,7 @@ public class NsdService extends INsdManager.Stub {
mMDnsManager.unregisterEventListener(mMDnsEventCallback);
mMDnsManager.stopDaemon();
mIsDaemonStarted = false;
mServiceLogs.log("Stop mdns_responder daemon");
}
private boolean isAnyRequestActive() {
@@ -401,7 +409,9 @@ public class NsdService extends INsdManager.Stub {
final INsdManagerCallback cb = arg.callback;
try {
cb.asBinder().linkToDeath(arg.connector, 0);
cInfo = new ClientInfo(cb, arg.useJavaBackend);
final String tag = "Client" + arg.uid + "-" + mClientNumberId++;
cInfo = new ClientInfo(cb, arg.useJavaBackend,
mServiceLogs.forSubComponent(tag));
mClients.put(arg.connector, cInfo);
} catch (RemoteException e) {
Log.w(TAG, "Client " + clientId + " has already died");
@@ -628,6 +638,8 @@ public class NsdService extends INsdManager.Stub {
listenServiceType, listener, options);
storeDiscoveryManagerRequestMap(clientId, id, listener, clientInfo);
clientInfo.onDiscoverServicesStarted(clientId, info);
clientInfo.log("Register a DiscoveryListener " + id
+ " for service type:" + listenServiceType);
} else {
maybeStartDaemon();
if (discoverServices(id, info)) {
@@ -669,6 +681,7 @@ public class NsdService extends INsdManager.Stub {
if (request instanceof DiscoveryManagerRequest) {
stopDiscoveryManagerRequest(request, clientId, id, clientInfo);
clientInfo.onStopDiscoverySucceeded(clientId);
clientInfo.log("Unregister the DiscoveryListener " + id);
} else {
removeRequestMap(clientId, id, clientInfo);
if (stopServiceDiscovery(id)) {
@@ -804,6 +817,8 @@ public class NsdService extends INsdManager.Stub {
mMdnsDiscoveryManager.registerListener(
resolveServiceType, listener, options);
storeDiscoveryManagerRequestMap(clientId, id, listener, clientInfo);
clientInfo.log("Register a ResolutionListener " + id
+ " for service type:" + resolveServiceType);
} else {
if (clientInfo.mResolvedService != null) {
clientInfo.onResolveServiceFailed(
@@ -846,6 +861,7 @@ public class NsdService extends INsdManager.Stub {
if (request instanceof DiscoveryManagerRequest) {
stopDiscoveryManagerRequest(request, clientId, id, clientInfo);
clientInfo.onStopResolutionSucceeded(clientId);
clientInfo.log("Unregister the ResolutionListener " + id);
} else {
removeRequestMap(clientId, id, clientInfo);
if (stopResolveService(id)) {
@@ -891,6 +907,8 @@ public class NsdService extends INsdManager.Stub {
mMdnsDiscoveryManager.registerListener(
resolveServiceType, listener, options);
storeDiscoveryManagerRequestMap(clientId, id, listener, clientInfo);
clientInfo.log("Register a ServiceInfoListener " + id
+ " for service type:" + resolveServiceType);
break;
}
case NsdManager.UNREGISTER_SERVICE_CALLBACK: {
@@ -914,6 +932,7 @@ public class NsdService extends INsdManager.Stub {
if (request instanceof DiscoveryManagerRequest) {
stopDiscoveryManagerRequest(request, clientId, id, clientInfo);
clientInfo.onServiceInfoCallbackUnregistered(clientId);
clientInfo.log("Unregister the ServiceInfoListener " + id);
} else {
loge("Unregister failed with non-DiscoveryManagerRequest.");
}
@@ -1545,12 +1564,14 @@ public class NsdService extends INsdManager.Stub {
@NonNull public final NsdServiceConnector connector;
@NonNull public final INsdManagerCallback callback;
public final boolean useJavaBackend;
public final int uid;
ConnectorArgs(@NonNull NsdServiceConnector connector, @NonNull INsdManagerCallback callback,
boolean useJavaBackend) {
boolean useJavaBackend, int uid) {
this.connector = connector;
this.callback = callback;
this.useJavaBackend = useJavaBackend;
this.uid = uid;
}
}
@@ -1559,9 +1580,9 @@ public class NsdService extends INsdManager.Stub {
mContext.enforceCallingOrSelfPermission(android.Manifest.permission.INTERNET, "NsdService");
if (DBG) Log.d(TAG, "New client connect. useJavaBackend=" + useJavaBackend);
final INsdServiceConnector connector = new NsdServiceConnector();
mNsdStateMachine.sendMessage(mNsdStateMachine.obtainMessage(
NsdManager.REGISTER_CLIENT,
new ConnectorArgs((NsdServiceConnector) connector, cb, useJavaBackend)));
mNsdStateMachine.sendMessage(mNsdStateMachine.obtainMessage(NsdManager.REGISTER_CLIENT,
new ConnectorArgs((NsdServiceConnector) connector, cb, useJavaBackend,
Binder.getCallingUid())));
return connector;
}
@@ -1760,15 +1781,39 @@ public class NsdService extends INsdManager.Stub {
}
@Override
public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
if (!PermissionUtils.checkDumpPermission(mContext, TAG, pw)) return;
for (ClientInfo client : mClients.values()) {
pw.println("Client Info");
pw.println(client);
}
public void dump(FileDescriptor fd, PrintWriter writer, String[] args) {
if (!PermissionUtils.checkDumpPermission(mContext, TAG, writer)) return;
final IndentingPrintWriter pw = new IndentingPrintWriter(writer, " ");
// Dump state machine logs
mNsdStateMachine.dump(fd, pw, args);
// Dump service and clients logs
pw.println();
pw.increaseIndent();
mServiceLogs.reverseDump(pw);
pw.decreaseIndent();
// Dump advertiser related logs
pw.println();
pw.println("Advertiser:");
pw.increaseIndent();
mAdvertiser.dump(pw);
pw.decreaseIndent();
// Dump discoverymanager related logs
pw.println();
pw.println("DiscoveryManager:");
pw.increaseIndent();
mMdnsDiscoveryManager.dump(pw);
pw.decreaseIndent();
// Dump socketprovider related logs
pw.println();
pw.println("SocketProvider:");
pw.increaseIndent();
mMdnsSocketProvider.dump(pw);
pw.decreaseIndent();
}
private abstract static class ClientRequest {
@@ -1819,11 +1864,14 @@ public class NsdService extends INsdManager.Stub {
private boolean mIsPreSClient = false;
// The flag of using java backend if the client's target SDK >= U
private final boolean mUseJavaBackend;
// Store client logs
private final SharedLog mClientLogs;
private ClientInfo(INsdManagerCallback cb, boolean useJavaBackend) {
private ClientInfo(INsdManagerCallback cb, boolean useJavaBackend, SharedLog sharedLog) {
mCb = cb;
mUseJavaBackend = useJavaBackend;
if (DBG) Log.d(TAG, "New client");
mClientLogs = sharedLog;
mClientLogs.log("New client. useJavaBackend=" + useJavaBackend);
}
@Override
@@ -1861,6 +1909,7 @@ public class NsdService extends INsdManager.Stub {
// Remove any pending requests from the global map when we get rid of a client,
// and send cancellations to the daemon.
private void expungeAllRequests() {
mClientLogs.log("Client unregistered. expungeAllRequests!");
// TODO: to keep handler responsive, do not clean all requests for that client at once.
for (int i = 0; i < mClientRequests.size(); i++) {
final int clientId = mClientRequests.keyAt(i);
@@ -1915,6 +1964,10 @@ public class NsdService extends INsdManager.Stub {
return -1;
}
private void log(String message) {
mClientLogs.log(message);
}
void onDiscoverServicesStarted(int listenerKey, NsdServiceInfo info) {
try {
mCb.onDiscoverServicesStarted(listenerKey, info);