diff --git a/core/java/com/android/internal/jank/EventLogTags.logtags b/core/java/com/android/internal/jank/EventLogTags.logtags index 7af5d8fe49fca..ad47b810aa504 100644 --- a/core/java/com/android/internal/jank/EventLogTags.logtags +++ b/core/java/com/android/internal/jank/EventLogTags.logtags @@ -3,8 +3,8 @@ option java_package com.android.internal.jank; # Marks a request to start tracing a CUJ. Doesn't mean the request was executed. -37001 jank_cuj_events_begin_request (CUJ Type|1|5),(Elapsed Time Ns|2|3),(Uptime Ns|2|3) +37001 jank_cuj_events_begin_request (CUJ Type|1|5),(Unix Time Ns|2|3),(Elapsed Time Ns|2|3),(Uptime Ns|2|3) # Marks a request to end tracing a CUJ. Doesn't mean the request was executed. -37002 jank_cuj_events_end_request (CUJ Type|1|5),(Elapsed Time Ns|2|3),(Uptime Time Ns|2|3) +37002 jank_cuj_events_end_request (CUJ Type|1|5),(Unix Time Ns|2|3),(Elapsed Time Ns|2|3),(Uptime Time Ns|2|3) # Marks a request to cancel tracing a CUJ. Doesn't mean the request was executed. -37003 jank_cuj_events_cancel_request (CUJ Type|1|5),(Elapsed Time Ns|2|3),(Uptime Time Ns|2|3) +37003 jank_cuj_events_cancel_request (CUJ Type|1|5),(Unix Time Ns|2|3),(Elapsed Time Ns|2|3),(Uptime Time Ns|2|3) diff --git a/core/java/com/android/internal/jank/InteractionJankMonitor.java b/core/java/com/android/internal/jank/InteractionJankMonitor.java index d93fff98254bc..fd97dadf8e197 100644 --- a/core/java/com/android/internal/jank/InteractionJankMonitor.java +++ b/core/java/com/android/internal/jank/InteractionJankMonitor.java @@ -128,6 +128,7 @@ import com.android.internal.util.PerfettoTrigger; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; +import java.time.Instant; import java.util.Locale; import java.util.concurrent.ThreadLocalRandom; import java.util.concurrent.TimeUnit; @@ -578,8 +579,10 @@ public class InteractionJankMonitor { public boolean begin(@NonNull Configuration.Builder builder) { try { final Configuration config = builder.build(); - EventLogTags.writeJankCujEventsBeginRequest( - config.mCujType, SystemClock.elapsedRealtimeNanos(), SystemClock.uptimeNanos()); + postEventLogToWorkerThread((unixNanos, elapsedNanos, realtimeNanos) -> { + EventLogTags.writeJankCujEventsBeginRequest( + config.mCujType, unixNanos, elapsedNanos, realtimeNanos); + }); final TrackerResult result = new TrackerResult(); final boolean success = config.getHandler().runWithScissors( () -> result.mResult = beginInternal(config), EXECUTOR_TASK_TIMEOUT); @@ -653,8 +656,10 @@ public class InteractionJankMonitor { * @return boolean true if the tracker is ended successfully, false otherwise. */ public boolean end(@CujType int cujType) { - EventLogTags.writeJankCujEventsEndRequest(cujType, SystemClock.elapsedRealtimeNanos(), - SystemClock.uptimeNanos()); + postEventLogToWorkerThread((unixNanos, elapsedNanos, realtimeNanos) -> { + EventLogTags.writeJankCujEventsEndRequest( + cujType, unixNanos, elapsedNanos, realtimeNanos); + }); FrameTracker tracker = getTracker(cujType); // Skip this call since we haven't started a trace yet. if (tracker == null) return false; @@ -692,8 +697,10 @@ public class InteractionJankMonitor { * @return boolean true if the tracker is cancelled successfully, false otherwise. */ public boolean cancel(@CujType int cujType) { - EventLogTags.writeJankCujEventsCancelRequest(cujType, SystemClock.elapsedRealtimeNanos(), - SystemClock.uptimeNanos()); + postEventLogToWorkerThread((unixNanos, elapsedNanos, realtimeNanos) -> { + EventLogTags.writeJankCujEventsCancelRequest( + cujType, unixNanos, elapsedNanos, realtimeNanos); + }); return cancel(cujType, REASON_CANCEL_NORMAL); } @@ -1284,4 +1291,21 @@ public class InteractionJankMonitor { return mReason; } } + + @FunctionalInterface + private interface TimeFunction { + void invoke(long unixNanos, long elapsedNanos, long realtimeNanos); + } + + private void postEventLogToWorkerThread(TimeFunction logFunction) { + final Instant now = Instant.now(); + final long unixNanos = TimeUnit.NANOSECONDS.convert(now.getEpochSecond(), TimeUnit.SECONDS) + + now.getNano(); + final long elapsedNanos = SystemClock.elapsedRealtimeNanos(); + final long realtimeNanos = SystemClock.uptimeNanos(); + + mWorker.getThreadHandler().post(() -> { + logFunction.invoke(unixNanos, elapsedNanos, realtimeNanos); + }); + } }