1 /*
2  * Copyright (C) 2022 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 package com.android.tradefed.invoker.tracing;
17 
18 import com.android.ddmlib.Log.LogLevel;
19 import com.android.tradefed.invoker.logger.InvocationMetricLogger;
20 import com.android.tradefed.invoker.logger.InvocationMetricLogger.InvocationMetricKey;
21 import com.android.tradefed.log.LogUtil.CLog;
22 import com.android.tradefed.util.FileUtil;
23 
24 import java.io.File;
25 import java.io.FileInputStream;
26 import java.io.FileOutputStream;
27 import java.io.IOException;
28 import java.util.HashMap;
29 import java.util.Map;
30 import java.util.UUID;
31 import java.util.zip.GZIPInputStream;
32 
33 import perfetto.protos.PerfettoTrace.DebugAnnotation;
34 import perfetto.protos.PerfettoTrace.ProcessDescriptor;
35 import perfetto.protos.PerfettoTrace.ThreadDescriptor;
36 import perfetto.protos.PerfettoTrace.Trace;
37 import perfetto.protos.PerfettoTrace.TracePacket;
38 import perfetto.protos.PerfettoTrace.TrackDescriptor;
39 import perfetto.protos.PerfettoTrace.TrackEvent;
40 
41 /** Main class helping to describe and manage an active trace. */
42 public class ActiveTrace {
43 
44     public static final String TRACE_KEY = "invocation-trace";
45     private final long pid;
46     private final long tid;
47     private final long traceUuid;
48     private final int uid = 5555; // TODO: collect a real uid
49     private final boolean mainTradefedProcess;
50     private final Map<String, Long> mThreadToTracker;
51     // File where the final trace gets outputed
52     private File mTraceOutput;
53 
ActiveTrace(long pid, long tid)54     public ActiveTrace(long pid, long tid) {
55         this(pid, tid, false);
56     }
57 
58     /**
59      * Constructor.
60      *
61      * @param pid Current process id
62      * @param tid Current thread id
63      */
ActiveTrace(long pid, long tid, boolean mainProcess)64     public ActiveTrace(long pid, long tid, boolean mainProcess) {
65         this.pid = pid;
66         this.tid = tid;
67         this.traceUuid = UUID.randomUUID().getMostSignificantBits() & Long.MAX_VALUE;
68         mThreadToTracker = new HashMap<>();
69         mainTradefedProcess = mainProcess;
70     }
71 
72     /** Start the tracing and report the metadata of the trace. */
startTracing(boolean isSubprocess)73     public void startTracing(boolean isSubprocess) {
74         if (mTraceOutput != null) {
75             throw new IllegalStateException("Tracing was already started.");
76         }
77         try {
78             mTraceOutput = FileUtil.createTempFile(TRACE_KEY, ".perfetto-trace");
79         } catch (IOException e) {
80             CLog.e(e);
81         }
82         // Initialize all the trace metadata
83         createMainInvocationTracker((int) pid, (int) tid, traceUuid, isSubprocess);
84     }
85 
86     /** Provide the trace file from a subprocess to be added to the parent. */
addSubprocessTrace(File subTrace)87     public void addSubprocessTrace(File subTrace) {
88         if (mTraceOutput == null) {
89             return;
90         }
91 
92         try (FileInputStream stream = new FileInputStream(subTrace)) {
93             try (GZIPInputStream gzip = new GZIPInputStream(stream)) {
94                 CLog.logAndDisplay(LogLevel.DEBUG, "merging with gzipped %s", subTrace);
95                 FileUtil.writeToFile(gzip, mTraceOutput, true);
96                 return;
97             } catch (IOException e) {
98                 CLog.logAndDisplay(LogLevel.DEBUG, "%s isn't gzip.", subTrace);
99             }
100         } catch (IOException e) {
101             CLog.e(e);
102         }
103 
104         try (FileInputStream stream = new FileInputStream(subTrace)) {
105             FileUtil.writeToFile(stream, mTraceOutput, true);
106         } catch (IOException e) {
107             CLog.e(e);
108         }
109     }
110 
reportTraceEvent(String categories, String name, TrackEvent.Type type)111     public void reportTraceEvent(String categories, String name, TrackEvent.Type type) {
112         reportTraceEvent(categories, name, (int) tid, null, type);
113     }
114 
115     /**
116      * thread id of the thread that initiated the tracing.
117      */
reportingThreadId()118     public long reportingThreadId() {
119         return tid;
120     }
121 
isMainTradefedProcess()122     public boolean isMainTradefedProcess() {
123         return mainTradefedProcess;
124     }
125 
126     /**
127      * Very basic event reporting to do START / END of traces.
128      *
129      * @param categories Category associated with event
130      * @param name Event name
131      * @param type Type of the event being reported
132      */
reportTraceEvent( String categories, String name, int threadId, String threadName, TrackEvent.Type type)133     public void reportTraceEvent(
134             String categories, String name, int threadId, String threadName, TrackEvent.Type type) {
135         long traceIdentifier = traceUuid;
136         if (threadId != this.tid) {
137             synchronized (mThreadToTracker) {
138                 if (mThreadToTracker.containsKey(Integer.toString(threadId))) {
139                     Long returnedValue = mThreadToTracker.get(Integer.toString(threadId));
140                     if (returnedValue == null) {
141                         CLog.e("Consistency error in trace identifier.");
142                         InvocationMetricLogger.addInvocationMetrics(
143                                 InvocationMetricKey.TRACE_INTERNAL_ERROR, 1);
144                         return;
145                     }
146                     traceIdentifier = returnedValue;
147                 } else {
148                     traceIdentifier = UUID.randomUUID().getMostSignificantBits() & Long.MAX_VALUE;
149                     createThreadTracker((int) pid, threadId, threadName, traceIdentifier);
150                     mThreadToTracker.put(Integer.toString(threadId), Long.valueOf(traceIdentifier));
151                 }
152             }
153         }
154         TracePacket.Builder tracePacket =
155                 TracePacket.newBuilder()
156                         .setTrustedUid(uid)
157                         .setTrustedPid((int) pid)
158                         .setTimestamp(System.nanoTime())
159                         .setTrustedPacketSequenceId(1)
160                         .setSequenceFlags(1)
161                         .setTrackEvent(
162                                 TrackEvent.newBuilder()
163                                         .setTrackUuid(traceIdentifier)
164                                         .setName(name)
165                                         .setType(type)
166                                         .addCategories(categories)
167                                         .addDebugAnnotations(
168                                                 DebugAnnotation.newBuilder().setName(name)));
169         writeToTrace(tracePacket.build());
170     }
171 
172     /** Reports the final trace files and clean up resources as needed. */
finalizeTracing()173     public File finalizeTracing() {
174         CLog.logAndDisplay(LogLevel.DEBUG, "Finalizing trace: %s", mTraceOutput);
175         File trace = mTraceOutput;
176         mTraceOutput = null;
177         return trace;
178     }
179 
createProcessName(boolean isSubprocess)180     private String createProcessName(boolean isSubprocess) {
181         if (isSubprocess) {
182             return "subprocess-test-invocation";
183         }
184         if (isMainTradefedProcess()) {
185             return "Tradefed";
186         }
187         return "test-invocation";
188     }
189 
createMainInvocationTracker( int pid, int tid, long traceUuid, boolean isSubprocess)190     private void createMainInvocationTracker(
191             int pid, int tid, long traceUuid, boolean isSubprocess) {
192         TrackDescriptor.Builder descriptor =
193                 TrackDescriptor.newBuilder()
194                         .setUuid(traceUuid)
195                         .setName(createProcessName(isSubprocess))
196                         .setThread(
197                                 ThreadDescriptor.newBuilder()
198                                         .setTid(tid)
199                                         .setThreadName("invocation-thread")
200                                         .setPid(pid))
201                         .setProcess(
202                                 ProcessDescriptor.newBuilder()
203                                         .setPid(pid)
204                                         .setProcessName(createProcessName(isSubprocess)));
205 
206         TracePacket.Builder traceTrackDescriptor =
207                 TracePacket.newBuilder()
208                         .setTrustedUid(uid)
209                         .setTimestamp(System.nanoTime())
210                         .setTrustedPacketSequenceId(1)
211                         .setSequenceFlags(1)
212                         .setTrustedPid(pid)
213                         .setTrackDescriptor(descriptor.build());
214 
215         writeToTrace(traceTrackDescriptor.build());
216     }
217 
createThreadTracker(int pid, int tid, String threadName, long traceUuid)218     private void createThreadTracker(int pid, int tid, String threadName, long traceUuid) {
219         TrackDescriptor.Builder descriptor =
220                 TrackDescriptor.newBuilder()
221                         .setUuid(traceUuid)
222                         .setThread(
223                                 ThreadDescriptor.newBuilder()
224                                         .setTid(tid)
225                                         .setThreadName(threadName)
226                                         .setPid(pid));
227 
228         TracePacket.Builder traceTrackDescriptor =
229                 TracePacket.newBuilder()
230                         .setTrustedUid(uid)
231                         .setTimestamp(System.nanoTime())
232                         .setTrustedPacketSequenceId(1)
233                         .setSequenceFlags(1)
234                         .setTrustedPid(pid)
235                         .setTrackDescriptor(descriptor.build());
236 
237         writeToTrace(traceTrackDescriptor.build());
238     }
239 
writeToTrace(TracePacket packet)240     private synchronized void writeToTrace(TracePacket packet) {
241         if (mTraceOutput == null) {
242             return;
243         }
244         // Perfetto UI supports repeated Trace
245         Trace wrappingTrace = Trace.newBuilder().addPacket(packet).build();
246         try (FileOutputStream out = new FileOutputStream(mTraceOutput, true)) {
247             wrappingTrace.writeTo(out);
248             out.flush();
249         } catch (IOException e) {
250             CLog.e("Failed to write execution trace to file.");
251             CLog.e(e);
252         }
253     }
254 }
255