365 lines
11 KiB
C
365 lines
11 KiB
C
/*
|
|
* trace_parser.c - Parse QEMU simpletrace binary files.
|
|
*
|
|
* Format reference: QEMU scripts/simpletrace.py (log format version 4).
|
|
* All multi-byte fields are little-endian (native on x86_64).
|
|
*/
|
|
|
|
#include "trace_parser.h"
|
|
#include "simpletrace.h"
|
|
|
|
#include <stdio.h>
|
|
#include <stdlib.h>
|
|
#include <string.h>
|
|
#include <inttypes.h>
|
|
|
|
#define MAX_EVENTS_IN_LIST 1000000
|
|
|
|
static const char *known_event_names[] = {
|
|
"serial_read",
|
|
"serial_write",
|
|
"ide_sector_read",
|
|
"cd_read_sector",
|
|
"cd_read_sector_sync",
|
|
"blk_co_preadv",
|
|
"virtio_blk_handle_read",
|
|
"cpu_in",
|
|
"cpu_out",
|
|
"pci_cfg_read",
|
|
"pci_cfg_write",
|
|
"ide_ioport_read",
|
|
"ide_ioport_write",
|
|
"memory_region_ops_read",
|
|
"memory_region_ops_write",
|
|
NULL
|
|
};
|
|
|
|
static int is_disk_read(const char *name)
|
|
{
|
|
return strcmp(name, "ide_sector_read") == 0 ||
|
|
strcmp(name, "cd_read_sector") == 0 ||
|
|
strcmp(name, "cd_read_sector_sync") == 0 ||
|
|
strcmp(name, "blk_co_preadv") == 0 ||
|
|
strcmp(name, "virtio_blk_handle_read") == 0;
|
|
}
|
|
|
|
static int is_disk_write(const char *name)
|
|
{
|
|
return strcmp(name, "blk_co_pwritev") == 0 ||
|
|
strcmp(name, "virtio_blk_handle_write") == 0 ||
|
|
strcmp(name, "ide_sector_write") == 0;
|
|
}
|
|
|
|
static int read_u64(FILE *f, uint64_t *val)
|
|
{
|
|
uint8_t b[8];
|
|
if (fread(b, 1, 8, f) != 8)
|
|
return -1;
|
|
*val = (uint64_t)b[0]
|
|
| ((uint64_t)b[1] << 8)
|
|
| ((uint64_t)b[2] << 16)
|
|
| ((uint64_t)b[3] << 24)
|
|
| ((uint64_t)b[4] << 32)
|
|
| ((uint64_t)b[5] << 40)
|
|
| ((uint64_t)b[6] << 48)
|
|
| ((uint64_t)b[7] << 56);
|
|
return 0;
|
|
}
|
|
|
|
static int read_u32(FILE *f, uint32_t *val)
|
|
{
|
|
uint8_t b[4];
|
|
if (fread(b, 1, 4, f) != 4)
|
|
return -1;
|
|
*val = (uint32_t)b[0]
|
|
| ((uint32_t)b[1] << 8)
|
|
| ((uint32_t)b[2] << 16)
|
|
| ((uint32_t)b[3] << 24);
|
|
return 0;
|
|
}
|
|
|
|
static void init_known_names(trace_summary_t *summary)
|
|
{
|
|
for (int i = 0; known_event_names[i] != NULL && i < TRACE_MAX_EVENT_ID; i++) {
|
|
size_t len = strlen(known_event_names[i]);
|
|
if (len >= 64)
|
|
len = 63;
|
|
memcpy(summary->event_names[i], known_event_names[i], len);
|
|
summary->event_names[i][len] = '\0';
|
|
}
|
|
}
|
|
|
|
static void resolve_name(trace_summary_t *summary, trace_event_t *ev)
|
|
{
|
|
if (ev->event_id < TRACE_MAX_EVENT_ID && summary->event_names[ev->event_id][0]) {
|
|
strncpy(ev->name, summary->event_names[ev->event_id], 63);
|
|
ev->name[63] = '\0';
|
|
} else {
|
|
snprintf(ev->name, sizeof(ev->name), "event_%" PRIu64, ev->event_id);
|
|
}
|
|
}
|
|
|
|
static void update_stats(trace_summary_t *summary, const trace_event_t *ev)
|
|
{
|
|
summary->total_events++;
|
|
if (ev->event_id < TRACE_MAX_EVENT_ID)
|
|
summary->events_by_id[ev->event_id]++;
|
|
|
|
if (summary->first_timestamp == 0 || ev->timestamp_ns < summary->first_timestamp)
|
|
summary->first_timestamp = ev->timestamp_ns;
|
|
if (ev->timestamp_ns > summary->last_timestamp)
|
|
summary->last_timestamp = ev->timestamp_ns;
|
|
|
|
if (is_disk_read(ev->name))
|
|
summary->total_disk_reads++;
|
|
else if (is_disk_write(ev->name))
|
|
summary->total_disk_writes++;
|
|
if (strcmp(ev->name, "serial_write") == 0)
|
|
summary->total_serial_writes++;
|
|
}
|
|
|
|
static void handle_mapping(FILE *f, trace_summary_t *summary)
|
|
{
|
|
uint64_t event_id;
|
|
uint32_t name_len;
|
|
|
|
if (read_u64(f, &event_id) != 0)
|
|
return;
|
|
if (read_u32(f, &name_len) != 0)
|
|
return;
|
|
|
|
if (name_len == 0 || name_len > 4096) {
|
|
if (name_len > 0)
|
|
fseek(f, (long)name_len, SEEK_CUR);
|
|
return;
|
|
}
|
|
|
|
char namebuf[64];
|
|
size_t copylen = name_len < 63 ? name_len : 63;
|
|
|
|
if (copylen <= sizeof(namebuf) - 1) {
|
|
if (fread(namebuf, 1, copylen, f) != copylen)
|
|
return;
|
|
namebuf[copylen] = '\0';
|
|
|
|
if (event_id < TRACE_MAX_EVENT_ID) {
|
|
memcpy(summary->event_names[event_id], namebuf, copylen + 1);
|
|
}
|
|
|
|
if (name_len > copylen) {
|
|
if (fseek(f, (long)(name_len - copylen), SEEK_CUR) != 0)
|
|
return;
|
|
}
|
|
} else {
|
|
if (fseek(f, (long)name_len, SEEK_CUR) != 0)
|
|
return;
|
|
}
|
|
}
|
|
|
|
static int handle_event(FILE *f, trace_summary_t *summary, trace_event_t **tail)
|
|
{
|
|
uint64_t event_id, timestamp_ns;
|
|
uint32_t record_length, record_pid;
|
|
|
|
if (read_u64(f, &event_id) != 0) return -1;
|
|
if (read_u64(f, ×tamp_ns) != 0) return -1;
|
|
if (read_u32(f, &record_length) != 0) return -1;
|
|
if (read_u32(f, &record_pid) != 0) return -1;
|
|
|
|
uint32_t args_len = 0;
|
|
if (record_length >= TRACE_REC_HEADER_LEN)
|
|
args_len = record_length - TRACE_REC_HEADER_LEN;
|
|
|
|
uint8_t *args = NULL;
|
|
if (args_len > 0) {
|
|
args = malloc(args_len);
|
|
if (!args)
|
|
return -1;
|
|
if (fread(args, 1, args_len, f) != args_len) {
|
|
free(args);
|
|
return -1;
|
|
}
|
|
}
|
|
|
|
trace_event_t *ev = calloc(1, sizeof(trace_event_t));
|
|
if (!ev) {
|
|
free(args);
|
|
return -1;
|
|
}
|
|
|
|
ev->event_id = event_id;
|
|
ev->timestamp_ns = timestamp_ns;
|
|
ev->pid = record_pid;
|
|
ev->args_len = args_len;
|
|
ev->args = args;
|
|
|
|
resolve_name(summary, ev);
|
|
update_stats(summary, ev);
|
|
|
|
if (!summary->events)
|
|
summary->events = ev;
|
|
else
|
|
(*tail)->next = ev;
|
|
*tail = ev;
|
|
summary->event_count++;
|
|
|
|
return 0;
|
|
}
|
|
|
|
int trace_parse_file(const char *path, trace_summary_t *summary)
|
|
{
|
|
if (!path || !summary)
|
|
return -1;
|
|
|
|
FILE *f = fopen(path, "rb");
|
|
if (!f)
|
|
return -1;
|
|
|
|
memset(summary, 0, sizeof(*summary));
|
|
init_known_names(summary);
|
|
|
|
uint64_t hdr_event_id, hdr_magic, hdr_version;
|
|
if (read_u64(f, &hdr_event_id) != 0 ||
|
|
read_u64(f, &hdr_magic) != 0 ||
|
|
read_u64(f, &hdr_version) != 0) {
|
|
fclose(f);
|
|
return -1;
|
|
}
|
|
|
|
if (hdr_event_id != TRACE_HEADER_EVENT_ID ||
|
|
hdr_magic != TRACE_HEADER_MAGIC) {
|
|
fclose(f);
|
|
return -1;
|
|
}
|
|
|
|
trace_event_t *tail = NULL;
|
|
|
|
for (;;) {
|
|
if (summary->event_count >= MAX_EVENTS_IN_LIST) {
|
|
uint64_t rectype;
|
|
while (read_u64(f, &rectype) == 0) {
|
|
if (rectype == TRACE_RECORD_TYPE_MAPPING) {
|
|
handle_mapping(f, summary);
|
|
} else {
|
|
uint64_t event_id, timestamp_ns;
|
|
uint32_t record_length, record_pid;
|
|
if (read_u64(f, &event_id) != 0) break;
|
|
if (read_u64(f, ×tamp_ns) != 0) break;
|
|
if (read_u32(f, &record_length) != 0) break;
|
|
if (read_u32(f, &record_pid) != 0) break;
|
|
summary->total_events++;
|
|
if (event_id < TRACE_MAX_EVENT_ID)
|
|
summary->events_by_id[event_id]++;
|
|
if (timestamp_ns > summary->last_timestamp)
|
|
summary->last_timestamp = timestamp_ns;
|
|
uint32_t al = 0;
|
|
if (record_length >= TRACE_REC_HEADER_LEN)
|
|
al = record_length - TRACE_REC_HEADER_LEN;
|
|
if (al > 0)
|
|
fseek(f, (long)al, SEEK_CUR);
|
|
}
|
|
}
|
|
break;
|
|
}
|
|
|
|
uint64_t rectype;
|
|
if (read_u64(f, &rectype) != 0)
|
|
break;
|
|
|
|
if (rectype == TRACE_RECORD_TYPE_MAPPING) {
|
|
handle_mapping(f, summary);
|
|
} else if (rectype == TRACE_RECORD_TYPE_EVENT) {
|
|
if (handle_event(f, summary, &tail) != 0)
|
|
break;
|
|
} else {
|
|
break;
|
|
}
|
|
}
|
|
|
|
fclose(f);
|
|
return 0;
|
|
}
|
|
|
|
void trace_free_summary(trace_summary_t *summary)
|
|
{
|
|
if (!summary)
|
|
return;
|
|
|
|
trace_event_t *ev = summary->events;
|
|
while (ev) {
|
|
trace_event_t *next = ev->next;
|
|
free(ev->args);
|
|
free(ev);
|
|
ev = next;
|
|
}
|
|
summary->events = NULL;
|
|
summary->event_count = 0;
|
|
}
|
|
|
|
void trace_print_text(const trace_summary_t *summary, FILE *out)
|
|
{
|
|
fprintf(out, "=== Trace Summary ===\n");
|
|
fprintf(out, "Total events: %" PRIu64 "\n", summary->total_events);
|
|
fprintf(out, "Events in list: %zu\n", summary->event_count);
|
|
fprintf(out, "First timestamp: %" PRIu64 " ns\n", summary->first_timestamp);
|
|
fprintf(out, "Last timestamp: %" PRIu64 " ns\n", summary->last_timestamp);
|
|
|
|
if (summary->last_timestamp > summary->first_timestamp) {
|
|
double dur_ms = (double)(summary->last_timestamp - summary->first_timestamp) / 1000000.0;
|
|
fprintf(out, "Duration: %.3f ms\n", dur_ms);
|
|
}
|
|
|
|
fprintf(out, "\nI/O Counts:\n");
|
|
fprintf(out, " Disk reads: %" PRIu64 "\n", summary->total_disk_reads);
|
|
fprintf(out, " Disk writes: %" PRIu64 "\n", summary->total_disk_writes);
|
|
fprintf(out, " Serial writes: %" PRIu64 "\n", summary->total_serial_writes);
|
|
|
|
fprintf(out, "\n--- Events by ID ---\n");
|
|
for (int i = 0; i < TRACE_MAX_EVENT_ID; i++) {
|
|
if (summary->events_by_id[i] > 0) {
|
|
const char *nm = summary->event_names[i][0]
|
|
? summary->event_names[i] : "(unknown)";
|
|
fprintf(out, " [%3d] %-40s %" PRIu64 "\n", i, nm, summary->events_by_id[i]);
|
|
}
|
|
}
|
|
}
|
|
|
|
void trace_print_json(const trace_summary_t *summary, FILE *out)
|
|
{
|
|
fprintf(out, "{\n");
|
|
fprintf(out, " \"total_events\": %" PRIu64 ",\n", summary->total_events);
|
|
fprintf(out, " \"event_count\": %zu,\n", summary->event_count);
|
|
fprintf(out, " \"first_timestamp_ns\": %" PRIu64 ",\n", summary->first_timestamp);
|
|
fprintf(out, " \"last_timestamp_ns\": %" PRIu64 ",\n", summary->last_timestamp);
|
|
fprintf(out, " \"disk_reads\": %" PRIu64 ",\n", summary->total_disk_reads);
|
|
fprintf(out, " \"disk_writes\": %" PRIu64 ",\n", summary->total_disk_writes);
|
|
fprintf(out, " \"serial_writes\": %" PRIu64 ",\n", summary->total_serial_writes);
|
|
|
|
fprintf(out, " \"events\": [");
|
|
int first = 1;
|
|
for (int i = 0; i < TRACE_MAX_EVENT_ID; i++) {
|
|
if (summary->events_by_id[i] > 0) {
|
|
const char *nm = summary->event_names[i][0]
|
|
? summary->event_names[i] : "unknown";
|
|
fprintf(out, "%s\n {\"id\": %d, \"name\": \"%s\", \"count\": %" PRIu64 "}",
|
|
first ? "" : ",", i, nm, summary->events_by_id[i]);
|
|
first = 0;
|
|
}
|
|
}
|
|
fprintf(out, first ? "]\n" : "\n ]\n");
|
|
|
|
fprintf(out, "}\n");
|
|
}
|
|
|
|
void trace_print_csv(const trace_summary_t *summary, FILE *out)
|
|
{
|
|
fprintf(out, "event_id,event_name,count\n");
|
|
for (int i = 0; i < TRACE_MAX_EVENT_ID; i++) {
|
|
if (summary->events_by_id[i] > 0) {
|
|
const char *nm = summary->event_names[i][0]
|
|
? summary->event_names[i] : "unknown";
|
|
fprintf(out, "%d,%s,%" PRIu64 "\n", i, nm, summary->events_by_id[i]);
|
|
}
|
|
}
|
|
}
|