From 5070570c9089b905dd9efae30ee4318033c6ccd6 Mon Sep 17 00:00:00 2001 From: Namhyung Kim Date: Wed, 8 Nov 2017 00:31:34 +0900 Subject: [PATCH 1/4] trace: Simplify find_debugfs() The return vale of find_debugfs() is 1 if it could find a mount point of debugfs. It can be saved in the while loop instead of checking it again. Signed-off-by: Namhyung Kim Signed-off-by: Stefan Hajnoczi --- trace/ftrace.c | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/trace/ftrace.c b/trace/ftrace.c index 7de104deba..bfa38e71f0 100644 --- a/trace/ftrace.c +++ b/trace/ftrace.c @@ -19,6 +19,7 @@ static int find_debugfs(char *debugfs) { char type[100]; FILE *fp; + int ret = 0; fp = fopen("/proc/mounts", "r"); if (fp == NULL) { @@ -28,15 +29,13 @@ static int find_debugfs(char *debugfs) while (fscanf(fp, "%*s %" STR(PATH_MAX) "s %99s %*s %*d %*d\n", debugfs, type) == 2) { if (strcmp(type, "debugfs") == 0) { + ret = 1; break; } } fclose(fp); - if (strcmp(type, "debugfs") != 0) { - return 0; - } - return 1; + return ret; } bool ftrace_init(void) From babfff8e11589a2d1ab9ca777ebb16495f708616 Mon Sep 17 00:00:00 2001 From: Namhyung Kim Date: Wed, 8 Nov 2017 00:31:35 +0900 Subject: [PATCH 2/4] trace: Generalize searching for debugfs The find_debugfs() can be shared to find a different filesystem like tracefs. So make it more general and rename to find_mount(). Signed-off-by: Namhyung Kim Signed-off-by: Stefan Hajnoczi --- trace/ftrace.c | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/trace/ftrace.c b/trace/ftrace.c index bfa38e71f0..213cb2205f 100644 --- a/trace/ftrace.c +++ b/trace/ftrace.c @@ -15,7 +15,7 @@ int trace_marker_fd; -static int find_debugfs(char *debugfs) +static int find_mount(char *mount_point, const char *fstype) { char type[100]; FILE *fp; @@ -27,8 +27,8 @@ static int find_debugfs(char *debugfs) } while (fscanf(fp, "%*s %" STR(PATH_MAX) "s %99s %*s %*d %*d\n", - debugfs, type) == 2) { - if (strcmp(type, "debugfs") == 0) { + mount_point, type) == 2) { + if (strcmp(type, fstype) == 0) { ret = 1; break; } @@ -40,14 +40,14 @@ static int find_debugfs(char *debugfs) bool ftrace_init(void) { - char debugfs[PATH_MAX]; + char mount_point[PATH_MAX]; char path[PATH_MAX]; int debugfs_found; int trace_fd = -1; - debugfs_found = find_debugfs(debugfs); + debugfs_found = find_mount(mount_point, "debugfs"); if (debugfs_found) { - snprintf(path, PATH_MAX, "%s/tracing/tracing_on", debugfs); + snprintf(path, PATH_MAX, "%s/tracing/tracing_on", mount_point); trace_fd = open(path, O_WRONLY); if (trace_fd < 0) { if (errno == EACCES) { @@ -66,7 +66,7 @@ bool ftrace_init(void) } close(trace_fd); } - snprintf(path, PATH_MAX, "%s/tracing/trace_marker", debugfs); + snprintf(path, PATH_MAX, "%s/tracing/trace_marker", mount_point); trace_marker_fd = open(path, O_WRONLY); if (trace_marker_fd < 0) { perror("Could not open ftrace 'trace_marker' file"); From c9add6219514b20223f024584f0464b8842b1ec0 Mon Sep 17 00:00:00 2001 From: Namhyung Kim Date: Wed, 8 Nov 2017 00:31:36 +0900 Subject: [PATCH 3/4] trace: Try using tracefs first Recent Linux kernel provides separate tracefs which doesn't need to be mounted on the debugfs. Although most systems mount it at the traditional place on the debugfs, it'd be safer to check tracefs first. Signed-off-by: Namhyung Kim Signed-off-by: Stefan Hajnoczi --- trace/ftrace.c | 18 ++++++++++++------ 1 file changed, 12 insertions(+), 6 deletions(-) diff --git a/trace/ftrace.c b/trace/ftrace.c index 213cb2205f..61692a8682 100644 --- a/trace/ftrace.c +++ b/trace/ftrace.c @@ -42,12 +42,18 @@ bool ftrace_init(void) { char mount_point[PATH_MAX]; char path[PATH_MAX]; - int debugfs_found; + int tracefs_found; int trace_fd = -1; + const char *subdir = ""; - debugfs_found = find_mount(mount_point, "debugfs"); - if (debugfs_found) { - snprintf(path, PATH_MAX, "%s/tracing/tracing_on", mount_point); + tracefs_found = find_mount(mount_point, "tracefs"); + if (!tracefs_found) { + tracefs_found = find_mount(mount_point, "debugfs"); + subdir = "/tracing"; + } + + if (tracefs_found) { + snprintf(path, PATH_MAX, "%s%s/tracing_on", mount_point, subdir); trace_fd = open(path, O_WRONLY); if (trace_fd < 0) { if (errno == EACCES) { @@ -66,14 +72,14 @@ bool ftrace_init(void) } close(trace_fd); } - snprintf(path, PATH_MAX, "%s/tracing/trace_marker", mount_point); + snprintf(path, PATH_MAX, "%s%s/trace_marker", mount_point, subdir); trace_marker_fd = open(path, O_WRONLY); if (trace_marker_fd < 0) { perror("Could not open ftrace 'trace_marker' file"); return false; } } else { - fprintf(stderr, "debugfs is not mounted\n"); + fprintf(stderr, "tracefs is not mounted\n"); return false; } From 5c9522b358faf9688fd83cd0a881e1990bb84516 Mon Sep 17 00:00:00 2001 From: Doug Gale Date: Sat, 2 Dec 2017 20:30:37 -0500 Subject: [PATCH 4/4] gdbstub: add tracing Signed-off-by: Doug Gale Message-id: 20171203013037.31978-1-doug16k@gmail.com Signed-off-by: Stefan Hajnoczi --- gdbstub.c | 113 +++++++++++++++++++++++++++++++++++---------------- trace-events | 28 +++++++++++++ 2 files changed, 106 insertions(+), 35 deletions(-) diff --git a/gdbstub.c b/gdbstub.c index 2a94030d3b..f1d51480f7 100644 --- a/gdbstub.c +++ b/gdbstub.c @@ -21,6 +21,7 @@ #include "qemu/error-report.h" #include "qemu/cutils.h" #include "cpu.h" +#include "trace-root.h" #ifdef CONFIG_USER_ONLY #include "qemu.h" #else @@ -287,21 +288,6 @@ static int gdb_signal_to_target (int sig) return -1; } -/* #define DEBUG_GDB */ - -#ifdef DEBUG_GDB -# define DEBUG_GDB_GATE 1 -#else -# define DEBUG_GDB_GATE 0 -#endif - -#define gdb_debug(fmt, ...) do { \ - if (DEBUG_GDB_GATE) { \ - fprintf(stderr, "%s: " fmt, __func__, ## __VA_ARGS__); \ - } \ -} while (0) - - typedef struct GDBRegisterState { int base_reg; int num_regs; @@ -410,10 +396,13 @@ int use_gdb_syscalls(void) /* Resume execution. */ static inline void gdb_continue(GDBState *s) { + #ifdef CONFIG_USER_ONLY s->running_state = 1; + trace_gdbstub_op_continue(); #else if (!runstate_needs_reset()) { + trace_gdbstub_op_continue(); vm_start(); } #endif @@ -434,6 +423,7 @@ static int gdb_continue_partial(GDBState *s, char *newstates) */ CPU_FOREACH(cpu) { if (newstates[cpu->cpu_index] == 's') { + trace_gdbstub_op_stepping(cpu->cpu_index); cpu_single_step(cpu, sstep_flags); } } @@ -452,11 +442,13 @@ static int gdb_continue_partial(GDBState *s, char *newstates) case 1: break; /* nothing to do here */ case 's': + trace_gdbstub_op_stepping(cpu->cpu_index); cpu_single_step(cpu, sstep_flags); cpu_resume(cpu); flag = 1; break; case 'c': + trace_gdbstub_op_continue_cpu(cpu->cpu_index); cpu_resume(cpu); flag = 1; break; @@ -538,12 +530,49 @@ static void hextomem(uint8_t *mem, const char *buf, int len) } } +static void hexdump(const char *buf, int len, + void (*trace_fn)(size_t ofs, char const *text)) +{ + char line_buffer[3 * 16 + 4 + 16 + 1]; + + size_t i; + for (i = 0; i < len || (i & 0xF); ++i) { + size_t byte_ofs = i & 15; + + if (byte_ofs == 0) { + memset(line_buffer, ' ', 3 * 16 + 4 + 16); + line_buffer[3 * 16 + 4 + 16] = 0; + } + + size_t col_group = (i >> 2) & 3; + size_t hex_col = byte_ofs * 3 + col_group; + size_t txt_col = 3 * 16 + 4 + byte_ofs; + + if (i < len) { + char value = buf[i]; + + line_buffer[hex_col + 0] = tohex((value >> 4) & 0xF); + line_buffer[hex_col + 1] = tohex((value >> 0) & 0xF); + line_buffer[txt_col + 0] = (value >= ' ' && value < 127) + ? value + : '.'; + } + + if (byte_ofs == 0xF) + trace_fn(i & -16, line_buffer); + } +} + /* return -1 if error, 0 if OK */ -static int put_packet_binary(GDBState *s, const char *buf, int len) +static int put_packet_binary(GDBState *s, const char *buf, int len, bool dump) { int csum, i; uint8_t *p; + if (dump && trace_event_get_state_backends(TRACE_GDBSTUB_IO_BINARYREPLY)) { + hexdump(buf, len, trace_gdbstub_io_binaryreply); + } + for(;;) { p = s->last_packet; *(p++) = '$'; @@ -576,9 +605,9 @@ static int put_packet_binary(GDBState *s, const char *buf, int len) /* return -1 if error, 0 if OK */ static int put_packet(GDBState *s, const char *buf) { - gdb_debug("reply='%s'\n", buf); + trace_gdbstub_io_reply(buf); - return put_packet_binary(s, buf, strlen(buf)); + return put_packet_binary(s, buf, strlen(buf), false); } /* Encode data using the encoding for 'x' packets. */ @@ -975,8 +1004,7 @@ static int gdb_handle_packet(GDBState *s, const char *line_buf) uint8_t *registers; target_ulong addr, len; - - gdb_debug("command='%s'\n", line_buf); + trace_gdbstub_io_command(line_buf); p = line_buf; ch = *p++; @@ -999,7 +1027,7 @@ static int gdb_handle_packet(GDBState *s, const char *line_buf) } s->signal = 0; gdb_continue(s); - return RS_IDLE; + return RS_IDLE; case 'C': s->signal = gdb_signal_to_target (strtoul(p, (char **)&p, 16)); if (s->signal == -1) @@ -1045,7 +1073,7 @@ static int gdb_handle_packet(GDBState *s, const char *line_buf) } cpu_single_step(s->c_cpu, sstep_flags); gdb_continue(s); - return RS_IDLE; + return RS_IDLE; case 'F': { target_ulong ret; @@ -1267,6 +1295,7 @@ static int gdb_handle_packet(GDBState *s, const char *line_buf) len = snprintf((char *)mem_buf, sizeof(buf) / 2, "CPU#%d [%s]", cpu->cpu_index, cpu->halted ? "halted " : "running"); + trace_gdbstub_op_extra_info((char *)mem_buf); memtohex(buf, mem_buf, len); put_packet(s, buf); } @@ -1350,7 +1379,7 @@ static int gdb_handle_packet(GDBState *s, const char *line_buf) buf[0] = 'l'; len = memtox(buf + 1, xml + addr, total_len - addr); } - put_packet_binary(s, buf, len + 1); + put_packet_binary(s, buf, len + 1, true); break; } if (is_query_packet(p, "Attached", ':')) { @@ -1407,29 +1436,38 @@ static void gdb_vm_state_change(void *opaque, int running, RunState state) type = ""; break; } + trace_gdbstub_hit_watchpoint(type, cpu_gdb_index(cpu), + (target_ulong)cpu->watchpoint_hit->vaddr); snprintf(buf, sizeof(buf), "T%02xthread:%02x;%swatch:" TARGET_FMT_lx ";", GDB_SIGNAL_TRAP, cpu_gdb_index(cpu), type, (target_ulong)cpu->watchpoint_hit->vaddr); cpu->watchpoint_hit = NULL; goto send_packet; + } else { + trace_gdbstub_hit_break(); } tb_flush(cpu); ret = GDB_SIGNAL_TRAP; break; case RUN_STATE_PAUSED: + trace_gdbstub_hit_paused(); ret = GDB_SIGNAL_INT; break; case RUN_STATE_SHUTDOWN: + trace_gdbstub_hit_shutdown(); ret = GDB_SIGNAL_QUIT; break; case RUN_STATE_IO_ERROR: + trace_gdbstub_hit_io_error(); ret = GDB_SIGNAL_IO; break; case RUN_STATE_WATCHDOG: + trace_gdbstub_hit_watchdog(); ret = GDB_SIGNAL_ALRM; break; case RUN_STATE_INTERNAL_ERROR: + trace_gdbstub_hit_internal_error(); ret = GDB_SIGNAL_ABRT; break; case RUN_STATE_SAVE_VM: @@ -1439,6 +1477,7 @@ static void gdb_vm_state_change(void *opaque, int running, RunState state) ret = GDB_SIGNAL_XCPU; break; default: + trace_gdbstub_hit_unknown(state); ret = GDB_SIGNAL_UNKNOWN; break; } @@ -1538,12 +1577,12 @@ static void gdb_read_byte(GDBState *s, int ch) /* Waiting for a response to the last packet. If we see the start of a new command then abandon the previous response. */ if (ch == '-') { - gdb_debug("Got NACK, retransmitting\n"); + trace_gdbstub_err_got_nack(); put_buffer(s, (uint8_t *)s->last_packet, s->last_packet_len); } else if (ch == '+') { - gdb_debug("Got ACK\n"); + trace_gdbstub_io_got_ack(); } else { - gdb_debug("Got '%c' when expecting ACK/NACK\n", ch); + trace_gdbstub_io_got_unexpected((uint8_t)ch); } if (ch == '+' || ch == '$') @@ -1566,7 +1605,7 @@ static void gdb_read_byte(GDBState *s, int ch) s->line_sum = 0; s->state = RS_GETLINE; } else { - gdb_debug("received garbage between packets: 0x%x\n", ch); + trace_gdbstub_err_garbage((uint8_t)ch); } break; case RS_GETLINE: @@ -1582,7 +1621,7 @@ static void gdb_read_byte(GDBState *s, int ch) /* end of command, start of checksum*/ s->state = RS_CHKSUM1; } else if (s->line_buf_index >= sizeof(s->line_buf) - 1) { - gdb_debug("command buffer overrun, dropping command\n"); + trace_gdbstub_err_overrun(); s->state = RS_IDLE; } else { /* unescaped command character */ @@ -1596,7 +1635,7 @@ static void gdb_read_byte(GDBState *s, int ch) s->state = RS_CHKSUM1; } else if (s->line_buf_index >= sizeof(s->line_buf) - 1) { /* command buffer overrun */ - gdb_debug("command buffer overrun, dropping command\n"); + trace_gdbstub_err_overrun(); s->state = RS_IDLE; } else { /* parse escaped character and leave escape state */ @@ -1608,18 +1647,18 @@ static void gdb_read_byte(GDBState *s, int ch) case RS_GETLINE_RLE: if (ch < ' ') { /* invalid RLE count encoding */ - gdb_debug("got invalid RLE count: 0x%x\n", ch); + trace_gdbstub_err_invalid_repeat((uint8_t)ch); s->state = RS_GETLINE; } else { /* decode repeat length */ int repeat = (unsigned char)ch - ' ' + 3; if (s->line_buf_index + repeat >= sizeof(s->line_buf) - 1) { /* that many repeats would overrun the command buffer */ - gdb_debug("command buffer overrun, dropping command\n"); + trace_gdbstub_err_overrun(); s->state = RS_IDLE; } else if (s->line_buf_index < 1) { /* got a repeat but we have nothing to repeat */ - gdb_debug("got invalid RLE sequence\n"); + trace_gdbstub_err_invalid_rle(); s->state = RS_GETLINE; } else { /* repeat the last character */ @@ -1634,7 +1673,7 @@ static void gdb_read_byte(GDBState *s, int ch) case RS_CHKSUM1: /* get high hex digit of checksum */ if (!isxdigit(ch)) { - gdb_debug("got invalid command checksum digit\n"); + trace_gdbstub_err_checksum_invalid((uint8_t)ch); s->state = RS_GETLINE; break; } @@ -1645,14 +1684,14 @@ static void gdb_read_byte(GDBState *s, int ch) case RS_CHKSUM2: /* get low hex digit of checksum */ if (!isxdigit(ch)) { - gdb_debug("got invalid command checksum digit\n"); + trace_gdbstub_err_checksum_invalid((uint8_t)ch); s->state = RS_GETLINE; break; } s->line_csum |= fromhex(ch); if (s->line_csum != (s->line_sum & 0xff)) { - gdb_debug("got command packet with incorrect checksum\n"); + trace_gdbstub_err_checksum_incorrect(s->line_sum, s->line_csum); /* send NAK reply */ reply = '-'; put_buffer(s, &reply, 1); @@ -1686,6 +1725,8 @@ void gdb_exit(CPUArchState *env, int code) } #endif + trace_gdbstub_op_exiting((uint8_t)code); + snprintf(buf, sizeof(buf), "W%02x", (uint8_t)code); put_packet(s, buf); @@ -1944,6 +1985,8 @@ static const TypeInfo char_gdb_type_info = { int gdbserver_start(const char *device) { + trace_gdbstub_op_start(device); + GDBState *s; char gdbstub_device_name[128]; Chardev *chr = NULL; diff --git a/trace-events b/trace-events index 1d2eb5d3e4..3695959d0a 100644 --- a/trace-events +++ b/trace-events @@ -68,6 +68,34 @@ flatview_new(FlatView *view, MemoryRegion *root) "%p (root %p)" flatview_destroy(FlatView *view, MemoryRegion *root) "%p (root %p)" flatview_destroy_rcu(FlatView *view, MemoryRegion *root) "%p (root %p)" +# gdbstub.c +gdbstub_op_start(char const *device) "Starting gdbstub using device %s" +gdbstub_op_exiting(uint8_t code) "notifying exit with code=0x%02x" +gdbstub_op_continue(void) "Continuing all CPUs" +gdbstub_op_continue_cpu(int cpu_index) "Continuing CPU %d" +gdbstub_op_stepping(int cpu_index) "Stepping CPU %d" +gdbstub_op_extra_info(char const *info) "Thread extra info: %s" +gdbstub_hit_watchpoint(char const *type, int cpu_gdb_index, uint64_t vaddr) "Watchpoint hit, type=\"%s\" cpu=%d, vaddr=0x%" PRIx64 "" +gdbstub_hit_internal_error(void) "RUN_STATE_INTERNAL_ERROR" +gdbstub_hit_break(void) "RUN_STATE_DEBUG" +gdbstub_hit_paused(void) "RUN_STATE_PAUSED" +gdbstub_hit_shutdown(void) "RUN_STATE_SHUTDOWN" +gdbstub_hit_io_error(void) "RUN_STATE_IO_ERROR" +gdbstub_hit_watchdog(void) "RUN_STATE_WATCHDOG" +gdbstub_hit_unknown(int state) "Unknown run state=0x%x" +gdbstub_io_reply(char const *message) "Sent: %s" +gdbstub_io_binaryreply(size_t ofs, char const *line) "0x%04zx: %s" +gdbstub_io_command(char const *command) "Received: %s" +gdbstub_io_got_ack(void) "Got ACK" +gdbstub_io_got_unexpected(uint8_t ch) "Got 0x%02x when expecting ACK/NACK" +gdbstub_err_got_nack(void) "Got NACK, retransmitting" +gdbstub_err_garbage(uint8_t ch) "received garbage between packets: 0x%02x" +gdbstub_err_overrun(void) "command buffer overrun, dropping command" +gdbstub_err_invalid_repeat(uint8_t ch) "got invalid RLE count: 0x%02x" +gdbstub_err_invalid_rle(void) "got invalid RLE sequence" +gdbstub_err_checksum_invalid(uint8_t ch) "got invalid command checksum digit: 0x%02x" +gdbstub_err_checksum_incorrect(uint8_t expected, uint8_t got) "got command packet with incorrect checksum, expected=0x%02x, received=0x%02x" + ### Guest events, keep at bottom