xref: /openbmc/qemu/contrib/plugins/lockstep.c (revision 44e79489)
1 /*
2  * Lockstep Execution Plugin
3  *
4  * Allows you to execute two QEMU instances in lockstep and report
5  * when their execution diverges. This is mainly useful for developers
6  * who want to see where a change to TCG code generation has
7  * introduced a subtle and hard to find bug.
8  *
9  * Caveats:
10  *   - single-threaded linux-user apps only with non-deterministic syscalls
11  *   - no MTTCG enabled system emulation (icount may help)
12  *
13  * While icount makes things more deterministic it doesn't mean a
14  * particular run may execute the exact same sequence of blocks. An
15  * asynchronous event (for example X11 graphics update) may cause a
16  * block to end early and a new partial block to start. This means
17  * serial only test cases are a better bet. -d nochain may also help
18  * as well as -accel tcg,one-insn-per-tb=on
19  *
20  * This code is not thread safe!
21  *
22  * Copyright (c) 2020 Linaro Ltd
23  *
24  * SPDX-License-Identifier: GPL-2.0-or-later
25  */
26 
27 #include <glib.h>
28 #include <inttypes.h>
29 #include <unistd.h>
30 #include <sys/socket.h>
31 #include <sys/un.h>
32 #include <stdio.h>
33 #include <errno.h>
34 
35 #include <qemu-plugin.h>
36 
37 QEMU_PLUGIN_EXPORT int qemu_plugin_version = QEMU_PLUGIN_VERSION;
38 
39 /* saved so we can uninstall later */
40 static qemu_plugin_id_t our_id;
41 
42 static unsigned long bb_count;
43 static unsigned long insn_count;
44 
45 /* Information about a translated block */
46 typedef struct {
47     uint64_t pc;
48     uint64_t insns;
49 } BlockInfo;
50 
51 /* Information about an execution state in the log */
52 typedef struct {
53     BlockInfo *block;
54     unsigned long insn_count;
55     unsigned long block_count;
56 } ExecInfo;
57 
58 /* The execution state we compare */
59 typedef struct {
60     uint64_t pc;
61     uint64_t insn_count;
62 } ExecState;
63 
64 typedef struct {
65     GSList *log_pos;
66     int distance;
67 } DivergeState;
68 
69 /* list of translated block info */
70 static GSList *blocks;
71 
72 /* execution log and points of divergence */
73 static GSList *log, *divergence_log;
74 
75 static int socket_fd;
76 static char *path_to_unlink;
77 
78 static bool verbose;
79 
plugin_cleanup(qemu_plugin_id_t id)80 static void plugin_cleanup(qemu_plugin_id_t id)
81 {
82     /* Free our block data */
83     g_slist_free_full(blocks, &g_free);
84     g_slist_free_full(log, &g_free);
85     g_slist_free(divergence_log);
86 
87     close(socket_fd);
88     if (path_to_unlink) {
89         unlink(path_to_unlink);
90     }
91 }
92 
plugin_exit(qemu_plugin_id_t id,void * p)93 static void plugin_exit(qemu_plugin_id_t id, void *p)
94 {
95     g_autoptr(GString) out = g_string_new("No divergence :-)\n");
96     g_string_append_printf(out, "Executed %ld/%d blocks\n",
97                            bb_count, g_slist_length(log));
98     g_string_append_printf(out, "Executed ~%ld instructions\n", insn_count);
99     qemu_plugin_outs(out->str);
100 
101     plugin_cleanup(id);
102 }
103 
104 /*
105  * g_memdup has been deprecated in Glib since 2.68 and
106  * will complain about it if you try to use it. However until
107  * glib_req_ver for QEMU is bumped we make a copy of the glib-compat
108  * handler.
109  */
g_memdup2_qemu(gconstpointer mem,gsize byte_size)110 static inline gpointer g_memdup2_qemu(gconstpointer mem, gsize byte_size)
111 {
112 #if GLIB_CHECK_VERSION(2, 68, 0)
113     return g_memdup2(mem, byte_size);
114 #else
115     gpointer new_mem;
116 
117     if (mem && byte_size != 0) {
118         new_mem = g_malloc(byte_size);
119         memcpy(new_mem, mem, byte_size);
120     } else {
121         new_mem = NULL;
122     }
123 
124     return new_mem;
125 #endif
126 }
127 #define g_memdup2(m, s) g_memdup2_qemu(m, s)
128 
report_divergance(ExecState * us,ExecState * them)129 static void report_divergance(ExecState *us, ExecState *them)
130 {
131     DivergeState divrec = { log, 0 };
132     g_autoptr(GString) out = g_string_new("");
133     bool diverged = false;
134 
135     /*
136      * If we have diverged before did we get back on track or are we
137      * totally losing it?
138      */
139     if (divergence_log) {
140         DivergeState *last = (DivergeState *) divergence_log->data;
141         GSList *entry;
142 
143         for (entry = log; g_slist_next(entry); entry = g_slist_next(entry)) {
144             if (entry == last->log_pos) {
145                 break;
146             }
147             divrec.distance++;
148         }
149 
150         /*
151          * If the last two records are so close it is likely we will
152          * not recover synchronisation with the other end.
153          */
154         if (divrec.distance == 1 && last->distance == 1) {
155             diverged = true;
156         }
157     }
158     divergence_log = g_slist_prepend(divergence_log,
159                                      g_memdup2(&divrec, sizeof(divrec)));
160 
161     /* Output short log entry of going out of sync... */
162     if (verbose || divrec.distance == 1 || diverged) {
163         g_string_printf(out, "@ "
164                         "0x%016" PRIx64 " (%" PRId64 ") vs "
165                         "0x%016" PRIx64 " (%" PRId64 ")"
166                         " (%d/%d since last)\n",
167                         us->pc, us->insn_count,
168                         them->pc, them->insn_count,
169                         g_slist_length(divergence_log),
170                         divrec.distance);
171         qemu_plugin_outs(out->str);
172     }
173 
174     if (diverged) {
175         int i;
176         GSList *entry;
177 
178         g_string_printf(out, "Δ too high, we have diverged, previous insns\n");
179 
180         for (entry = log, i = 0;
181              g_slist_next(entry) && i < 5;
182              entry = g_slist_next(entry), i++) {
183             ExecInfo *prev = (ExecInfo *) entry->data;
184             g_string_append_printf(out,
185                                    "  previously @ 0x%016" PRIx64 "/%" PRId64
186                                    " (%ld insns)\n",
187                                    prev->block->pc, prev->block->insns,
188                                    prev->insn_count);
189         }
190         qemu_plugin_outs(out->str);
191         qemu_plugin_outs("giving up\n");
192         qemu_plugin_uninstall(our_id, plugin_cleanup);
193     }
194 }
195 
vcpu_tb_exec(unsigned int cpu_index,void * udata)196 static void vcpu_tb_exec(unsigned int cpu_index, void *udata)
197 {
198     BlockInfo *bi = (BlockInfo *) udata;
199     ExecState us, them;
200     ssize_t bytes;
201     ExecInfo *exec;
202 
203     us.pc = bi->pc;
204     us.insn_count = insn_count;
205 
206     /*
207      * Write our current position to the other end. If we fail the
208      * other end has probably died and we should shut down gracefully.
209      */
210     bytes = write(socket_fd, &us, sizeof(ExecState));
211     if (bytes < sizeof(ExecState)) {
212         qemu_plugin_outs(bytes < 0 ?
213                          "problem writing to socket" :
214                          "wrote less than expected to socket");
215         qemu_plugin_uninstall(our_id, plugin_cleanup);
216         return;
217     }
218 
219     /*
220      * Now read where our peer has reached. Again a failure probably
221      * indicates the other end died and we should close down cleanly.
222      */
223     bytes = read(socket_fd, &them, sizeof(ExecState));
224     if (bytes < sizeof(ExecState)) {
225         qemu_plugin_outs(bytes < 0 ?
226                          "problem reading from socket" :
227                          "read less than expected");
228         qemu_plugin_uninstall(our_id, plugin_cleanup);
229         return;
230     }
231 
232     /*
233      * Compare and report if we have diverged.
234      */
235     if (us.pc != them.pc) {
236         report_divergance(&us, &them);
237     }
238 
239     /*
240      * Assume this block will execute fully and record it
241      * in the execution log.
242      */
243     insn_count += bi->insns;
244     bb_count++;
245     exec = g_new0(ExecInfo, 1);
246     exec->block = bi;
247     exec->insn_count = insn_count;
248     exec->block_count = bb_count;
249     log = g_slist_prepend(log, exec);
250 }
251 
vcpu_tb_trans(qemu_plugin_id_t id,struct qemu_plugin_tb * tb)252 static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb)
253 {
254     BlockInfo *bi = g_new0(BlockInfo, 1);
255     bi->pc = qemu_plugin_tb_vaddr(tb);
256     bi->insns = qemu_plugin_tb_n_insns(tb);
257 
258     /* save a reference so we can free later */
259     blocks = g_slist_prepend(blocks, bi);
260     qemu_plugin_register_vcpu_tb_exec_cb(tb, vcpu_tb_exec,
261                                          QEMU_PLUGIN_CB_NO_REGS, (void *)bi);
262 }
263 
264 
265 /*
266  * Instead of encoding master/slave status into what is essentially
267  * two peers we shall just take the simple approach of checking for
268  * the existence of the pipe and assuming if it's not there we are the
269  * first process.
270  */
setup_socket(const char * path)271 static bool setup_socket(const char *path)
272 {
273     struct sockaddr_un sockaddr;
274     const gsize pathlen = sizeof(sockaddr.sun_path) - 1;
275     int fd;
276 
277     fd = socket(AF_UNIX, SOCK_STREAM, 0);
278     if (fd < 0) {
279         perror("create socket");
280         return false;
281     }
282 
283     sockaddr.sun_family = AF_UNIX;
284     if (g_strlcpy(sockaddr.sun_path, path, pathlen) >= pathlen) {
285         perror("bad path");
286         close(fd);
287         return false;
288     }
289 
290     if (bind(fd, (struct sockaddr *)&sockaddr, sizeof(sockaddr)) < 0) {
291         perror("bind socket");
292         close(fd);
293         return false;
294     }
295 
296     /* remember to clean-up */
297     path_to_unlink = g_strdup(path);
298 
299     if (listen(fd, 1) < 0) {
300         perror("listen socket");
301         close(fd);
302         return false;
303     }
304 
305     socket_fd = accept(fd, NULL, NULL);
306     if (socket_fd < 0 && errno != EINTR) {
307         perror("accept socket");
308         close(fd);
309         return false;
310     }
311 
312     qemu_plugin_outs("setup_socket::ready\n");
313 
314     close(fd);
315     return true;
316 }
317 
connect_socket(const char * path)318 static bool connect_socket(const char *path)
319 {
320     int fd;
321     struct sockaddr_un sockaddr;
322     const gsize pathlen = sizeof(sockaddr.sun_path) - 1;
323 
324     fd = socket(AF_UNIX, SOCK_STREAM, 0);
325     if (fd < 0) {
326         perror("create socket");
327         return false;
328     }
329 
330     sockaddr.sun_family = AF_UNIX;
331     if (g_strlcpy(sockaddr.sun_path, path, pathlen) >= pathlen) {
332         perror("bad path");
333         close(fd);
334         return false;
335     }
336 
337     if (connect(fd, (struct sockaddr *)&sockaddr, sizeof(sockaddr)) < 0) {
338         perror("failed to connect");
339         close(fd);
340         return false;
341     }
342 
343     qemu_plugin_outs("connect_socket::ready\n");
344 
345     socket_fd = fd;
346     return true;
347 }
348 
setup_unix_socket(const char * path)349 static bool setup_unix_socket(const char *path)
350 {
351     if (g_file_test(path, G_FILE_TEST_EXISTS)) {
352         return connect_socket(path);
353     } else {
354         return setup_socket(path);
355     }
356 }
357 
358 
qemu_plugin_install(qemu_plugin_id_t id,const qemu_info_t * info,int argc,char ** argv)359 QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
360                                            const qemu_info_t *info,
361                                            int argc, char **argv)
362 {
363     int i;
364     g_autofree char *sock_path = NULL;
365 
366     for (i = 0; i < argc; i++) {
367         char *p = argv[i];
368         g_auto(GStrv) tokens = g_strsplit(p, "=", 2);
369 
370         if (g_strcmp0(tokens[0], "verbose") == 0) {
371             if (!qemu_plugin_bool_parse(tokens[0], tokens[1], &verbose)) {
372                 fprintf(stderr, "boolean argument parsing failed: %s\n", p);
373                 return -1;
374             }
375         } else if (g_strcmp0(tokens[0], "sockpath") == 0) {
376             sock_path = g_strdup(tokens[1]);
377         } else {
378             fprintf(stderr, "option parsing failed: %s\n", p);
379             return -1;
380         }
381     }
382 
383     if (sock_path == NULL) {
384         fprintf(stderr, "Need a socket path to talk to other instance.\n");
385         return -1;
386     }
387 
388     if (!setup_unix_socket(sock_path)) {
389         fprintf(stderr, "Failed to setup socket for communications.\n");
390         return -1;
391     }
392 
393     our_id = id;
394 
395     qemu_plugin_register_vcpu_tb_trans_cb(id, vcpu_tb_trans);
396     qemu_plugin_register_atexit_cb(id, plugin_exit, NULL);
397     return 0;
398 }
399