1 /*
2  * Copyright (C) 2023 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 
17 package com.android.microdroid.test.host;
18 
19 import static com.google.common.truth.Truth.assertWithMessage;
20 
21 import static org.junit.Assert.assertNotNull;
22 
23 import com.android.tradefed.device.ITestDevice;
24 import com.android.tradefed.log.LogUtil.CLog;
25 import com.android.tradefed.util.SimpleStats;
26 
27 import java.io.BufferedReader;
28 import java.io.File;
29 import java.io.FileReader;
30 import java.text.ParseException;
31 import java.util.ArrayList;
32 import java.util.Arrays;
33 import java.util.List;
34 import java.util.regex.Matcher;
35 import java.util.regex.Pattern;
36 
37 import javax.annotation.Nonnull;
38 
39 class KvmHypEvent {
40     public final int cpu;
41     public final double timestamp;
42     public final String name;
43     public final String args;
44     public final boolean valid;
45 
46     private static final Pattern LOST_EVENT_PATTERN =
47             Pattern.compile("^CPU:[0-9]* \\[LOST ([0-9]*) EVENTS\\]");
48 
KvmHypEvent(String str)49     public KvmHypEvent(String str) {
50         Matcher matcher = LOST_EVENT_PATTERN.matcher(str);
51         if (matcher.find()) throw new OutOfMemoryError("Lost " + matcher.group(1) + " events");
52 
53         Pattern pattern = Pattern.compile("^\\[([0-9]*)\\][ \t]*([0-9]*\\.[0-9]*): (\\S+) (.*)");
54 
55         matcher = pattern.matcher(str);
56         if (!matcher.find()) {
57             valid = false;
58             cpu = 0;
59             timestamp = 0;
60             name = "";
61             args = "";
62             CLog.w("Failed to parse hyp event: " + str);
63             return;
64         }
65 
66         cpu = Integer.parseInt(matcher.group(1));
67         timestamp = Double.parseDouble(matcher.group(2));
68         name = matcher.group(3);
69         args = matcher.group(4);
70         valid = true;
71     }
72 
toString()73     public String toString() {
74         return String.format("[%03d]\t%f: %s %s", cpu, timestamp, name, args);
75     }
76 }
77 
78 /** This class provides utilities to interact with the hyp tracing subsystem */
79 public final class KvmHypTracer {
80 
81     private static final int DEFAULT_BUF_SIZE_KB = 4 * 1024;
82 
83     private final String mHypTracingRoot;
84     private final CommandRunner mRunner;
85     private final ITestDevice mDevice;
86     private final int mNrCpus;
87     private final String mHypEvents[];
88 
89     private final ArrayList<File> mTraces;
90 
getHypTracingRoot(ITestDevice device)91     private static String getHypTracingRoot(ITestDevice device) throws Exception {
92         String legacy = "/sys/kernel/tracing/hyp/";
93         String path = "/sys/kernel/tracing/hypervisor/";
94 
95         if (device.doesFileExist(path)) {
96             return path;
97         }
98 
99         if (device.doesFileExist(legacy)) {
100             return legacy;
101         }
102 
103         throw new Exception("Hypervisor tracing not found");
104     }
105 
getHypEventsDir(String root)106     private static String getHypEventsDir(String root) {
107         if (root.endsWith("/hypervisor/"))
108             return "events/hypervisor/";
109 
110         return "events/hyp/";
111     }
112 
isSupported(ITestDevice device, String[] events)113     public static boolean isSupported(ITestDevice device, String[] events) throws Exception {
114         String dir;
115 
116         try {
117             dir = getHypTracingRoot(device);
118             dir += getHypEventsDir(dir);
119         } catch (Exception e) {
120             return false;
121         }
122 
123         for (String event: events) {
124             if (!device.doesFileExist(dir + event + "/enable"))
125                 return false;
126         }
127         return true;
128     }
129 
KvmHypTracer(@onnull ITestDevice device, String[] events)130     public KvmHypTracer(@Nonnull ITestDevice device, String[] events) throws Exception {
131         assertWithMessage("Hypervisor events " + String.join(",", events) + " not supported")
132                 .that(isSupported(device, events))
133                 .isTrue();
134 
135         mHypTracingRoot = getHypTracingRoot(device);
136         mDevice = device;
137         mRunner = new CommandRunner(mDevice);
138         mTraces = new ArrayList<File>();
139         mNrCpus = Integer.parseInt(mRunner.run("nproc"));
140         mHypEvents = events;
141     }
142 
setNode(String node, int val)143     private void setNode(String node, int val) throws Exception {
144         mRunner.run("echo " + val + " > " + mHypTracingRoot + node);
145     }
146 
run(String payload_cmd)147     public String run(String payload_cmd) throws Exception {
148         mTraces.clear();
149 
150         setNode("tracing_on", 0);
151         mRunner.run("echo 0 | tee " + mHypTracingRoot + "events/*/*/enable");
152         setNode("buffer_size_kb", DEFAULT_BUF_SIZE_KB);
153 
154         for (String event: mHypEvents) {
155             setNode(getHypEventsDir(mHypTracingRoot) + event + "/enable", 1);
156         }
157 
158         setNode("trace", 0);
159 
160         /* Cat each per-cpu trace_pipe in its own tmp file in the background */
161         String cmd = "cd " + mHypTracingRoot + ";";
162         String trace_pipes[] = new String[mNrCpus];
163         for (int i = 0; i < mNrCpus; i++) {
164             trace_pipes[i] = mRunner.run("mktemp -t trace_pipe.cpu" + i + ".XXXXXXXXXX");
165             cmd += "cat per_cpu/cpu" + i + "/trace_pipe > " + trace_pipes[i] + " &";
166             cmd += "CPU" + i + "_TRACE_PIPE_PID=$!;";
167         }
168 
169         String cmd_script = mRunner.run("mktemp -t cmd_script.XXXXXXXXXX");
170         mRunner.run("echo '" + payload_cmd + "' > " + cmd_script);
171 
172         /* Run the payload with tracing enabled */
173         cmd += "echo 1 > tracing_on;";
174         String cmd_stdout = mRunner.run("mktemp -t cmd_stdout.XXXXXXXXXX");
175         cmd += "sh " + cmd_script + " > " + cmd_stdout + ";";
176         cmd += "echo 0 > tracing_on;";
177 
178         /* Wait for cat to finish reading the pipe interface before killing it */
179         for (int i = 0; i < mNrCpus; i++) {
180             cmd +=
181                     "while $(test '$(ps -o S -p $CPU"
182                             + i
183                             + "_TRACE_PIPE_PID | tail -n 1)' = 'R'); do sleep 1; done;";
184             cmd += "kill -9 $CPU" + i + "_TRACE_PIPE_PID;";
185         }
186         cmd += "wait";
187 
188         /*
189          * The whole thing runs in a single command for simplicity as `adb
190          * shell` doesn't play well with subprocesses outliving their parent,
191          * and cat-ing a trace_pipe is blocking, so doing so from separate Java
192          * threads wouldn't be much easier as we would need to actively kill
193          * them too.
194          */
195         mRunner.run(cmd);
196 
197         mRunner.run("rm -f " + cmd_script);
198 
199         for (String t : trace_pipes) {
200             File trace = mDevice.pullFile(t);
201             assertNotNull(trace);
202             mTraces.add(trace);
203             mRunner.run("rm -f " + t);
204         }
205 
206         String res = mRunner.run("cat " + cmd_stdout);
207         mRunner.run("rm -f " + cmd_stdout);
208         return res;
209     }
210 
hasEvents(String[] events)211     private boolean hasEvents(String[] events) {
212         for (String event : events) {
213             if (!Arrays.asList(mHypEvents).contains(event)) {
214                 return false;
215             }
216         }
217 
218         return true;
219     }
220 
getNextEvent(BufferedReader br)221     private KvmHypEvent getNextEvent(BufferedReader br) throws Exception {
222         KvmHypEvent event;
223         String l;
224 
225         if ((l = br.readLine()) == null) return null;
226 
227         event = new KvmHypEvent(l);
228         if (!event.valid) return null;
229 
230         return event;
231     }
232 
getDurationStats()233     public SimpleStats getDurationStats() throws Exception {
234         String[] reqEvents = {"hyp_enter", "hyp_exit"};
235         SimpleStats stats = new SimpleStats();
236 
237         assertWithMessage("KvmHypTracer() is missing events " + String.join(",", reqEvents))
238                 .that(hasEvents(reqEvents))
239                 .isTrue();
240 
241         for (File trace : mTraces) {
242             BufferedReader br = new BufferedReader(new FileReader(trace));
243             double last = 0.0, hyp_enter = 0.0;
244             String prev_event = "";
245             KvmHypEvent hypEvent;
246 
247             while ((hypEvent = getNextEvent(br)) != null) {
248                 int cpu = hypEvent.cpu;
249                 if (cpu < 0 || cpu >= mNrCpus)
250                     throw new ParseException("Incorrect CPU number: " + cpu, 0);
251 
252                 double cur = hypEvent.timestamp;
253                 if (cur < last) throw new ParseException("Time must not go backward: " + cur, 0);
254                 last = cur;
255 
256                 String event = hypEvent.name;
257                 if (event.equals(prev_event)) {
258                     throw new ParseException(
259                             "Hyp event found twice in a row: " + trace + " - " + hypEvent, 0);
260                 }
261 
262                 switch (event) {
263                     case "hyp_exit":
264                         if (prev_event.equals("hyp_enter")) stats.add(cur - hyp_enter);
265                         break;
266                     case "hyp_enter":
267                         hyp_enter = cur;
268                         break;
269                     default:
270                         throw new ParseException("Unexpected line in trace " + hypEvent, 0);
271                 }
272                 prev_event = event;
273             }
274         }
275 
276         return stats;
277     }
278 
getPsciMemProtect()279     public List<Integer> getPsciMemProtect() throws Exception {
280         String[] reqEvents = {"psci_mem_protect"};
281         List<Integer> psciMemProtect = new ArrayList<>();
282 
283         assertWithMessage("KvmHypTracer() is missing events " + String.join(",", reqEvents))
284                 .that(hasEvents(reqEvents))
285                 .isTrue();
286 
287         BufferedReader[] brs = new BufferedReader[mTraces.size()];
288         KvmHypEvent[] next = new KvmHypEvent[mTraces.size()];
289 
290         for (int i = 0; i < mTraces.size(); i++) {
291             brs[i] = new BufferedReader(new FileReader(mTraces.get(i)));
292             next[i] = getNextEvent(brs[i]);
293         }
294 
295         while (true) {
296             double oldest = Double.MAX_VALUE;
297             int oldestIdx = -1;
298 
299             for (int i = 0; i < mTraces.size(); i++) {
300                 if ((next[i] != null) && (next[i].timestamp < oldest)) {
301                     oldest = next[i].timestamp;
302                     oldestIdx = i;
303                 }
304             }
305 
306             if (oldestIdx < 0) break;
307 
308             Pattern pattern = Pattern.compile("count=([0-9]*) was=([0-9]*)");
309             Matcher matcher = pattern.matcher(next[oldestIdx].args);
310             if (!matcher.find()) {
311                 throw new ParseException(
312                         "Unexpected psci_mem_protect event: " + next[oldestIdx], 0);
313             }
314 
315             int count = Integer.parseInt(matcher.group(1));
316             int was = Integer.parseInt(matcher.group(2));
317 
318             if (psciMemProtect.isEmpty()) {
319                 psciMemProtect.add(was);
320             }
321 
322             psciMemProtect.add(count);
323             next[oldestIdx] = getNextEvent(brs[oldestIdx]);
324         }
325 
326         return psciMemProtect;
327     }
328 }
329