/*
* Copyright (c) 2018 Google, Inc.
*
* SPDX-License-Identifier: GPL-2.0-or-later
*/
#define _GNU_SOURCE
#include <fcntl.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <unistd.h>
#include <errno.h>
#include <stdlib.h>
#include <stdio.h>
#include <string.h>
#include "tst_res_flags.h"
#include "tst_safe_file_ops.h"
#include "tst_safe_macros.h"
#include "trace_parse.h"
int num_trace_records = 0;
struct trace_record *trace = NULL;
static int trace_fd = -1;
static char *trace_buffer = NULL;
static int parse_event_type(char *event_name)
{
if (!strcmp(event_name, "sched_process_exit"))
return TRACE_RECORD_SCHED_PROCESS_EXIT;
if (!strcmp(event_name, "sched_process_fork"))
return TRACE_RECORD_SCHED_PROCESS_FORK;
if (!strcmp(event_name, "sched_switch"))
return TRACE_RECORD_SCHED_SWITCH;
if (!strcmp(event_name, "sched_wakeup"))
return TRACE_RECORD_SCHED_WAKEUP;
if (!strcmp(event_name, "sugov_util_update"))
return TRACE_RECORD_SUGOV_UTIL_UPDATE;
if (!strcmp(event_name, "sugov_next_freq"))
return TRACE_RECORD_SUGOV_NEXT_FREQ;
if (!strcmp(event_name, "cpu_frequency"))
return TRACE_RECORD_CPU_FREQUENCY;
if (!strcmp(event_name, "tracing_mark_write"))
return TRACE_RECORD_TRACING_MARK_WRITE;
return -1;
}
void print_trace_record(struct trace_record *tr)
{
printf("task: %s pid %d cpu %d flags %d irq_context %c preempt_depth %d timestamp %d.%.6d event_type %d ",
tr->task, tr->pid, tr->cpu, tr->flags, tr->irq_context,
tr->preempt_depth, tr->ts.sec, tr->ts.usec,
tr->event_type);
if (tr->event_type == TRACE_RECORD_SCHED_PROCESS_EXIT)
printf("(sched_process_exit)\n");
else if (tr->event_type == TRACE_RECORD_SCHED_PROCESS_FORK)
printf("(sched_process_fork)\n");
else if (tr->event_type == TRACE_RECORD_SCHED_SWITCH) {
struct trace_sched_switch *t = tr->event_data;
printf("(sched_switch) %s pid=%d prio=%d state=%c => "
"%s pid=%d prio=%d\n", t->prev_comm, t->prev_pid,
t->prev_prio, t->prev_state, t->next_comm, t->next_pid,
t->next_prio);
} else if (tr->event_type == TRACE_RECORD_SCHED_WAKEUP) {
struct trace_sched_wakeup *t = tr->event_data;
printf("(sched_wakeup) %s pid=%d prio=%d cpu=%d\n",
t->comm, t->pid, t->prio, t->cpu);
} else if (tr->event_type == TRACE_RECORD_SUGOV_UTIL_UPDATE) {
struct trace_sugov_util_update *t = tr->event_data;
printf("(sugov_util_update) cpu=%d util=%d avg_cap=%d "
"max_cap=%d\n", t->cpu, t->util, t->avg_cap,
t->max_cap);
} else if (tr->event_type == TRACE_RECORD_SUGOV_NEXT_FREQ) {
struct trace_sugov_next_freq *t = tr->event_data;
printf("(sugov_next_freq) cpu=%d util=%d max=%d freq=%d\n",
t->cpu, t->util, t->max, t->freq);
} else if (tr->event_type == TRACE_RECORD_CPU_FREQUENCY) {
struct trace_cpu_frequency *t = tr->event_data;
printf("(cpu_frequency) state=%d cpu=%d\n",
t->state, t->cpu);
} else if (tr->event_type == TRACE_RECORD_TRACING_MARK_WRITE)
printf("(tracing_mark_write)\n");
else
printf("(other)\n");
}
void trace_cleanup(void)
{
SAFE_FILE_PRINTF(TRACING_DIR "tracing_on", "0");
}
static void *parse_event_data(unsigned int event_type, char *data)
{
if (event_type == TRACE_RECORD_TRACING_MARK_WRITE) {
char *buf = SAFE_MALLOC(strlen(data) + 1);
strcpy(buf, data);
return buf;
}
if (event_type == TRACE_RECORD_CPU_FREQUENCY) {
struct trace_cpu_frequency *t;
t = SAFE_MALLOC(sizeof(struct trace_cpu_frequency));
if (sscanf(data, "state=%d cpu_id=%hd", &t->state, &t->cpu)
!= 2) {
printf("Error parsing cpu_frequency event:\n%s\n",
data);
free(t);
return NULL;
}
return t;
}
if (event_type == TRACE_RECORD_SUGOV_UTIL_UPDATE) {
struct trace_sugov_util_update *t;
t = SAFE_MALLOC(sizeof(struct trace_sugov_util_update));
if (sscanf(data, "cpu=%d util=%d avg_cap=%d max_cap=%d",
&t->cpu, &t->util, &t->avg_cap, &t->max_cap) != 4) {
printf("Error parsing sugov_util_update event:\n%s\n",
data);
free(t);
return NULL;
}
return t;
}
if (event_type == TRACE_RECORD_SUGOV_NEXT_FREQ) {
struct trace_sugov_next_freq *t;
t = SAFE_MALLOC(sizeof(struct trace_sugov_next_freq));
if (sscanf(data, "cpu=%d util=%d max=%d freq=%d",
&t->cpu, &t->util, &t->max, &t->freq) != 4) {
printf("Error parsing sugov_next_freq event:\n%s\n",
data);
free(t);
return NULL;
}
return t;
}
if (event_type == TRACE_RECORD_SCHED_SWITCH) {
struct trace_sched_switch *t;
char *tmp, *tmp2;
t = SAFE_MALLOC(sizeof(struct trace_sched_switch));
/*
* The prev_comm could have spaces in it. Find start of
* "prev_pid=" as that is just after end of prev_comm.
*/
if (strstr(data, "prev_comm=") != data) {
printf("Malformatted sched_switch event:\n%s\n",
data);
free(t);
return NULL;
}
tmp = strstr(data, " prev_pid=");
if (!tmp) {
printf("Malformatted sched_switch event, "
"no prev_pid:\n%s\n", data);
free(t);
return NULL;
}
*tmp = 0;
snprintf(t->prev_comm, sizeof(t->prev_comm), "%s", data + 10);
*tmp = ' ';
tmp++;
if (sscanf(tmp, "prev_pid=%hd prev_prio=%hd "
"prev_state=%c ==>\n",
&t->prev_pid, &t->prev_prio, &t->prev_state) != 3) {
printf("Malformatted sched_switch event:\n%s\n",
data);
free(t);
return NULL;
}
tmp = strstr(tmp, "==> next_comm=");
if (!tmp) {
printf("Malformatted sched_switch event:\n%s\n",
data);
free(t);
return NULL;
}
tmp += 14;
tmp2 = strstr(tmp, " next_pid=");
if (!tmp2) {
printf("Malformatted sched_switch event:\n%s\n",
data);
free(t);
return NULL;
}
*tmp2 = 0;
if (strlen(tmp) > 16) {
printf("next_comm %s is greater than 16!\n",
tmp);
t->next_comm[0] = 0;
}
snprintf(t->next_comm, sizeof(t->next_comm), "%s", tmp);
*tmp2 = ' ';
tmp2++;
if (sscanf(tmp2, "next_pid=%hd next_prio=%hd", &t->next_pid,
&t->next_prio) != 2) {
printf("Malformatted sched_switch event:\n%s\n",
data);
free(t);
return NULL;
}
return t;
}
if (event_type == TRACE_RECORD_SCHED_WAKEUP) {
struct trace_sched_wakeup *t;
char *tmp;
t = SAFE_MALLOC(sizeof(struct trace_sched_wakeup));
tmp = strstr(data, " pid=");
if (!tmp) {
printf("Malformatted sched_wakeup event:\n%s\n", data);
free(t);
return NULL;
}
*tmp = 0;
snprintf(t->comm, sizeof(t->comm), "%s", data + 5);
*tmp = ' ';
if (sscanf(tmp, " pid=%hd prio=%hd target_cpu=%hd", &t->pid,
&t->prio, &t->cpu) != 3) {
printf("Malformatted sched_wakeup event:\n%s\n", data);
free(t);
return NULL;
}
return t;
}
return NULL;
}
/*
* Given a line of text from a trace containing a trace record, parse the trace
* record into a struct trace_record.
* First 16 chars are the currently running thread name. Drop leading spaces.
* Next char is a dash
* Next 5 chars are PID. Drop trailing spaces.
* Next char is a space.
* Next five chars are the CPU, i.e. [001].
* Next char is a space.
* Next letter is whether IRQs are off.
* Next letter is if NEED_RESCHED is set.
* Next letter is if this is in hard or soft IRQ context.
* Next letter is the preempt disable depth.
* Next char is a space.
* Next twelve letters are the timestamp. Drop leading spaces.
* Next char is colon.
* Next char is space.
* Next twelve letters are the event name.
* Next char is colon.
* Rest of line is string specific to event.
*/
static int parse_trace_record(struct trace_record *tr, char *line) {
unsigned int idx = 0;
char *found;
/* Skip leading spaces in the task name. */
while (idx < 16 && line[idx] == ' ')
idx++;
if (idx == 16) {
printf("Malformatted trace record, no task name:\n");
printf("%s", line);
return -1;
}
memcpy(tr->task, &line[idx], 16-idx);
if (line[16] != '-') {
printf("Malformatted trace record, no dash after task "
"name:\n");
printf("%s", line);
return -1;
}
idx = 17;
if (line[22] != ' ') {
printf("Malformatted trace record, no space between"
"pid and CPU:\n");
printf("%s", line);
return -1;
}
line[22] = 0;
if (sscanf(&line[17], "%hd", &tr->pid) != 1) {
printf("Malformatted trace record, error parsing"
"pid:\n");
printf("%s", line);
return -1;
}
if (line[28] != ' ') {
printf("Malformatted trace record, no space between"
"CPU and flags:\n");
printf("%s", line);
return -1;
}
line[28] = 0;
if (sscanf(&line[23], "[%hd]", &tr->cpu) != 1) {
printf("Malformatted trace record, error parsing CPU:\n");
printf("%s", line);
return -1;
}
if (line[29] == 'd') {
tr->flags |= TRACE_RECORD_IRQS_OFF;
} else if (line[29] != '.') {
printf("Malformatted trace record, error parsing irqs-off:\n");
printf("%s", line);
return -1;
}
if (line[30] == 'N') {
tr->flags |= TRACE_RECORD_TIF_NEED_RESCHED;
tr->flags |= TRACE_RECORD_PREEMPT_NEED_RESCHED;
} else if (line[30] == 'n') {
tr->flags |= TRACE_RECORD_TIF_NEED_RESCHED;
} else if (line[30] == 'p') {
tr->flags |= TRACE_RECORD_PREEMPT_NEED_RESCHED;
} else if (line[30] != '.') {
printf("Malformatted trace record, error parsing "
"need-resched:\n");
printf("%s", line);
return -1;
}
if (line[31] != IRQ_CONTEXT_NORMAL && line[31] != IRQ_CONTEXT_SOFT &&
line[31] != IRQ_CONTEXT_HARD &&
line[31] != IRQ_CONTEXT_HARD_IN_SOFT &&
line[31] != IRQ_CONTEXT_NMI && line[31] != IRQ_CONTEXT_NMI_IN_HARD) {
printf("Malformatted trace record, error parsing irq "
"context:\n");
printf("%s", line);
return -1;
}
tr->irq_context = line[31];
if (line[33] != ' ') {
printf("Malformatted trace record, no space between"
"flags and timestamp:\n");
printf("%s", line);
return -1;
}
line[33] = 0;
if (line[32] == '.') {
tr->preempt_depth = 0;
} else if (sscanf(&line[32], "%hx", &tr->preempt_depth) != 1) {
printf("Malformatted trace record, error parsing "
"preempt-depth:\n");
printf("%s", line);
return -1;
}
/* timestamp starts as early as line[34], skip leading spaces */
idx = 34;
while (idx < 38 && line[idx] == ' ')
idx++;
if (sscanf(&line[idx], "%d.%d: ", &tr->ts.sec,
&tr->ts.usec) != 2) {
printf("Malformatted trace record, error parsing "
"timestamp:\n");
printf("%s", line);
return -1;
}
/* we know a space appears in the string because sscanf parsed it */
found = strchr(&line[idx], ' ');
idx = (found - line + 1);
found = strchr(&line[idx], ':');
if (!found) {
printf("Malformatted trace record, error parsing "
"event name:\n");
printf("%s", line);
return -1;
}
*found = 0;
tr->event_type = parse_event_type(&line[idx]);
/*
* there is a space between the ':' after the event name and the event
* data
*/
if (tr->event_type > 0)
tr->event_data = parse_event_data(tr->event_type, found + 2);
return 0;
}
#define TRACE_BUFFER_SIZE 8192
static int refill_buffer(char *buffer, char *idx)
{
int bytes_in_buffer;
int bytes_to_read;
int bytes_read = 0;
int rv;
bytes_in_buffer = TRACE_BUFFER_SIZE - (idx - buffer) - 1;
bytes_to_read = TRACE_BUFFER_SIZE - bytes_in_buffer - 1;
if (trace_fd == -1) {
trace_fd = open(TRACING_DIR "trace", O_RDONLY);
if (trace_fd == -1) {
printf("Could not open trace file!\n");
return 0;
}
}
/* Shift existing bytes in buffer to front. */
memmove(buffer, idx, bytes_in_buffer);
idx = buffer + bytes_in_buffer;
while(bytes_to_read) {
rv = read(trace_fd, idx, bytes_to_read);
if (rv == -1) {
printf("Could not read trace file! (%d)\n", errno);
return -1;
}
if (rv == 0)
break;
idx += rv;
bytes_read += rv;
bytes_to_read -= rv;
}
return bytes_read;
}
/*
* Returns a pointer to a null (not newline) terminated line
* of the trace.
*/
static char *read_trace_line(void)
{
static char *idx;
char *line, *newline;
int rv;
if (!trace_buffer) {
trace_buffer = SAFE_MALLOC(TRACE_BUFFER_SIZE);
idx = trace_buffer + TRACE_BUFFER_SIZE - 1;
*idx = 0;
}
line = idx;
newline = strchr(idx, '\n');
if (!newline) {
rv = refill_buffer(trace_buffer, idx);
if (rv == -1 || rv == 0)
return NULL;
idx = trace_buffer;
line = idx;
newline = strchr(idx, '\n');
}
if (newline) {
*newline = 0;
idx = newline + 1;
return line;
}
return NULL;
}
struct trace_record *load_trace(void)
{
int buflines, unused;
int tmp_num_trace_records = 0;
char *line;
enum parse_state_type {
PARSE_STATE_SEEK_NUM_ENTRIES = 0,
PARSE_STATE_REMAINING_COMMENTS,
PARSE_STATE_TRACE_ENTRIES,
};
int parse_state = PARSE_STATE_SEEK_NUM_ENTRIES;
num_trace_records = 0;
#ifdef PRINT_PARSING_UPDATES
printf("\n");
#endif
while((line = read_trace_line())) {
if (line[0] == '#') {
if (parse_state == PARSE_STATE_TRACE_ENTRIES) {
printf("Malformatted trace output, comment"
"after start of trace entries.\n");
if (trace)
free(trace);
return NULL;
}
if (parse_state == PARSE_STATE_REMAINING_COMMENTS)
continue;
if (sscanf(line,
"# entries-in-buffer/entries-written: "
"%d/%d",
&buflines, &unused) != 2) {
continue;
}
trace = SAFE_MALLOC(sizeof(struct trace_record) *
buflines);
parse_state = PARSE_STATE_REMAINING_COMMENTS;
} else {
if (parse_state == PARSE_STATE_SEEK_NUM_ENTRIES) {
printf("Malformatted trace output, non-comment "
"before number of entries.\n");
if (trace)
free(trace);
return NULL;
}
if (parse_state == PARSE_STATE_REMAINING_COMMENTS)
parse_state = PARSE_STATE_TRACE_ENTRIES;
if (parse_trace_record(&trace[tmp_num_trace_records++],
line)) {
printf("Malformatted trace record entry:\n");
printf("%s\n", line);
if (trace)
free(trace);
return NULL;
}
#ifdef PRINT_PARSING_UPDATES
if (tmp_num_trace_records%1000 == 0) {
printf("\r%d/%d records processed",
tmp_num_trace_records, buflines);
fflush(stdout);
}
#endif
}
}
#ifdef PRINT_PARSING_UPDATES
printf("\n");
#endif
num_trace_records = tmp_num_trace_records;
if (trace_fd >= 0) {
close(trace_fd);
trace_fd = -1;
}
if (trace_buffer) {
free(trace_buffer);
trace_buffer = NULL;
}
return trace;
}