Merge "Add framework stats for the Context Hub service"

This commit is contained in:
Matthew Sedam
2022-09-06 21:22:25 +00:00
committed by Android (Google) Code Review
7 changed files with 348 additions and 65 deletions

View File

@@ -33,7 +33,7 @@ public class ConcurrentLinkedEvictingDeque<E> extends ConcurrentLinkedDeque<E> {
@Override
public boolean add(E elem) {
synchronized (this) {
if (size() == mSize) {
if (size() == mSize) { // TODO(b/244459069): the size() method is not constant time
poll();
}

View File

@@ -471,6 +471,11 @@ public class ContextHubClientBroker extends IContextHubClient.Stub
+ mAttachedContextHubInfo.getId() + ")", e);
result = ContextHubTransaction.RESULT_FAILED_UNKNOWN;
}
ContextHubEventLogger.getInstance().logMessageToNanoapp(
mAttachedContextHubInfo.getId(),
message,
result == ContextHubTransaction.RESULT_SUCCESS);
} else {
String messageString = Base64.getEncoder().encodeToString(message.getMessageBody());
Log.e(TAG, String.format(

View File

@@ -31,9 +31,6 @@ import com.android.server.location.ClientManagerProto;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.Iterator;
import java.util.List;
import java.util.concurrent.ConcurrentHashMap;
@@ -47,11 +44,6 @@ import java.util.function.Consumer;
/* package */ class ContextHubClientManager {
private static final String TAG = "ContextHubClientManager";
/*
* The DateFormat for printing RegistrationRecord.
*/
private static final DateFormat DATE_FORMAT = new SimpleDateFormat("MM/dd HH:mm:ss.SSS");
/*
* The maximum host endpoint ID value that a client can be assigned.
*/
@@ -125,14 +117,15 @@ import java.util.function.Consumer;
@Override
public String toString() {
String out = "";
out += DATE_FORMAT.format(new Date(mTimestamp)) + " ";
out += mAction == ACTION_REGISTERED ? "+ " : "- ";
out += mBroker;
StringBuilder sb = new StringBuilder();
sb.append(ContextHubServiceUtil.formatDateFromTimestamp(mTimestamp));
sb.append(" ");
sb.append(mAction == ACTION_REGISTERED ? "+ " : "- ");
sb.append(mBroker);
if (mAction == ACTION_CANCELLED) {
out += " (cancelled)";
sb.append(" (cancelled)");
}
return out;
return sb.toString();
}
}
@@ -247,14 +240,17 @@ import java.util.function.Consumer;
+ message.getNanoAppId());
}
broadcastMessage(
contextHubId, message, nanoappPermissions, messagePermissions);
ContextHubEventLogger.getInstance().logMessageFromNanoapp(contextHubId, message, true);
broadcastMessage(contextHubId, message, nanoappPermissions, messagePermissions);
} else {
ContextHubClientBroker proxy = mHostEndPointIdToClientMap.get(hostEndpointId);
if (proxy != null) {
proxy.sendMessageToClient(
message, nanoappPermissions, messagePermissions);
ContextHubEventLogger.getInstance().logMessageFromNanoapp(contextHubId, message,
true);
proxy.sendMessageToClient(message, nanoappPermissions, messagePermissions);
} else {
ContextHubEventLogger.getInstance().logMessageFromNanoapp(contextHubId, message,
false);
Log.e(TAG, "Cannot send message to unregistered client (host endpoint ID = "
+ hostEndpointId + ")");
}
@@ -414,17 +410,21 @@ import java.util.function.Consumer;
@Override
public String toString() {
String out = "";
StringBuilder sb = new StringBuilder();
for (ContextHubClientBroker broker : mHostEndPointIdToClientMap.values()) {
out += broker + "\n";
sb.append(broker);
sb.append(System.lineSeparator());
}
out += "\nRegistration history:\n";
sb.append(System.lineSeparator());
sb.append("Registration History:");
sb.append(System.lineSeparator());
Iterator<RegistrationRecord> it = mRegistrationRecordDeque.descendingIterator();
while (it.hasNext()) {
out += it.next() + "\n";
sb.append(it.next());
sb.append(System.lineSeparator());
}
return out;
return sb.toString();
}
}

View File

@@ -17,6 +17,7 @@
package com.android.server.location.contexthub;
import android.hardware.location.NanoAppMessage;
import android.util.Log;
/**
* A class to log events and useful metrics within the Context Hub service.
@@ -30,35 +31,226 @@ import android.hardware.location.NanoAppMessage;
* @hide
*/
public class ContextHubEventLogger {
/**
* The base class for all Context Hub events
*/
public static class ContextHubEventBase {
/**
* the timestamp in milliseconds
*/
public final long timeStampInMs;
/**
* the ID of the context hub
*/
public final int contextHubId;
public ContextHubEventBase(long mTimeStampInMs, int mContextHubId) {
timeStampInMs = mTimeStampInMs;
contextHubId = mContextHubId;
}
}
/**
* A base class for nanoapp events
*/
public static class NanoappEventBase extends ContextHubEventBase {
/**
* the ID of the nanoapp
*/
public final long nanoappId;
/**
* whether the event was successful
*/
public final boolean success;
public NanoappEventBase(long mTimeStampInMs, int mContextHubId,
long mNanoappId, boolean mSuccess) {
super(mTimeStampInMs, mContextHubId);
nanoappId = mNanoappId;
success = mSuccess;
}
}
/**
* Represents a nanoapp load event
*/
public static class NanoappLoadEvent extends NanoappEventBase {
/**
* the version of the nanoapp
*/
public final int nanoappVersion;
/**
* the size in bytes of the nanoapp
*/
public final long nanoappSize;
public NanoappLoadEvent(long mTimeStampInMs, int mContextHubId, long mNanoappId,
int mNanoappVersion, long mNanoappSize, boolean mSuccess) {
super(mTimeStampInMs, mContextHubId, mNanoappId, mSuccess);
nanoappVersion = mNanoappVersion;
nanoappSize = mNanoappSize;
}
@Override
public String toString() {
StringBuilder sb = new StringBuilder();
sb.append(ContextHubServiceUtil.formatDateFromTimestamp(timeStampInMs));
sb.append(": NanoappLoadEvent[hubId = ");
sb.append(contextHubId);
sb.append(", appId = 0x");
sb.append(Long.toHexString(nanoappId));
sb.append(", appVersion = ");
sb.append(nanoappVersion);
sb.append(", appSize = ");
sb.append(nanoappSize);
sb.append(" bytes, success = ");
sb.append(success ? "true" : "false");
sb.append(']');
return sb.toString();
}
}
/**
* Represents a nanoapp unload event
*/
public static class NanoappUnloadEvent extends NanoappEventBase {
public NanoappUnloadEvent(long mTimeStampInMs, int mContextHubId,
long mNanoappId, boolean mSuccess) {
super(mTimeStampInMs, mContextHubId, mNanoappId, mSuccess);
}
@Override
public String toString() {
StringBuilder sb = new StringBuilder();
sb.append(ContextHubServiceUtil.formatDateFromTimestamp(timeStampInMs));
sb.append(": NanoappUnloadEvent[hubId = ");
sb.append(contextHubId);
sb.append(", appId = 0x");
sb.append(Long.toHexString(nanoappId));
sb.append(", success = ");
sb.append(success ? "true" : "false");
sb.append(']');
return sb.toString();
}
}
/**
* Represents a nanoapp message event
*/
public static class NanoappMessageEvent extends NanoappEventBase {
/**
* the message that was sent
*/
public final NanoAppMessage message;
public NanoappMessageEvent(long mTimeStampInMs, int mContextHubId,
NanoAppMessage mMessage, boolean mSuccess) {
super(mTimeStampInMs, mContextHubId, 0, mSuccess);
message = mMessage;
}
@Override
public String toString() {
StringBuilder sb = new StringBuilder();
sb.append(ContextHubServiceUtil.formatDateFromTimestamp(timeStampInMs));
sb.append(": NanoappMessageEvent[hubId = ");
sb.append(contextHubId);
sb.append(", ");
sb.append(message.toString());
sb.append(", success = ");
sb.append(success ? "true" : "false");
sb.append(']');
return sb.toString();
}
}
/**
* Represents a context hub restart event
*/
public static class ContextHubRestartEvent extends ContextHubEventBase {
public ContextHubRestartEvent(long mTimeStampInMs, int mContextHubId) {
super(mTimeStampInMs, mContextHubId);
}
@Override
public String toString() {
StringBuilder sb = new StringBuilder();
sb.append(ContextHubServiceUtil.formatDateFromTimestamp(timeStampInMs));
sb.append(": ContextHubRestartEvent[hubId = ");
sb.append(contextHubId);
sb.append(']');
return sb.toString();
}
}
public static final int NUM_EVENTS_TO_STORE = 20;
private static final String TAG = "ContextHubEventLogger";
ContextHubEventLogger() {
throw new RuntimeException("Not implemented");
private final ConcurrentLinkedEvictingDeque<NanoappLoadEvent> mNanoappLoadEventQueue =
new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE);
private final ConcurrentLinkedEvictingDeque<NanoappUnloadEvent> mNanoappUnloadEventQueue =
new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE);
private final ConcurrentLinkedEvictingDeque<NanoappMessageEvent> mMessageFromNanoappQueue =
new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE);
private final ConcurrentLinkedEvictingDeque<NanoappMessageEvent> mMessageToNanoappQueue =
new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE);
private final ConcurrentLinkedEvictingDeque<ContextHubRestartEvent>
mContextHubRestartEventQueue = new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE);
// Make ContextHubEventLogger a singleton
private static ContextHubEventLogger sInstance = null;
private ContextHubEventLogger() {}
/**
* Gets the singleton instance for ContextHubEventLogger
*/
public static synchronized ContextHubEventLogger getInstance() {
if (sInstance == null) {
sInstance = new ContextHubEventLogger();
}
return sInstance;
}
/**
* Logs a nanoapp load event
*
* @param contextHubId the ID of the context hub
* @param nanoAppId the ID of the nanoapp
* @param nanoAppVersion the version of the nanoapp
* @param nanoAppSize the size in bytes of the nanoapp
* @param nanoappId the ID of the nanoapp
* @param nanoappVersion the version of the nanoapp
* @param nanoappSize the size in bytes of the nanoapp
* @param success whether the load was successful
*/
public void logNanoAppLoad(int contextHubId, long nanoAppId, int nanoAppVersion,
long nanoAppSize, boolean success) {
throw new RuntimeException("Not implemented");
public synchronized void logNanoappLoad(int contextHubId, long nanoappId, int nanoappVersion,
long nanoappSize, boolean success) {
long timeStampInMs = System.currentTimeMillis();
NanoappLoadEvent event = new NanoappLoadEvent(timeStampInMs, contextHubId, nanoappId,
nanoappVersion, nanoappSize, success);
boolean status = mNanoappLoadEventQueue.add(event);
if (!status) {
Log.e(TAG, "Unable to add nanoapp load event to queue: " + event);
}
}
/**
* Logs a nanoapp unload event
*
* @param contextHubId the ID of the context hub
* @param nanoAppId the ID of the nanoapp
* @param nanoappId the ID of the nanoapp
* @param success whether the unload was successful
*/
public void logNanoAppUnload(int contextHubId, long nanoAppId, boolean success) {
throw new RuntimeException("Not implemented");
public synchronized void logNanoappUnload(int contextHubId, long nanoappId, boolean success) {
long timeStampInMs = System.currentTimeMillis();
NanoappUnloadEvent event = new NanoappUnloadEvent(timeStampInMs, contextHubId,
nanoappId, success);
boolean status = mNanoappUnloadEventQueue.add(event);
if (!status) {
Log.e(TAG, "Unable to add nanoapp unload event to queue: " + event);
}
}
/**
@@ -66,9 +258,21 @@ public class ContextHubEventLogger {
*
* @param contextHubId the ID of the context hub
* @param message the message that was sent
* @param success whether the message was sent successfully
*/
public void logMessageFromNanoApp(int contextHubId, NanoAppMessage message) {
throw new RuntimeException("Not implemented");
public synchronized void logMessageFromNanoapp(int contextHubId, NanoAppMessage message,
boolean success) {
if (message == null) {
return;
}
long timeStampInMs = System.currentTimeMillis();
NanoappMessageEvent event = new NanoappMessageEvent(timeStampInMs, contextHubId,
message, success);
boolean status = mMessageFromNanoappQueue.add(event);
if (!status) {
Log.e(TAG, "Unable to add message from nanoapp event to queue: " + event);
}
}
/**
@@ -78,8 +282,19 @@ public class ContextHubEventLogger {
* @param message the message that was sent
* @param success whether the message was sent successfully
*/
public void logMessageToNanoApp(int contextHubId, NanoAppMessage message, boolean success) {
throw new RuntimeException("Not implemented");
public synchronized void logMessageToNanoapp(int contextHubId, NanoAppMessage message,
boolean success) {
if (message == null) {
return;
}
long timeStampInMs = System.currentTimeMillis();
NanoappMessageEvent event = new NanoappMessageEvent(timeStampInMs, contextHubId,
message, success);
boolean status = mMessageToNanoappQueue.add(event);
if (!status) {
Log.e(TAG, "Unable to add message to nanoapp event to queue: " + event);
}
}
/**
@@ -87,8 +302,13 @@ public class ContextHubEventLogger {
*
* @param contextHubId the ID of the context hub
*/
public void logContextHubRestarts(int contextHubId) {
throw new RuntimeException("Not implemented");
public synchronized void logContextHubRestart(int contextHubId) {
long timeStampInMs = System.currentTimeMillis();
ContextHubRestartEvent event = new ContextHubRestartEvent(timeStampInMs, contextHubId);
boolean status = mContextHubRestartEventQueue.add(event);
if (!status) {
Log.e(TAG, "Unable to add Context Hub restart event to queue: " + event);
}
}
/**
@@ -96,8 +316,43 @@ public class ContextHubEventLogger {
*
* @return the dumped events
*/
public String dump() {
throw new RuntimeException("Not implemented");
public synchronized String dump() {
StringBuilder sb = new StringBuilder();
sb.append("Nanoapp Loads:");
sb.append(System.lineSeparator());
for (NanoappLoadEvent event : mNanoappLoadEventQueue) {
sb.append(event);
sb.append(System.lineSeparator());
}
sb.append(System.lineSeparator());
sb.append("Nanoapp Unloads:");
sb.append(System.lineSeparator());
for (NanoappUnloadEvent event : mNanoappUnloadEventQueue) {
sb.append(event);
sb.append(System.lineSeparator());
}
sb.append(System.lineSeparator());
sb.append("Messages from Nanoapps:");
sb.append(System.lineSeparator());
for (NanoappMessageEvent event : mMessageFromNanoappQueue) {
sb.append(event);
sb.append(System.lineSeparator());
}
sb.append(System.lineSeparator());
sb.append("Messages to Nanoapps:");
sb.append(System.lineSeparator());
for (NanoappMessageEvent event : mMessageToNanoappQueue) {
sb.append(event);
sb.append(System.lineSeparator());
}
sb.append(System.lineSeparator());
sb.append("Context Hub Restarts:");
sb.append(System.lineSeparator());
for (ContextHubRestartEvent event : mContextHubRestartEventQueue) {
sb.append(event);
sb.append(System.lineSeparator());
}
return sb.toString();
}
@Override

View File

@@ -71,7 +71,6 @@ import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collections;
import java.util.HashMap;
import java.util.Iterator;
import java.util.List;
import java.util.Map;
import java.util.Set;
@@ -172,10 +171,6 @@ public class ContextHubService extends IContextHubService.Stub {
private final Map<Integer, AtomicLong> mLastRestartTimestampMap = new HashMap<>();
private static final int MAX_NUM_OF_NANOAPP_MESSAGE_RECORDS = 10;
private final ConcurrentLinkedEvictingDeque<NanoAppMessage> mNanoAppMessageRecords =
new ConcurrentLinkedEvictingDeque<>(MAX_NUM_OF_NANOAPP_MESSAGE_RECORDS);
/**
* Class extending the callback to register with a Context Hub.
*/
@@ -728,7 +723,6 @@ public class ContextHubService extends IContextHubService.Stub {
NanoAppMessage message,
List<String> nanoappPermissions,
List<String> messagePermissions) {
mNanoAppMessageRecords.add(message);
mClientManager.onMessageFromNanoApp(
contextHubId, hostEndpointId, message, nanoappPermissions, messagePermissions);
}
@@ -791,6 +785,8 @@ public class ContextHubService extends IContextHubService.Stub {
TimeUnit.NANOSECONDS.toMillis(now - lastRestartTimeNs),
contextHubId);
ContextHubEventLogger.getInstance().logContextHubRestart(contextHubId);
sendLocationSettingUpdate();
sendWifiSettingUpdate(true /* forceUpdate */);
sendAirplaneModeSettingUpdate();
@@ -1048,13 +1044,6 @@ public class ContextHubService extends IContextHubService.Stub {
// Dump nanoAppHash
mNanoAppStateManager.foreachNanoAppInstanceInfo((info) -> pw.println(info));
pw.println("");
pw.println("=================== NANOAPPS MESSAGES ====================");
Iterator<NanoAppMessage> iterator = mNanoAppMessageRecords.descendingIterator();
while (iterator.hasNext()) {
pw.println(iterator.next());
}
pw.println("");
pw.println("=================== CLIENTS ====================");
pw.println(mClientManager);
@@ -1063,6 +1052,10 @@ public class ContextHubService extends IContextHubService.Stub {
pw.println("=================== TRANSACTIONS ====================");
pw.println(mTransactionManager);
pw.println("");
pw.println("=================== EVENTS ====================");
pw.println(ContextHubEventLogger.getInstance().dump());
// dump eventLog
}

View File

@@ -31,6 +31,9 @@ import android.hardware.location.NanoAppRpcService;
import android.hardware.location.NanoAppState;
import android.util.Log;
import java.time.Instant;
import java.time.ZoneId;
import java.time.format.DateTimeFormatter;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
@@ -49,6 +52,18 @@ import java.util.List;
*/
private static final char HOST_ENDPOINT_BROADCAST = 0xFFFF;
/*
* The format for printing to logs.
*/
private static final String DATE_FORMAT = "MM/dd HH:mm:ss.SSS";
/**
* The DateTimeFormatter for printing to logs.
*/
private static final DateTimeFormatter DATE_FORMATTER = DateTimeFormatter.ofPattern(DATE_FORMAT)
.withZone(ZoneId.systemDefault());
/**
* Creates a ConcurrentHashMap of the Context Hub ID to the ContextHubInfo object given an
* ArrayList of HIDL ContextHub objects.
@@ -386,4 +401,15 @@ import java.util.List;
return ContextHubService.CONTEXT_HUB_EVENT_UNKNOWN;
}
}
/**
* Converts a timestamp in milliseconds to a properly-formatted date string for log output.
*
* @param timeStampInMs the timestamp in milliseconds
* @return the formatted date string
*/
/* package */
static String formatDateFromTimestamp(long timeStampInMs) {
return DATE_FORMATTER.format(Instant.ofEpochMilli(timeStampInMs));
}
}

View File

@@ -23,11 +23,8 @@ import android.hardware.location.NanoAppState;
import android.os.RemoteException;
import android.util.Log;
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.ArrayDeque;
import java.util.Collections;
import java.util.Date;
import java.util.Iterator;
import java.util.List;
import java.util.concurrent.ScheduledFuture;
@@ -53,11 +50,6 @@ import java.util.concurrent.atomic.AtomicInteger;
*/
private static final int MAX_PENDING_REQUESTS = 10000;
/*
* The DateFormat for printing TransactionRecord.
*/
private static final DateFormat DATE_FORMAT = new SimpleDateFormat("MM/dd HH:mm:ss.SSS");
/*
* The proxy to talk to the Context Hub
*/
@@ -112,7 +104,7 @@ import java.util.concurrent.atomic.AtomicInteger;
@Override
public String toString() {
return DATE_FORMAT.format(new Date(mTimestamp)) + " " + mTransaction;
return ContextHubServiceUtil.formatDateFromTimestamp(mTimestamp) + " " + mTransaction;
}
}
@@ -160,6 +152,13 @@ import java.util.concurrent.atomic.AtomicInteger;
.CHRE_CODE_DOWNLOAD_TRANSACTED__TRANSACTION_TYPE__TYPE_LOAD,
toStatsTransactionResult(result));
ContextHubEventLogger.getInstance().logNanoappLoad(
contextHubId,
nanoAppBinary.getNanoAppId(),
nanoAppBinary.getNanoAppVersion(),
nanoAppBinary.getBinary().length,
result == ContextHubTransaction.RESULT_SUCCESS);
if (result == ContextHubTransaction.RESULT_SUCCESS) {
// NOTE: The legacy JNI code used to do a query right after a load success
// to synchronize the service cache. Instead store the binary that was
@@ -215,6 +214,11 @@ import java.util.concurrent.atomic.AtomicInteger;
.CHRE_CODE_DOWNLOAD_TRANSACTED__TRANSACTION_TYPE__TYPE_UNLOAD,
toStatsTransactionResult(result));
ContextHubEventLogger.getInstance().logNanoappUnload(
contextHubId,
nanoAppId,
result == ContextHubTransaction.RESULT_SUCCESS);
if (result == ContextHubTransaction.RESULT_SUCCESS) {
mNanoAppStateManager.removeNanoAppInstance(contextHubId, nanoAppId);
}