From 8afa13d4267a151d01ed6b034bb497396c1cba53 Mon Sep 17 00:00:00 2001 From: Lalit Maganti Date: Fri, 18 Nov 2022 19:20:37 +0000 Subject: [PATCH] frameworks: improve semantics and documentation for asyncTraceForTrack* This CL improves the documentation and semantic behaviour of asyncTraceForTrackBegin to match how these methods were expected to be used. [1] misuses the event as previously written because it provides overlapping events with the same cookie: however, it also nests the events and due to how Perfetto UI/trace_processor are implemented, this just ends up *happening* to work out. I will send some follow up CLs cleaning up usages in the broadcast code where we should nest events instead of overlapping them. Bug: 259535570 Change-Id: Idcf10bed7ed1228b0ba9aa62ef3f47169030cc6a --- core/java/android/os/Trace.java | 90 ++++++++++++++++++++++++++++++--- 1 file changed, 82 insertions(+), 8 deletions(-) diff --git a/core/java/android/os/Trace.java b/core/java/android/os/Trace.java index fb197f5be2a88..b91939383d4fd 100644 --- a/core/java/android/os/Trace.java +++ b/core/java/android/os/Trace.java @@ -241,9 +241,16 @@ public final class Trace { /** * Writes a trace message to indicate that a given section of code has * begun. Must be followed by a call to {@link #asyncTraceEnd} using the same - * tag. Unlike {@link #traceBegin(long, String)} and {@link #traceEnd(long)}, - * asynchronous events do not need to be nested. The name and cookie used to - * begin an event must be used to end it. + * tag, name and cookie. + * + * If two events with the same methodName overlap in time then they *must* have + * different cookie values. If they do not, the trace can become corrupted + * in unpredictable ways. + * + * Unlike {@link #traceBegin(long, String)} and {@link #traceEnd(long)}, + * asynchronous events cannot be not nested. Consider using + * {@link #asyncTraceForTrackBegin(long, String, String, int)} + * if nested asynchronous events are needed. * * @param traceTag The trace tag. * @param methodName The method name to appear in the trace. @@ -264,6 +271,9 @@ public final class Trace { * Must be called exactly once for each call to {@link #asyncTraceBegin(long, String, int)} * using the same tag, name and cookie. * + * See the documentation for {@link #asyncTraceBegin(long, String, int)}. + * for inteded usage of this method. + * * @param traceTag The trace tag. * @param methodName The method name to appear in the trace. * @param cookie Unique identifier for distinguishing simultaneous events @@ -283,14 +293,73 @@ public final class Trace { * Writes a trace message to indicate that a given section of code has * begun. Must be followed by a call to {@link #asyncTraceForTrackEnd} using the same * track name and cookie. - * This function operates exactly like {@link #asyncTraceBegin(long, String, int)}, - * except with the inclusion of a track name argument for where this method should appear. - * The cookie must be unique on the trackName level, not the methodName level + * + * Events with the same trackName and cookie nest inside each other in the + * same way as calls to {@link #traceBegin(long, String)} and + * {@link #traceEnd(long)}. + * + * If two events with the same trackName overlap in time but do not nest + * correctly, then they *must* have different cookie values. If they do not, + * the trace can become corrupted in unpredictable ways. + * + * Good Example: + * + * public void parent() { + * asyncTraceForTrackBegin(TRACE_TAG_ALWAYS, "Track", "parent", mId); + * child() + * asyncTraceForTrackEnd(TRACE_TAG_ALWAYS, "Track", mId); + * } + * + * public void child() { + * asyncTraceForTrackBegin(TRACE_TAG_ALWAYS, "Track", "child", mId); + * // Some code here. + * asyncTraceForTrackEnd(TRACE_TAG_ALWAYS, "Track", mId); + * } + * + * This would be visualized as so: + * [ Parent ] + * [ Child ] + * + * Bad Example: + * + * public static void processData(String dataToProcess) { + * asyncTraceForTrackBegin(TRACE_TAG_ALWAYS, "processDataInParallel", "processData", 0); + * // Some code here. + * asyncTraceForTrackEnd(TRACE_TAG_ALWAYS, "processDataInParallel", 0); + * } + * + * public static void processDataInParallel({@code List} data) { + * ExecutorService executor = Executors.newCachedThreadPool(); + * for (String s : data) { + * pool.execute(() -> processData(s)); + * } + * } + * + * This is invalid because it's possible for processData to be run many times + * in parallel (i.e. processData events overlap) but the same cookie is + * provided each time. + * + * To fix this, specify a different id in each invocation of processData: + * + * public static void processData(String dataToProcess, int id) { + * asyncTraceForTrackBegin(TRACE_TAG_ALWAYS, "processDataInParallel", "processData", id); + * // Some code here. + * asyncTraceForTrackEnd(TRACE_TAG_ALWAYS, "processDataInParallel", id); + * } + * + * public static void processDataInParallel({@code List} data) { + * ExecutorService executor = Executors.newCachedThreadPool(); + * for (int i = 0; i < data.size(); ++i) { + * pool.execute(() -> processData(data.get(i), i)); + * } + * } * * @param traceTag The trace tag. * @param trackName The track where the event should appear in the trace. * @param methodName The method name to appear in the trace. - * @param cookie Unique identifier for distinguishing simultaneous events + * @param cookie Unique identifier used for nesting events on a single + * track. Events which overlap without nesting on the same + * track must have different values for cookie. * * @hide */ @@ -307,9 +376,14 @@ public final class Trace { * {@link #asyncTraceForTrackBegin(long, String, String, int)} * using the same tag, track name, and cookie. * + * See the documentation for {@link #asyncTraceForTrackBegin(long, String, String, int)}. + * for inteded usage of this method. + * * @param traceTag The trace tag. * @param trackName The track where the event should appear in the trace. - * @param cookie Unique identifier for distinguishing simultaneous events + * @param cookie Unique identifier used for nesting events on a single + * track. Events which overlap without nesting on the same + * track must have different values for cookie. * * @hide */