X-Git-Url: http://rtime.felk.cvut.cz/gitweb/can-benchmark.git/blobdiff_plain/1e49f2400a836005448ef7a2ee29a9268a49098e..27c8ce5c4cd6ef751eb4c0914805aef74ce50f68:/latester/latester.c diff --git a/latester/latester.c b/latester/latester.c index f418567..a72558a 100644 --- a/latester/latester.c +++ b/latester/latester.c @@ -35,6 +35,8 @@ #include "histogram.h" +//#define FTRACE + #ifndef DEBUG #define dbg(level, fmt, arg...) do {} while (0) #else @@ -70,8 +72,14 @@ struct options opt = { .length = 2, }; +struct { + unsigned enobufs; + unsigned overrun; +} stats; + int num_interfaces = 0; int count = 0; /* Number of sent messages */ +unsigned msg_in_progress = 0; int completion_pipe[2]; struct msg_info { @@ -124,7 +132,7 @@ static inline struct msg_info *frame2info(struct can_frame *frame) if (idx >= MAX_INFOS) error(1, 0, "%s idx too high", __FUNCTION__); } else { - + error(1, 0, "%s error", __FUNCTION__); } return &msg_infos[idx]; @@ -230,9 +238,9 @@ static inline unsigned get_msg_latency_us(struct msg_info *mi) struct timespec diff; if (num_interfaces == 3) if (opt.userhist) - timespec_subtract(&diff, &mi->ts_rx_final_kern, &mi->ts_rx_onwire_kern); - else timespec_subtract(&diff, &mi->ts_rx_final, &mi->ts_rx_onwire); + else + timespec_subtract(&diff, &mi->ts_rx_final_kern, &mi->ts_rx_onwire_kern); else if (opt.userhist) timespec_subtract(&diff, &mi->ts_rx_final, &mi->ts_sent); @@ -278,6 +286,64 @@ static inline get_tstamp(struct timespec *ts) clock_gettime(CLOCK_REALTIME, ts); } + +int trace_fd = -1; +int marker_fd = -1; + +int init_ftrace() +{ +#ifdef FTRACE + char *debugfs; + char path[256]; + FILE *f; + + debugfs = "/sys/kernel/debug"; + if (debugfs) { + strcpy(path, debugfs); + strcat(path,"/tracing/tracing_on"); + trace_fd = open(path, O_WRONLY); + if (trace_fd >= 0) + write(trace_fd, "1", 1); + + strcpy(path, debugfs); + strcat(path,"/tracing/trace_marker"); + marker_fd = open(path, O_WRONLY); + + strcpy(path, debugfs); + strcat(path,"/tracing/set_ftrace_pid"); + f = fopen(path, "w"); + fprintf(f, "%d\n", getpid()); + fclose(f); + system("echo function_graph > /sys/kernel/debug/tracing/current_tracer"); + system("echo can_send > /sys/kernel/debug/tracing/set_graph_function"); + system("echo > /sys/kernel/debug/tracing/trace"); + system("echo 1 > /sys/kernel/debug/tracing/tracing_enabled"); + } +#endif /* FTRACE */ +} + +static inline void trace_on() +{ + if (trace_fd >= 0) + write(trace_fd, "1", 1); +} + +static inline void trace_off(int ret) +{ + if (marker_fd >= 0) { + char marker[100]; + sprintf(marker, "write returned %d\n", ret); + write(marker_fd, marker, strlen(marker)); + } + if (trace_fd >= 0) + write(trace_fd, "0", 1); +} + +void msg_info_free(struct msg_info *mi) +{ + mi->id = -1; +} + int send_frame(int socket) { struct can_frame frame; @@ -311,13 +377,30 @@ int send_frame(int socket) mi->length = frame.can_dlc; get_tstamp(&mi->ts_sent); mi->sent = frame; + + trace_on(); ret = write(socket, &frame, sizeof(frame)); + trace_off(ret); + + if (ret == -1) + msg_info_free(mi); return ret; } -void msg_info_free(struct msg_info *mi) +static inline send_and_check(int s) { - mi->id = -1; + int ret; + ret = send_frame(s); + if (ret != sizeof(struct can_frame)) { +/* if (ret == -1 && errno == ENOBUFS && opt.period_us == 0 && !opt.oneattime) { */ +/* stats.enobufs++; */ +/* /\* Ignore this error - pfifo_fast qeuue is full *\/ */ +/* } else */ + error(1, errno, "send_frame (line %d)", __LINE__); + } else { + count++; + msg_in_progress++; + } } static inline void get_next_timeout(struct timespec *timeout) @@ -336,7 +419,10 @@ static inline void get_next_timeout(struct timespec *timeout) last.tv_nsec -= 1000000000; last.tv_sec++; } - timespec_subtract(timeout, &last, &now); + if (timespec_subtract(timeout, &last, &now) /* is negative */) { + stats.overrun++; + memset(timeout, 0, sizeof(*timeout)); + } } else if (opt.timeout_ms != 0) { timeout->tv_sec = opt.timeout_ms/1000; timeout->tv_nsec = (opt.timeout_ms%1000)*1000000; @@ -409,7 +495,7 @@ void process_final_rx(int s) struct can_frame frame; struct msg_info *mi; int ret; - + receive(s, &frame, &ts_kern, &ts_user); mi = frame2info(&frame); mi->ts_rx_final_kern = ts_kern; @@ -431,7 +517,6 @@ void *measure_thread(void *arg) struct timespec timeout; struct sockaddr_can addr; sigset_t set; - unsigned msg_in_progress = 0; MEMSET_ZERO(pfd); @@ -471,21 +556,12 @@ void *measure_thread(void *arg) pfd[i].events = POLLIN; } - set_sched_policy_and_prio(SCHED_FIFO, 99); + set_sched_policy_and_prio(SCHED_FIFO, 40); -#define SEND() \ - do { \ - ret = send_frame(pfd[0].fd); \ - if (ret != sizeof(struct can_frame)) \ - error(1, errno, "send_frame (line %d)", __LINE__); \ - count++; \ - msg_in_progress++; \ - } while (0) +#define SEND() send_and_check(pfd[0].fd) - if (opt.oneattime) { + if (opt.oneattime) SEND(); - count = 1; - } while (!finish_flag && (opt.count == 0 || count < opt.count || msg_in_progress != 0)) { @@ -600,6 +676,11 @@ int parse_options(int argc, const char *argv[]) return 0; } +void print_progress() +{ + printf("\rSent %5d, in progress %5d", count, msg_in_progress); + fflush(stdout); +} int main(int argc, const char *argv[]) { @@ -627,7 +708,9 @@ int main(int argc, const char *argv[]) ret = fcntl(completion_pipe[1], F_SETFL, O_NONBLOCK); if (ret == -1) error(1, errno, "pipe fcntl"); - + + init_ftrace(); + pthread_create(&thread, 0, measure_thread, NULL); struct timespec next, now, diff; @@ -654,16 +737,16 @@ int main(int argc, const char *argv[]) clock_gettime(CLOCK_MONOTONIC, &now); if (timespec_subtract(&diff, &next, &now)) { - printf("\rMessage %d", count); - fflush(stdout); - next.tv_nsec += 100000000; + print_progress(); + next.tv_nsec += 100000000; while (next.tv_nsec >= 1000000000) { next.tv_nsec -= 1000000000; next.tv_sec++; } } } - printf("\rMessage %d\n", count); + print_progress(); + printf("\n"); pthread_join(thread, NULL); @@ -677,5 +760,10 @@ int main(int argc, const char *argv[]) if (opt.file) fclose(opt.file); + if (stats.overrun) + printf("overrun=%d\n", stats.overrun); + if (stats.enobufs) + printf("enobufs=%d\n", stats.enobufs); + return 0; }