From 3c052f3625e67e50288fde44ec2c88d860407822 Mon Sep 17 00:00:00 2001 From: Paul Hu Date: Thu, 17 Oct 2024 05:52:24 +0000 Subject: [PATCH] Clarify logs in MdnsServiceTypeClient Adjust log messages to provide a clearer trace of sending queries and receiving responses. Before: [MdnsDiscoveryManager._nearby_presence._tcp.local-100/20] Next run: sessionId: 1, in 1000 ms [MdnsDiscoveryManager._nearby_presence._tcp.local-100/20] onServiceFound: Name: NsdManagerTest7899, type: _nearby_presence._tcp.local, subtypes: , ip: [192.168.1.104], ipv6: [2001:b011:3010:1983:bc64:b11b:d4cc:f9ab, fe80::285e:44ff:fe0e:b59c, 2001:b011:3010:1983:285e:44ff:fe0e:b59c], port: 12345, interfaceIndex: 20, network: 100, textStrings: [T=0, SAI=800, SAT=4000, SII=800], textEntries: [T=0, SAI=800, SAT=4000, SII=800], expirationTime: 2024-10-17T05:49:51Z [MdnsDiscoveryManager._nearby_presence._tcp.local-100/20] onServiceNameDiscovered: Name: NsdManagerTest7899, type: _nearby_presence._tcp.local, subtypes: , ip: [192.168.1.104], ipv6: [2001:b011:3010:1983:bc64:b11b:d4cc:f9ab, fe80::285e:44ff:fe0e:b59c, 2001:b011:3010:1983:285e:44ff:fe0e:b59c], port: 12345, interfaceIndex: 20, network: 100, textStrings: [T=0, SAI=800, SAT=4000, SII=800], textEntries: [T=0, SAI=800, SAT=4000, SII=800], expirationTime: 2024-10-17T05:49:51Z [MdnsDiscoveryManager._nearby_presence._tcp.local-100/20] Handling response from service: NsdManagerTest7899, newInCache: true, serviceBecomesComplete: false, responseIsComplete: true [MdnsDiscoveryManager._nearby_presence._tcp.local-100/20] Next run: sessionId: 1, in 1000 ms [MdnsDiscoveryManager._nearby_presence._tcp.local-100/20] Remove EVENT_START_QUERYTASK, current session: 0 After: [MdnsDiscoveryManager._nearby_presence._tcp.local-100/47] Reschedule a query. Next run: sessionId: 2, in 95989 ms [MdnsDiscoveryManager._nearby_presence._tcp.local-100/47] VERBOSE Update the last receipt time for service:NsdManagerTest7899 [MdnsDiscoveryManager._nearby_presence._tcp.local-100/47] onServiceFound: Name: NsdManagerTest7899, type: _nearby_presence._tcp.local, subtypes: , ip: [192.168.1.110], ipv6: [2001:b011:3010:1983:21da:cd64:302d:1e97, fe80::c8ce:2aff:fe97:87b, 2001:b011:3010:1983:c8ce:2aff:fe97:87b], port: 12345, interfaceIndex: 47, network: 100, textStrings: [T=0, SAI=800, SAT=4000, SII=800], textEntries: [T=0, SAI=800, SAT=4000, SII=800], expirationTime: 2024-10-17T05:43:02Z [MdnsDiscoveryManager._nearby_presence._tcp.local-100/47] onServiceNameDiscovered: Name: NsdManagerTest7899, type: _nearby_presence._tcp.local, subtypes: , ip: [192.168.1.110], ipv6: [2001:b011:3010:1983:21da:cd64:302d:1e97, fe80::c8ce:2aff:fe97:87b, 2001:b011:3010:1983:c8ce:2aff:fe97:87b], port: 12345, interfaceIndex: 47, network: 100, textStrings: [T=0, SAI=800, SAT=4000, SII=800], textEntries: [T=0, SAI=800, SAT=4000, SII=800], expirationTime: 2024-10-17T05:43:02Z [MdnsDiscoveryManager._nearby_presence._tcp.local-100/47] Handling response from service: NsdManagerTest7899, newInCache: true, serviceBecomesComplete: false, responseIsComplete: true [MdnsDiscoveryManager._nearby_presence._tcp.local-100/47] Query sent with transactionId: 1. Next run: sessionId: 1, in 1000 ms [MdnsDiscoveryManager._nearby_presence._tcp.local-100/47] Remove EVENT_START_QUERYTASK, current session: 0 Test: m & adb shell dumpsys servicediscovery Change-Id: I7b535308272c8630ad920b47befe46d94e32209c --- .../mdns/MdnsServiceTypeClient.java | 28 +++++++++++++------ 1 file changed, 20 insertions(+), 8 deletions(-) diff --git a/service-t/src/com/android/server/connectivity/mdns/MdnsServiceTypeClient.java b/service-t/src/com/android/server/connectivity/mdns/MdnsServiceTypeClient.java index b0e3ba42cb..4199e6b5be 100644 --- a/service-t/src/com/android/server/connectivity/mdns/MdnsServiceTypeClient.java +++ b/service-t/src/com/android/server/connectivity/mdns/MdnsServiceTypeClient.java @@ -59,6 +59,7 @@ import java.util.concurrent.ScheduledExecutorService; public class MdnsServiceTypeClient { private static final String TAG = MdnsServiceTypeClient.class.getSimpleName(); + private static final boolean DBG = MdnsDiscoveryManager.DBG; @VisibleForTesting static final int EVENT_START_QUERYTASK = 1; static final int EVENT_QUERY_RESULT = 2; @@ -184,10 +185,14 @@ public class MdnsServiceTypeClient { searchOptions.numOfQueriesBeforeBackoff(), false /* forceEnableBackoff */ ); + final long timeToNextTaskMs = calculateTimeToNextTask(args, now); + sharedLog.log(String.format("Query sent with transactionId: %d. " + + "Next run: sessionId: %d, in %d ms", + sentResult.transactionId, args.sessionId, timeToNextTaskMs)); dependencies.sendMessageDelayed( handler, handler.obtainMessage(EVENT_START_QUERYTASK, args), - calculateTimeToNextTask(args, now, sharedLog)); + timeToNextTaskMs); break; } default: @@ -369,10 +374,13 @@ public class MdnsServiceTypeClient { searchOptions.numOfQueriesBeforeBackoff(), forceEnableBackoff ); + final long timeToNextTaskMs = calculateTimeToNextTask(args, now); + sharedLog.log(String.format("Schedule a query. Next run: sessionId: %d, in %d ms", + args.sessionId, timeToNextTaskMs)); dependencies.sendMessageDelayed( handler, handler.obtainMessage(EVENT_START_QUERYTASK, args), - calculateTimeToNextTask(args, now, sharedLog)); + timeToNextTaskMs); } else { final List servicesToResolve = makeResponsesForResolve(socketKey); final QueryTask queryTask = new QueryTask( @@ -492,6 +500,10 @@ public class MdnsServiceTypeClient { // If the response is not modified and already in the cache. The cache will // need to be updated to refresh the last receipt time. serviceCache.addOrUpdateService(cacheKey, response); + if (DBG) { + sharedLog.v("Update the last receipt time for service:" + + serviceInstanceName); + } } } if (dependencies.hasMessages(handler, EVENT_START_QUERYTASK)) { @@ -503,10 +515,13 @@ public class MdnsServiceTypeClient { searchOptions.numOfQueriesBeforeBackoff()); if (args != null) { removeScheduledTask(); + final long timeToNextTaskMs = calculateTimeToNextTask(args, now); + sharedLog.log(String.format("Reschedule a query. Next run: sessionId: %d, in %d ms", + args.sessionId, timeToNextTaskMs)); dependencies.sendMessageDelayed( handler, handler.obtainMessage(EVENT_START_QUERYTASK, args), - calculateTimeToNextTask(args, now, sharedLog)); + timeToNextTaskMs); } } } @@ -757,11 +772,8 @@ public class MdnsServiceTypeClient { } private static long calculateTimeToNextTask(MdnsQueryScheduler.ScheduledQueryTaskArgs args, - long now, SharedLog sharedLog) { - long timeToNextTasksWithBackoffInMs = Math.max(args.timeToRun - now, 0); - sharedLog.log(String.format("Next run: sessionId: %d, in %d ms", - args.sessionId, timeToNextTasksWithBackoffInMs)); - return timeToNextTasksWithBackoffInMs; + long now) { + return Math.max(args.timeToRun - now, 0); } /**