diff --git a/services/core/java/com/android/server/location/contexthub/ConcurrentLinkedEvictingDeque.java b/services/core/java/com/android/server/location/contexthub/ConcurrentLinkedEvictingDeque.java index 0427007d7d500..5ed0d0db2e187 100644 --- a/services/core/java/com/android/server/location/contexthub/ConcurrentLinkedEvictingDeque.java +++ b/services/core/java/com/android/server/location/contexthub/ConcurrentLinkedEvictingDeque.java @@ -33,7 +33,7 @@ public class ConcurrentLinkedEvictingDeque extends ConcurrentLinkedDeque { @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(); } diff --git a/services/core/java/com/android/server/location/contexthub/ContextHubClientBroker.java b/services/core/java/com/android/server/location/contexthub/ContextHubClientBroker.java index cd6ae450759b6..5819ff0811be2 100644 --- a/services/core/java/com/android/server/location/contexthub/ContextHubClientBroker.java +++ b/services/core/java/com/android/server/location/contexthub/ContextHubClientBroker.java @@ -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( diff --git a/services/core/java/com/android/server/location/contexthub/ContextHubClientManager.java b/services/core/java/com/android/server/location/contexthub/ContextHubClientManager.java index 41a406ce7fcdb..4de7c0c220aff 100644 --- a/services/core/java/com/android/server/location/contexthub/ContextHubClientManager.java +++ b/services/core/java/com/android/server/location/contexthub/ContextHubClientManager.java @@ -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 it = mRegistrationRecordDeque.descendingIterator(); while (it.hasNext()) { - out += it.next() + "\n"; + sb.append(it.next()); + sb.append(System.lineSeparator()); } - return out; + return sb.toString(); } } diff --git a/services/core/java/com/android/server/location/contexthub/ContextHubEventLogger.java b/services/core/java/com/android/server/location/contexthub/ContextHubEventLogger.java index e46bb74003a2f..071917ca3e4ce 100644 --- a/services/core/java/com/android/server/location/contexthub/ContextHubEventLogger.java +++ b/services/core/java/com/android/server/location/contexthub/ContextHubEventLogger.java @@ -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 mNanoappLoadEventQueue = + new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE); + private final ConcurrentLinkedEvictingDeque mNanoappUnloadEventQueue = + new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE); + private final ConcurrentLinkedEvictingDeque mMessageFromNanoappQueue = + new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE); + private final ConcurrentLinkedEvictingDeque mMessageToNanoappQueue = + new ConcurrentLinkedEvictingDeque<>(NUM_EVENTS_TO_STORE); + private final ConcurrentLinkedEvictingDeque + 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 diff --git a/services/core/java/com/android/server/location/contexthub/ContextHubService.java b/services/core/java/com/android/server/location/contexthub/ContextHubService.java index 3ad5fc149d865..4ca0ea6e0e957 100644 --- a/services/core/java/com/android/server/location/contexthub/ContextHubService.java +++ b/services/core/java/com/android/server/location/contexthub/ContextHubService.java @@ -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 mLastRestartTimestampMap = new HashMap<>(); - private static final int MAX_NUM_OF_NANOAPP_MESSAGE_RECORDS = 10; - private final ConcurrentLinkedEvictingDeque 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 nanoappPermissions, List 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 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 } diff --git a/services/core/java/com/android/server/location/contexthub/ContextHubServiceUtil.java b/services/core/java/com/android/server/location/contexthub/ContextHubServiceUtil.java index e9bf90f1a82ed..f637149d8e4ba 100644 --- a/services/core/java/com/android/server/location/contexthub/ContextHubServiceUtil.java +++ b/services/core/java/com/android/server/location/contexthub/ContextHubServiceUtil.java @@ -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)); + } } diff --git a/services/core/java/com/android/server/location/contexthub/ContextHubTransactionManager.java b/services/core/java/com/android/server/location/contexthub/ContextHubTransactionManager.java index c199bb30a6d37..4f6d0d472d269 100644 --- a/services/core/java/com/android/server/location/contexthub/ContextHubTransactionManager.java +++ b/services/core/java/com/android/server/location/contexthub/ContextHubTransactionManager.java @@ -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); }