diff --git a/thread/service/java/com/android/server/thread/NsdPublisher.java b/thread/service/java/com/android/server/thread/NsdPublisher.java index 1447ff8457..8d89e13312 100644 --- a/thread/service/java/com/android/server/thread/NsdPublisher.java +++ b/thread/service/java/com/android/server/thread/NsdPublisher.java @@ -31,10 +31,10 @@ import android.os.CancellationSignal; import android.os.Handler; import android.os.RemoteException; import android.text.TextUtils; -import android.util.Log; import android.util.SparseArray; import com.android.internal.annotations.VisibleForTesting; +import com.android.net.module.util.SharedLog; import com.android.server.thread.openthread.DnsTxtAttribute; import com.android.server.thread.openthread.INsdDiscoverServiceCallback; import com.android.server.thread.openthread.INsdPublisher; @@ -62,6 +62,7 @@ import java.util.concurrent.Executor; */ public final class NsdPublisher extends INsdPublisher.Stub { private static final String TAG = NsdPublisher.class.getSimpleName(); + private static final SharedLog LOG = ThreadNetworkLogger.forSubComponent(TAG); // TODO: b/321883491 - specify network for mDNS operations @Nullable private Network mNetwork; @@ -158,8 +159,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { int listenerId, String registrationType) { checkOnHandlerThread(); - Log.i( - TAG, + LOG.i( "Registering " + registrationType + ". Listener ID: " @@ -171,7 +171,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { try { mNsdManager.registerService(serviceInfo, PROTOCOL_DNS_SD, mExecutor, listener); } catch (IllegalArgumentException e) { - Log.i(TAG, "Failed to register service. serviceInfo: " + serviceInfo, e); + LOG.e("Failed to register service. serviceInfo: " + serviceInfo, e); listener.onRegistrationFailed(serviceInfo, NsdManager.FAILURE_INTERNAL_ERROR); } } @@ -184,8 +184,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { checkOnHandlerThread(); RegistrationListener registrationListener = mRegistrationListeners.get(listenerId); if (registrationListener == null) { - Log.w( - TAG, + LOG.w( "Failed to unregister service." + " Listener ID: " + listenerId @@ -193,8 +192,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { return; } - Log.i( - TAG, + LOG.i( "Unregistering service." + " Listener ID: " + listenerId @@ -212,13 +210,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { private void discoverServiceInternal( String type, INsdDiscoverServiceCallback callback, int listenerId) { checkOnHandlerThread(); - Log.i( - TAG, - "Discovering services." - + " Listener ID: " - + listenerId - + ", service type: " - + type); + LOG.i("Discovering services." + " Listener ID: " + listenerId + ", service type: " + type); DiscoveryListener listener = new DiscoveryListener(listenerId, type, callback); mDiscoveryListeners.append(listenerId, listener); @@ -237,15 +229,14 @@ public final class NsdPublisher extends INsdPublisher.Stub { DiscoveryListener listener = mDiscoveryListeners.get(listenerId); if (listener == null) { - Log.w( - TAG, + LOG.w( "Failed to stop service discovery. Listener ID " + listenerId + ". The listener is null."); return; } - Log.i(TAG, "Stopping service discovery. Listener: " + listener); + LOG.i("Stopping service discovery. Listener: " + listener); mNsdManager.stopServiceDiscovery(listener); } @@ -263,8 +254,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { serviceInfo.setServiceName(name); serviceInfo.setServiceType(type); serviceInfo.setNetwork(null); - Log.i( - TAG, + LOG.i( "Resolving service." + " Listener ID: " + listenerId @@ -288,21 +278,19 @@ public final class NsdPublisher extends INsdPublisher.Stub { ServiceInfoListener listener = mServiceInfoListeners.get(listenerId); if (listener == null) { - Log.w( - TAG, + LOG.w( "Failed to stop service resolution. Listener ID: " + listenerId + ". The listener is null."); return; } - Log.i(TAG, "Stopping service resolution. Listener: " + listener); + LOG.i("Stopping service resolution. Listener: " + listener); try { mNsdManager.unregisterServiceInfoCallback(listener); } catch (IllegalArgumentException e) { - Log.w( - TAG, + LOG.w( "Failed to stop the service resolution because it's already stopped. Listener: " + listener); } @@ -330,7 +318,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { listener); mHostInfoListeners.append(listenerId, listener); - Log.i(TAG, "Resolving host." + " Listener ID: " + listenerId + ", hostname: " + name); + LOG.i("Resolving host." + " Listener ID: " + listenerId + ", hostname: " + name); } @Override @@ -343,14 +331,13 @@ public final class NsdPublisher extends INsdPublisher.Stub { HostInfoListener listener = mHostInfoListeners.get(listenerId); if (listener == null) { - Log.w( - TAG, + LOG.w( "Failed to stop host resolution. Listener ID: " + listenerId + ". The listener is null."); return; } - Log.i(TAG, "Stopping host resolution. Listener: " + listener); + LOG.i("Stopping host resolution. Listener: " + listener); listener.cancel(); mHostInfoListeners.remove(listenerId); } @@ -373,14 +360,14 @@ public final class NsdPublisher extends INsdPublisher.Stub { try { mNsdManager.unregisterService(mRegistrationListeners.valueAt(i)); } catch (IllegalArgumentException e) { - Log.i( - TAG, + LOG.i( "Failed to unregister." + " Listener ID: " + mRegistrationListeners.keyAt(i) + " serviceInfo: " - + mRegistrationListeners.valueAt(i).mServiceInfo, - e); + + mRegistrationListeners.valueAt(i).mServiceInfo + + ", error: " + + e.getMessage()); } } mRegistrationListeners.clear(); @@ -415,8 +402,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { public void onRegistrationFailed(NsdServiceInfo serviceInfo, int errorCode) { checkOnHandlerThread(); mRegistrationListeners.remove(mListenerId); - Log.i( - TAG, + LOG.i( "Failed to register listener ID: " + mListenerId + " error code: " @@ -434,8 +420,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { public void onUnregistrationFailed(NsdServiceInfo serviceInfo, int errorCode) { checkOnHandlerThread(); for (INsdStatusReceiver receiver : mUnregistrationReceivers) { - Log.i( - TAG, + LOG.i( "Failed to unregister." + "Listener ID: " + mListenerId @@ -454,8 +439,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onServiceRegistered(NsdServiceInfo serviceInfo) { checkOnHandlerThread(); - Log.i( - TAG, + LOG.i( "Registered successfully. " + "Listener ID: " + mListenerId @@ -472,8 +456,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { public void onServiceUnregistered(NsdServiceInfo serviceInfo) { checkOnHandlerThread(); for (INsdStatusReceiver receiver : mUnregistrationReceivers) { - Log.i( - TAG, + LOG.i( "Unregistered successfully. " + "Listener ID: " + mListenerId @@ -505,8 +488,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onStartDiscoveryFailed(String serviceType, int errorCode) { - Log.e( - TAG, + LOG.e( "Failed to start service discovery." + " Error code: " + errorCode @@ -517,8 +499,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onStopDiscoveryFailed(String serviceType, int errorCode) { - Log.e( - TAG, + LOG.e( "Failed to stop service discovery." + " Error code: " + errorCode @@ -529,18 +510,18 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onDiscoveryStarted(String serviceType) { - Log.i(TAG, "Started service discovery. Listener: " + this); + LOG.i("Started service discovery. Listener: " + this); } @Override public void onDiscoveryStopped(String serviceType) { - Log.i(TAG, "Stopped service discovery. Listener: " + this); + LOG.i("Stopped service discovery. Listener: " + this); mDiscoveryListeners.remove(mListenerId); } @Override public void onServiceFound(NsdServiceInfo serviceInfo) { - Log.i(TAG, "Found service: " + serviceInfo); + LOG.i("Found service: " + serviceInfo); try { mDiscoverServiceCallback.onServiceDiscovered( serviceInfo.getServiceName(), mType, true); @@ -551,7 +532,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onServiceLost(NsdServiceInfo serviceInfo) { - Log.i(TAG, "Lost service: " + serviceInfo); + LOG.i("Lost service: " + serviceInfo); try { mDiscoverServiceCallback.onServiceDiscovered( serviceInfo.getServiceName(), mType, false); @@ -584,8 +565,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onServiceInfoCallbackRegistrationFailed(int errorCode) { - Log.e( - TAG, + LOG.e( "Failed to register service info callback." + " Listener ID: " + mListenerId @@ -599,8 +579,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onServiceUpdated(@NonNull NsdServiceInfo serviceInfo) { - Log.i( - TAG, + LOG.i( "Service is resolved. " + " Listener ID: " + mListenerId @@ -640,7 +619,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { @Override public void onServiceInfoCallbackUnregistered() { - Log.i(TAG, "The service info callback is unregistered. Listener: " + this); + LOG.i("The service info callback is unregistered. Listener: " + this); mServiceInfoListeners.remove(mListenerId); } @@ -671,8 +650,7 @@ public final class NsdPublisher extends INsdPublisher.Stub { public void onAnswer(@NonNull List answerList, int rcode) { checkOnHandlerThread(); - Log.i( - TAG, + LOG.i( "Host is resolved." + " Listener ID: " + mListenerId @@ -698,14 +676,14 @@ public final class NsdPublisher extends INsdPublisher.Stub { public void onError(@NonNull DnsResolver.DnsException error) { checkOnHandlerThread(); - Log.i( - TAG, + LOG.i( "Failed to resolve host." + " Listener ID: " + mListenerId + ", hostname: " - + mHostname, - error); + + mHostname + + ", error: " + + error.getMessage()); try { mResolveHostCallback.onHostResolved(mHostname, Collections.emptyList()); } catch (RemoteException e) { diff --git a/thread/service/java/com/android/server/thread/ThreadNetworkControllerService.java b/thread/service/java/com/android/server/thread/ThreadNetworkControllerService.java index 93b2f70595..13817cfb5b 100644 --- a/thread/service/java/com/android/server/thread/ThreadNetworkControllerService.java +++ b/thread/service/java/com/android/server/thread/ThreadNetworkControllerService.java @@ -112,11 +112,11 @@ import android.os.ParcelFileDescriptor; import android.os.RemoteException; import android.os.SystemClock; import android.os.UserManager; -import android.util.Log; import android.util.SparseArray; import com.android.connectivity.resources.R; import com.android.internal.annotations.VisibleForTesting; +import com.android.net.module.util.SharedLog; import com.android.server.ServiceManagerWrapper; import com.android.server.connectivity.ConnectivityResources; import com.android.server.thread.openthread.BackboneRouterState; @@ -160,7 +160,8 @@ import java.util.regex.Pattern; */ @TargetApi(Build.VERSION_CODES.UPSIDE_DOWN_CAKE) final class ThreadNetworkControllerService extends IThreadNetworkController.Stub { - private static final String TAG = "ThreadNetworkService"; + private static final String TAG = "ControllerService"; + private static final SharedLog LOG = ThreadNetworkLogger.forSubComponent(TAG); // The model name length in utf-8 bytes private static final int MAX_MODEL_NAME_UTF8_BYTES = 24; @@ -303,12 +304,12 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub return; } - Log.i(TAG, "Starting OT daemon..."); + LOG.i("Starting OT daemon..."); try { getOtDaemon(); } catch (RemoteException e) { - Log.e(TAG, "Failed to initialize ot-daemon", e); + LOG.e("Failed to initialize ot-daemon", e); } catch (ThreadNetworkException e) { // no ThreadNetworkException.ERROR_THREAD_DISABLED error should be thrown throw new AssertionError(e); @@ -422,7 +423,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub private void onOtDaemonDied() { checkOnHandlerThread(); - Log.w(TAG, "OT daemon is dead, clean up..."); + LOG.w("OT daemon is dead, clean up..."); OperationReceiverWrapper.onOtDaemonDied(); mOtDaemonCallbackProxy.onOtDaemonDied(); @@ -435,8 +436,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub public void initialize() { mHandler.post( () -> { - Log.d( - TAG, + LOG.v( "Initializing Thread system service: Thread is " + (shouldEnableThread() ? "enabled" : "disabled")); try { @@ -493,7 +493,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub // become dead, so that it's guaranteed that ot-daemon is stopped when {@code // receiver} is completed } catch (RemoteException e) { - Log.e(TAG, "otDaemon.terminate failed", e); + LOG.e("otDaemon.terminate failed", e); receiver.onError(ERROR_INTERNAL_ERROR, "Thread stack error"); } catch (ThreadNetworkException e) { // No ThreadNetworkException.ERROR_THREAD_DISABLED error will be thrown @@ -524,7 +524,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub return; } - Log.i(TAG, "Set Thread enabled: " + isEnabled + ", persist: " + persist); + LOG.i("Set Thread enabled: " + isEnabled + ", persist: " + persist); if (persist) { // The persistent setting keeps the desired enabled state, thus it's set regardless @@ -536,7 +536,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub try { getOtDaemon().setThreadEnabled(isEnabled, newOtStatusReceiver(receiver)); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.setThreadEnabled failed", e); + LOG.e("otDaemon.setThreadEnabled failed", e); receiver.onError(e); } } @@ -553,7 +553,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub @NonNull IOperationReceiver operationReceiver) { checkOnHandlerThread(); - Log.i(TAG, "Set Thread configuration: " + configuration); + LOG.i("Set Thread configuration: " + configuration); final boolean changed = mPersistentSettings.putConfiguration(configuration); try { @@ -631,8 +631,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub if (mUserRestricted == newUserRestrictedState) { return; } - Log.i( - TAG, + LOG.i( "Thread user restriction changed: " + mUserRestricted + " -> " @@ -644,16 +643,14 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub new IOperationReceiver.Stub() { @Override public void onSuccess() { - Log.d( - TAG, + LOG.v( (shouldEnableThread ? "Enabled" : "Disabled") + " Thread due to user restriction change"); } @Override public void onError(int errorCode, String errorMessage) { - Log.e( - TAG, + LOG.e( "Failed to " + (shouldEnableThread ? "enable" : "disable") + " Thread for user restriction change"); @@ -702,13 +699,13 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub @Override public void onAvailable(@NonNull Network network) { checkOnHandlerThread(); - Log.i(TAG, "Upstream network available: " + network); + LOG.i("Upstream network available: " + network); } @Override public void onLost(@NonNull Network network) { checkOnHandlerThread(); - Log.i(TAG, "Upstream network lost: " + network); + LOG.i("Upstream network lost: " + network); // TODO: disable border routing when upsteam network disconnected } @@ -723,7 +720,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub if (Objects.equals(existingIfName, newIfName)) { return; } - Log.i(TAG, "Upstream network changed: " + existingIfName + " -> " + newIfName); + LOG.i("Upstream network changed: " + existingIfName + " -> " + newIfName); mNetworkToInterface.put(network, newIfName); // TODO: disable border routing if netIfName is null @@ -737,13 +734,13 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub @Override public void onAvailable(@NonNull Network network) { checkOnHandlerThread(); - Log.i(TAG, "Thread network is available: " + network); + LOG.i("Thread network is available: " + network); } @Override public void onLost(@NonNull Network network) { checkOnHandlerThread(); - Log.i(TAG, "Thread network is lost: " + network); + LOG.i("Thread network is lost: " + network); disableBorderRouting(); } @@ -751,8 +748,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub public void onLocalNetworkInfoChanged( @NonNull Network network, @NonNull LocalNetworkInfo localNetworkInfo) { checkOnHandlerThread(); - Log.i( - TAG, + LOG.i( "LocalNetworkInfo of Thread network changed: {threadNetwork: " + network + ", localNetworkInfo: " @@ -810,7 +806,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub return new NetworkAgent( mContext, mHandler.getLooper(), - TAG, + LOG.getTag(), netCaps, mTunIfController.getLinkProperties(), newLocalNetworkConfig(), @@ -827,7 +823,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub mNetworkAgent = newNetworkAgent(); mNetworkAgent.register(); mNetworkAgent.markConnected(); - Log.i(TAG, "Registered Thread network"); + LOG.i("Registered Thread network"); } private void unregisterThreadNetwork() { @@ -837,7 +833,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub return; } - Log.d(TAG, "Unregistering Thread network agent"); + LOG.v("Unregistering Thread network agent"); mNetworkAgent.unregister(); mNetworkAgent = null; @@ -863,7 +859,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub try { getOtDaemon().getChannelMasks(newChannelMasksReceiver(networkName, receiver)); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.getChannelMasks failed", e); + LOG.e("otDaemon.getChannelMasks failed", e); receiver.onError(e); } } @@ -904,7 +900,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub now = clock.instant(); authoritative = true; } catch (DateTimeException e) { - Log.w(TAG, "Failed to get authoritative time", e); + LOG.w("Failed to get authoritative time: " + e.getMessage()); } int panId = random.nextInt(/* bound= */ 0xffff); @@ -1095,7 +1091,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub // The otDaemon.join() will leave first if this device is currently attached getOtDaemon().join(activeDataset.toThreadTlvs(), newOtStatusReceiver(receiver)); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.join failed", e); + LOG.e("otDaemon.join failed", e); receiver.onError(e); } } @@ -1120,7 +1116,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub .scheduleMigration( pendingDataset.toThreadTlvs(), newOtStatusReceiver(receiver)); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.scheduleMigration failed", e); + LOG.e("otDaemon.scheduleMigration failed", e); receiver.onError(e); } } @@ -1138,7 +1134,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub try { getOtDaemon().leave(newOtStatusReceiver(receiver)); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.leave failed", e); + LOG.e("otDaemon.leave failed", e); receiver.onError(e); } } @@ -1171,7 +1167,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub try { getOtDaemon().setCountryCode(countryCode, newOtStatusReceiver(receiver)); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.setCountryCode failed", e); + LOG.e("otDaemon.setCountryCode failed", e); receiver.onError(e); } } @@ -1181,7 +1177,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub @Nullable String testNetworkInterfaceName, @NonNull IOperationReceiver receiver) { enforceAllPermissionsGranted(PERMISSION_THREAD_NETWORK_PRIVILEGED, NETWORK_SETTINGS); - Log.i(TAG, "setTestNetworkAsUpstream: " + testNetworkInterfaceName); + LOG.i("setTestNetworkAsUpstream: " + testNetworkInterfaceName); mHandler.post(() -> setTestNetworkAsUpstreamInternal(testNetworkInterfaceName, receiver)); } @@ -1227,7 +1223,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub try { getOtDaemon().setChannelMaxPowers(channelMaxPowers, newOtStatusReceiver(receiver)); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.setChannelMaxPowers failed", e); + LOG.e("otDaemon.setChannelMaxPowers failed", e); receiver.onError(ERROR_INTERNAL_ERROR, "Thread stack error"); } } @@ -1236,7 +1232,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub if (mInfraLinkState.equals(infraLinkState)) { return; } - Log.i(TAG, "Infra link state changed: " + mInfraLinkState + " -> " + infraLinkState); + LOG.i("Infra link state changed: " + mInfraLinkState + " -> " + infraLinkState); mInfraLinkState = infraLinkState; ParcelFileDescriptor infraIcmp6Socket = null; if (mInfraLinkState.interfaceName != null) { @@ -1244,7 +1240,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub infraIcmp6Socket = mInfraIfController.createIcmp6Socket(mInfraLinkState.interfaceName); } catch (IOException e) { - Log.i(TAG, "Failed to create ICMPv6 socket on infra network interface", e); + LOG.e("Failed to create ICMPv6 socket on infra network interface", e); } } try { @@ -1254,14 +1250,14 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub infraIcmp6Socket, new setInfraLinkStateStatusReceiver()); } catch (RemoteException | ThreadNetworkException e) { - Log.w(TAG, "Failed to configure border router " + mOtDaemonConfig, e); + LOG.e("Failed to configure border router " + mOtDaemonConfig, e); } } private void enableBorderRouting(String infraIfName) { InfraLinkState infraLinkState = newInfraLinkStateBuilder(mInfraLinkState).setInterfaceName(infraIfName).build(); - Log.i(TAG, "Enable border routing on AIL: " + infraIfName); + LOG.i("Enable border routing on AIL: " + infraIfName); setInfraLinkState(infraLinkState); } @@ -1269,28 +1265,28 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub mUpstreamNetwork = null; InfraLinkState infraLinkState = newInfraLinkStateBuilder(mInfraLinkState).setInterfaceName(null).build(); - Log.i(TAG, "Disabling border routing"); + LOG.i("Disabling border routing"); setInfraLinkState(infraLinkState); } private void handleThreadInterfaceStateChanged(boolean isUp) { try { mTunIfController.setInterfaceUp(isUp); - Log.i(TAG, "Thread TUN interface becomes " + (isUp ? "up" : "down")); + LOG.i("Thread TUN interface becomes " + (isUp ? "up" : "down")); } catch (IOException e) { - Log.e(TAG, "Failed to handle Thread interface state changes", e); + LOG.e("Failed to handle Thread interface state changes", e); } } private void handleDeviceRoleChanged(@DeviceRole int deviceRole) { if (ThreadNetworkController.isAttached(deviceRole)) { - Log.i(TAG, "Attached to the Thread network"); + LOG.i("Attached to the Thread network"); // This is an idempotent method which can be called for multiple times when the device // is already attached (e.g. going from Child to Router) registerThreadNetwork(); } else { - Log.i(TAG, "Detached from the Thread network"); + LOG.i("Detached from the Thread network"); // This is an idempotent method which can be called for multiple times when the device // is already detached or stopped @@ -1328,7 +1324,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub } final LocalNetworkConfig localNetworkConfig = newLocalNetworkConfig(); mNetworkAgent.sendLocalNetworkConfig(localNetworkConfig); - Log.d(TAG, "Sent localNetworkConfig: " + localNetworkConfig); + LOG.v("Sent localNetworkConfig: " + localNetworkConfig); } private void handleMulticastForwardingChanged(BackboneRouterState state) { @@ -1407,12 +1403,12 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub @Override public void onSuccess() { - Log.i(TAG, "Configured border router successfully"); + LOG.i("Configured border router successfully"); } @Override public void onError(int i, String s) { - Log.w(TAG, String.format("Failed to set configurations: %d %s", i, s)); + LOG.w(String.format("Failed to set configurations: %d %s", i, s)); } } @@ -1421,12 +1417,12 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub @Override public void onSuccess() { - Log.i(TAG, "Set the infra link state successfully"); + LOG.i("Set the infra link state successfully"); } @Override public void onError(int i, String s) { - Log.w(TAG, String.format("Failed to set the infra link state: %d %s", i, s)); + LOG.w(String.format("Failed to set the infra link state: %d %s", i, s)); } } @@ -1463,7 +1459,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub try { getOtDaemon().registerStateCallback(this, callbackMetadata.id); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.registerStateCallback failed", e); + LOG.e("otDaemon.registerStateCallback failed", e); } } @@ -1495,7 +1491,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub try { getOtDaemon().registerStateCallback(this, callbackMetadata.id); } catch (RemoteException | ThreadNetworkException e) { - Log.e(TAG, "otDaemon.registerStateCallback failed", e); + LOG.e("otDaemon.registerStateCallback failed", e); } } @@ -1587,7 +1583,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub mActiveDataset = newActiveDataset; } catch (IllegalArgumentException e) { // Is unlikely that OT will generate invalid Operational Dataset - Log.wtf(TAG, "Invalid Active Operational Dataset from OpenThread", e); + LOG.wtf("Invalid Active Operational Dataset from OpenThread", e); } PendingOperationalDataset newPendingDataset; @@ -1602,7 +1598,7 @@ final class ThreadNetworkControllerService extends IThreadNetworkController.Stub mPendingDataset = newPendingDataset; } catch (IllegalArgumentException e) { // Is unlikely that OT will generate invalid Operational Dataset - Log.wtf(TAG, "Invalid Pending Operational Dataset from OpenThread", e); + LOG.wtf("Invalid Pending Operational Dataset from OpenThread", e); } } diff --git a/thread/service/java/com/android/server/thread/ThreadNetworkCountryCode.java b/thread/service/java/com/android/server/thread/ThreadNetworkCountryCode.java index a194114af5..2cd34e86d7 100644 --- a/thread/service/java/com/android/server/thread/ThreadNetworkCountryCode.java +++ b/thread/service/java/com/android/server/thread/ThreadNetworkCountryCode.java @@ -38,10 +38,10 @@ import android.telephony.SubscriptionInfo; import android.telephony.SubscriptionManager; import android.telephony.TelephonyManager; import android.util.ArrayMap; -import android.util.Log; import com.android.connectivity.resources.R; import com.android.internal.annotations.VisibleForTesting; +import com.android.net.module.util.SharedLog; import com.android.server.connectivity.ConnectivityResources; import java.io.FileDescriptor; @@ -63,7 +63,9 @@ import java.util.Objects; */ @TargetApi(Build.VERSION_CODES.UPSIDE_DOWN_CAKE) public class ThreadNetworkCountryCode { - private static final String TAG = "ThreadNetworkCountryCode"; + private static final String TAG = "CountryCode"; + private static final SharedLog LOG = ThreadNetworkLogger.forSubComponent(TAG); + // To be used when there is no country code available. @VisibleForTesting public static final String DEFAULT_COUNTRY_CODE = "WW"; @@ -280,11 +282,11 @@ public class ThreadNetworkCountryCode { String countryCode = addresses.get(0).getCountryCode(); if (isValidCountryCode(countryCode)) { - Log.d(TAG, "Set location country code to: " + countryCode); + LOG.v("Set location country code to: " + countryCode); mLocationCountryCodeInfo = new CountryCodeInfo(countryCode, COUNTRY_CODE_SOURCE_LOCATION); } else { - Log.d(TAG, "Received invalid location country code"); + LOG.v("Received invalid location country code"); mLocationCountryCodeInfo = null; } @@ -296,8 +298,7 @@ public class ThreadNetworkCountryCode { if ((location == null) || (mGeocoder == null)) return; if (Build.VERSION.SDK_INT <= Build.VERSION_CODES.TIRAMISU) { - Log.wtf( - TAG, + LOG.wtf( "Unexpected call to set country code from the Geocoding location, " + "Thread code never runs under T or lower."); return; @@ -320,13 +321,13 @@ public class ThreadNetworkCountryCode { private class WifiCountryCodeCallback implements ActiveCountryCodeChangedCallback { @Override public void onActiveCountryCodeChanged(String countryCode) { - Log.d(TAG, "Wifi country code is changed to " + countryCode); + LOG.v("Wifi country code is changed to " + countryCode); synchronized ("ThreadNetworkCountryCode.this") { if (isValidCountryCode(countryCode)) { mWifiCountryCodeInfo = new CountryCodeInfo(countryCode, COUNTRY_CODE_SOURCE_WIFI); } else { - Log.w(TAG, "WiFi country code " + countryCode + " is invalid"); + LOG.w("WiFi country code " + countryCode + " is invalid"); mWifiCountryCodeInfo = null; } @@ -336,7 +337,7 @@ public class ThreadNetworkCountryCode { @Override public void onCountryCodeInactive() { - Log.d(TAG, "Wifi country code is inactived"); + LOG.v("Wifi country code is inactived"); synchronized ("ThreadNetworkCountryCode.this") { mWifiCountryCodeInfo = null; updateCountryCode(false /* forceUpdate */); @@ -346,8 +347,7 @@ public class ThreadNetworkCountryCode { private synchronized void registerTelephonyCountryCodeCallback() { if (Build.VERSION.SDK_INT < Build.VERSION_CODES.TIRAMISU) { - Log.wtf( - TAG, + LOG.wtf( "Unexpected call to register the telephony country code changed callback, " + "Thread code never runs under T or lower."); return; @@ -387,7 +387,7 @@ public class ThreadNetworkCountryCode { mSubscriptionManager.getActiveSubscriptionInfoList(); if (subscriptionInfoList == null) { - Log.d(TAG, "No SIM card is found"); + LOG.v("No SIM card is found"); return; } @@ -399,11 +399,11 @@ public class ThreadNetworkCountryCode { try { countryCode = mTelephonyManager.getNetworkCountryIso(slotIndex); } catch (IllegalArgumentException e) { - Log.e(TAG, "Failed to get country code for slot index:" + slotIndex, e); + LOG.e("Failed to get country code for slot index:" + slotIndex, e); continue; } - Log.d(TAG, "Telephony slot " + slotIndex + " country code is " + countryCode); + LOG.v("Telephony slot " + slotIndex + " country code is " + countryCode); setTelephonyCountryCodeAndLastKnownCountryCode( slotIndex, countryCode, null /* lastKnownCountryCode */); } @@ -411,8 +411,7 @@ public class ThreadNetworkCountryCode { private synchronized void setTelephonyCountryCodeAndLastKnownCountryCode( int slotIndex, String countryCode, String lastKnownCountryCode) { - Log.d( - TAG, + LOG.v( "Set telephony country code to: " + countryCode + ", last country code to: " @@ -522,8 +521,7 @@ public class ThreadNetworkCountryCode { @Override public void onError(int otError, String message) { - Log.e( - TAG, + LOG.e( "Error " + otError + ": " @@ -545,11 +543,11 @@ public class ThreadNetworkCountryCode { CountryCodeInfo countryCodeInfo = pickCountryCode(); if (!forceUpdate && countryCodeInfo.isCountryCodeMatch(mCurrentCountryCodeInfo)) { - Log.i(TAG, "Ignoring already set country code " + countryCodeInfo.getCountryCode()); + LOG.i("Ignoring already set country code " + countryCodeInfo.getCountryCode()); return; } - Log.i(TAG, "Set country code: " + countryCodeInfo); + LOG.i("Set country code: " + countryCodeInfo); mThreadNetworkControllerService.setCountryCode( countryCodeInfo.getCountryCode().toUpperCase(Locale.ROOT), newOperationReceiver(countryCodeInfo)); diff --git a/thread/service/java/com/android/server/thread/ThreadNetworkLogger.java b/thread/service/java/com/android/server/thread/ThreadNetworkLogger.java new file mode 100644 index 0000000000..a7653047e9 --- /dev/null +++ b/thread/service/java/com/android/server/thread/ThreadNetworkLogger.java @@ -0,0 +1,37 @@ +/* + * Copyright (C) 2024 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.android.server.thread; + +import com.android.net.module.util.SharedLog; + +/** + * The Logger for Thread network. + * + *

Each class should log with its own tag using the logger of + * ThreadNetworkLogger.forSubComponent(TAG). + */ +public final class ThreadNetworkLogger { + private static final String TAG = "ThreadNetwork"; + private static final SharedLog mLog = new SharedLog(TAG); + + public static SharedLog forSubComponent(String subComponent) { + return mLog.forSubComponent(subComponent); + } + + // Disable instantiation + private ThreadNetworkLogger() {} +} diff --git a/thread/service/java/com/android/server/thread/ThreadPersistentSettings.java b/thread/service/java/com/android/server/thread/ThreadPersistentSettings.java index 7c4c72d837..fc18ef9a63 100644 --- a/thread/service/java/com/android/server/thread/ThreadPersistentSettings.java +++ b/thread/service/java/com/android/server/thread/ThreadPersistentSettings.java @@ -25,11 +25,11 @@ import android.content.Context; import android.net.thread.ThreadConfiguration; import android.os.PersistableBundle; import android.util.AtomicFile; -import android.util.Log; import com.android.connectivity.resources.R; import com.android.internal.annotations.GuardedBy; import com.android.internal.annotations.VisibleForTesting; +import com.android.net.module.util.SharedLog; import com.android.server.connectivity.ConnectivityResources; import java.io.ByteArrayInputStream; @@ -48,6 +48,7 @@ import java.io.InputStream; */ public class ThreadPersistentSettings { private static final String TAG = "ThreadPersistentSettings"; + private static final SharedLog LOG = ThreadNetworkLogger.forSubComponent(TAG); /** File name used for storing settings. */ private static final String FILE_NAME = "ThreadPersistentSettings.xml"; @@ -115,7 +116,7 @@ public class ThreadPersistentSettings { readFromStoreFile(); synchronized (mLock) { if (!mSettings.containsKey(THREAD_ENABLED.key)) { - Log.i(TAG, "\"thread_enabled\" is missing in settings file, using default value"); + LOG.i("\"thread_enabled\" is missing in settings file, using default value"); put( THREAD_ENABLED.key, mResources.get().getBoolean(R.bool.config_thread_default_enabled)); @@ -243,7 +244,7 @@ public class ThreadPersistentSettings { writeToAtomicFile(mAtomicFile, outputStream.toByteArray()); } } catch (IOException e) { - Log.wtf(TAG, "Write to store file failed", e); + LOG.wtf("Write to store file failed", e); } } @@ -251,7 +252,7 @@ public class ThreadPersistentSettings { try { final byte[] readData; synchronized (mLock) { - Log.i(TAG, "Reading from store file: " + mAtomicFile.getBaseFile()); + LOG.i("Reading from store file: " + mAtomicFile.getBaseFile()); readData = readFromAtomicFile(mAtomicFile); } final ByteArrayInputStream inputStream = new ByteArrayInputStream(readData); @@ -262,9 +263,9 @@ public class ThreadPersistentSettings { mSettings.putAll(bundleRead); } } catch (FileNotFoundException e) { - Log.w(TAG, "No store file to read", e); + LOG.w("No store file to read " + e.getMessage()); } catch (IOException e) { - Log.e(TAG, "Read from store file failed", e); + LOG.e("Read from store file failed", e); } } diff --git a/thread/service/java/com/android/server/thread/TunInterfaceController.java b/thread/service/java/com/android/server/thread/TunInterfaceController.java index 976f93d842..85a0371c28 100644 --- a/thread/service/java/com/android/server/thread/TunInterfaceController.java +++ b/thread/service/java/com/android/server/thread/TunInterfaceController.java @@ -38,10 +38,10 @@ import android.os.ParcelFileDescriptor; import android.os.SystemClock; import android.system.ErrnoException; import android.system.Os; -import android.util.Log; import com.android.net.module.util.HexDump; import com.android.net.module.util.LinkPropertiesUtils.CompareResult; +import com.android.net.module.util.SharedLog; import com.android.net.module.util.netlink.NetlinkUtils; import com.android.net.module.util.netlink.StructIfinfoMsg; import com.android.net.module.util.netlink.StructNlAttr; @@ -66,6 +66,7 @@ import java.util.List; public class TunInterfaceController { private static final String TAG = "TunIfController"; private static final boolean DBG = false; + private static final SharedLog LOG = ThreadNetworkLogger.forSubComponent(TAG); private static final long INFINITE_LIFETIME = 0xffffffffL; static final int MTU = 1280; @@ -147,7 +148,7 @@ public class TunInterfaceController { /** Adds a new address to the interface. */ public void addAddress(LinkAddress address) { - Log.d(TAG, "Adding address " + address + " with flags: " + address.getFlags()); + LOG.v("Adding address " + address + " with flags: " + address.getFlags()); long preferredLifetimeSeconds; long validLifetimeSeconds; @@ -180,7 +181,7 @@ public class TunInterfaceController { (byte) address.getScope(), preferredLifetimeSeconds, validLifetimeSeconds)) { - Log.w(TAG, "Failed to add address " + address.getAddress().getHostAddress()); + LOG.w("Failed to add address " + address.getAddress().getHostAddress()); return; } mLinkProperties.addLinkAddress(address); @@ -189,7 +190,7 @@ public class TunInterfaceController { /** Removes an address from the interface. */ public void removeAddress(LinkAddress address) { - Log.d(TAG, "Removing address " + address); + LOG.v("Removing address " + address); // Intentionally update the mLinkProperties before send netlink message because the // address is already removed from ot-daemon and apps can't reach to the address even @@ -200,7 +201,7 @@ public class TunInterfaceController { Os.if_nametoindex(mIfName), (Inet6Address) address.getAddress(), (short) address.getPrefixLength())) { - Log.w(TAG, "Failed to remove address " + address.getAddress().getHostAddress()); + LOG.w("Failed to remove address " + address.getAddress().getHostAddress()); } } @@ -287,7 +288,7 @@ public class TunInterfaceController { try { setInterfaceUp(false); } catch (IOException e) { - Log.e(TAG, "Failed to set Thread TUN interface down"); + LOG.e("Failed to set Thread TUN interface down"); } } @@ -347,11 +348,15 @@ public class TunInterfaceController { if (e.getCause() instanceof ErrnoException) { ErrnoException ee = (ErrnoException) e.getCause(); if (ee.errno == EADDRINUSE) { - Log.w(TAG, "Already joined group" + address.getHostAddress(), e); + LOG.w( + "Already joined group " + + address.getHostAddress() + + ": " + + e.getMessage()); return; } } - Log.e(TAG, "failed to join group " + address.getHostAddress(), e); + LOG.e("failed to join group " + address.getHostAddress(), e); } } @@ -360,7 +365,7 @@ public class TunInterfaceController { try { mMulticastSocket.leaveGroup(socketAddress, mNetworkInterface); } catch (IOException e) { - Log.e(TAG, "failed to leave group " + address.getHostAddress(), e); + LOG.e("failed to leave group " + address.getHostAddress(), e); } } @@ -415,14 +420,14 @@ public class TunInterfaceController { } if (DBG) { - Log.d(TAG, "ADDR_GEN_MODE message is:"); - Log.d(TAG, HexDump.dumpHexString(msg)); + LOG.v("ADDR_GEN_MODE message is:"); + LOG.v(HexDump.dumpHexString(msg)); } try { NetlinkUtils.sendOneShotKernelMessage(NETLINK_ROUTE, msg); } catch (ErrnoException e) { - Log.e(TAG, "Failed to set ADDR_GEN_MODE to NONE", e); + LOG.e("Failed to set ADDR_GEN_MODE to NONE", e); } } }