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
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 b0e3ba4..4199e6b 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 @@
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 @@
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 @@
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<MdnsResponse> servicesToResolve = makeResponsesForResolve(socketKey);
final QueryTask queryTask = new QueryTask(
@@ -492,6 +500,10 @@
// 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 @@
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 @@
}
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);
}
/**