X-Git-Url: http://rtime.felk.cvut.cz/gitweb/can-benchmark.git/blobdiff_plain/02ace553c6f4b790696fce6b560e0b3a59f929e4..d5e98779e6641341bb138c0c131196249a1bc42d:/latester/latester.c diff --git a/latester/latester.c b/latester/latester.c index 67e1dcb..a6f1453 100644 --- a/latester/latester.c +++ b/latester/latester.c @@ -34,6 +34,7 @@ #include "canframelen.h" #include #include +#include #include "histogram.h" @@ -101,7 +102,6 @@ struct msg_info { struct timespec ts_rx_onwire, ts_rx_onwire_kern; struct timespec ts_rx_final, ts_rx_final_kern; struct can_frame sent, received; - unsigned lat_measured_us, tx_time_us; }; #define MAX_INFOS 10000 @@ -162,18 +162,27 @@ static inline char *tstamp_str(const void *ctx, struct timespec *tstamp) tstamp->tv_sec, tstamp->tv_nsec/1000); } -int timespec_subtract (struct timespec *result, struct timespec *x, struct timespec *yy); +int timespec_subtract (struct timespec *result, const struct timespec *x, const struct timespec *yy); -void msg_info_print(FILE *f, struct msg_info *mi) +static inline unsigned get_timestamp_diff_us(struct msg_info *mi); + +void msg_info_process(FILE *f, struct msg_info *mi) { struct timespec diff; void *local = talloc_new (NULL); static long num = 0; char sent[64], received[64]; + int diff_us = get_timestamp_diff_us(mi); + int tx_time_us = calc_frame_length(&mi->received); + + /* Update histograms */ + histogram_add(&histogram, diff_us); + histogram_add(&histogram_gw, diff_us - tx_time_us); if (!f) return; + /* Print information to a file */ sprint_canframe(sent, &mi->sent, true); sprint_canframe(received, &mi->received, true); @@ -186,10 +195,10 @@ void msg_info_print(FILE *f, struct msg_info *mi) num, S(mi->ts_sent), sent, S(mi->ts_rx_final_kern), S(mi->ts_rx_final), received, DIFF(mi->ts_sent, mi->ts_rx_final_kern), DIFF(mi->ts_sent, mi->ts_rx_final), - mi->tx_time_us); + tx_time_us); break; case 3: - fprintf(f, "%ld: %s %s -> %s (%s) -> %s (%s) %s = %s (%s), %s (%s) %d\n", + fprintf(f, "%ld: %s %s -> %s (%s) -> %s (%s) %s = %s (%s), %s (%s) %d %.6f\n", num, S(mi->ts_sent), sent, S(mi->ts_rx_onwire_kern), S(mi->ts_rx_onwire), S(mi->ts_rx_final_kern), S(mi->ts_rx_final), received, @@ -197,7 +206,8 @@ void msg_info_print(FILE *f, struct msg_info *mi) DIFF(mi->ts_sent, mi->ts_rx_onwire), DIFF(mi->ts_rx_onwire_kern, mi->ts_rx_final_kern), DIFF(mi->ts_rx_onwire, mi->ts_rx_final), - mi->tx_time_us); + tx_time_us, + 1e-6*(diff_us - tx_time_us)); break; } #undef S @@ -209,7 +219,7 @@ void msg_info_print(FILE *f, struct msg_info *mi) /* Subtract the `struct timespec' values X and Y, storing the result in RESULT. Return 1 if the difference is negative, otherwise 0. */ -int timespec_subtract (struct timespec *result, struct timespec *x, struct timespec *yy) +int timespec_subtract (struct timespec *result, const struct timespec *x, const struct timespec *yy) { struct timespec ylocal = *yy, *y = &ylocal; /* Perform the carry for the later subtraction by updating Y. */ @@ -239,7 +249,7 @@ void dbg_print_timespec(char *msg, struct timespec *tv) printf("%s sec=%ld nsec=%ld\n", msg, tv->tv_sec, tv->tv_nsec); } -static inline void calc_msg_latencies(struct msg_info *mi) +static inline unsigned get_timestamp_diff_us(struct msg_info *mi) { struct timespec diff; switch (num_interfaces) { @@ -256,10 +266,10 @@ static inline void calc_msg_latencies(struct msg_info *mi) timespec_subtract(&diff, &mi->ts_rx_final_kern, &mi->ts_sent); break; default: - return; + return 0; } - mi->lat_measured_us = diff.tv_sec * 1000000 + diff.tv_nsec/1000; - mi->tx_time_us = calc_frame_length(&mi->received); + unsigned us = diff.tv_sec * 1000000 + diff.tv_nsec/1000; + return us; } void set_sched_policy_and_prio(int policy, int rtprio) @@ -296,7 +306,7 @@ static inline int sock_get_if_index(int s, const char *if_name) static inline void get_tstamp(struct timespec *ts) { - clock_gettime(CLOCK_REALTIME, ts); + clock_gettime(CLOCK_MONOTONIC/*REALTIME*/, ts); } @@ -421,26 +431,34 @@ static inline void send_and_check(int s) } } -static inline void get_next_timeout(struct timespec *timeout) +static inline void get_next_timeout(struct timespec *timeout, bool advance) { struct timespec now; static struct timespec last = {-1, 0 }; clock_gettime(CLOCK_MONOTONIC, &now); - if (last.tv_sec == -1) + if (last.tv_sec == -1) { last = now; + last.tv_nsec = last.tv_nsec/1000000*1000000; + } if (opt.period_us != 0) { - last.tv_sec += opt.period_us/1000000; - last.tv_nsec += (opt.period_us%1000000)*1000; - while (last.tv_nsec >= 1000000000) { - last.tv_nsec -= 1000000000; - last.tv_sec++; + if (advance) { + last.tv_sec += opt.period_us/1000000; + last.tv_nsec += (opt.period_us%1000000)*1000; + while (last.tv_nsec >= 1000000000) { + last.tv_nsec -= 1000000000; + last.tv_sec++; + } } if (timespec_subtract(timeout, &last, &now) /* is negative */) { stats.overrun++; memset(timeout, 0, sizeof(*timeout)); } +/* printf("next %ld.%06ld now %ld.%06ld --> timeout %ld.%06ld\n", */ +/* last.tv_sec, last.tv_nsec/1000, */ +/* now.tv_sec, now.tv_nsec/1000, */ +/* timeout->tv_sec, timeout->tv_nsec/1000); */ } else if (opt.timeout_ms != 0) { timeout->tv_sec = opt.timeout_ms/1000; timeout->tv_nsec = (opt.timeout_ms%1000)*1000000; @@ -457,6 +475,7 @@ void receive(int s, struct can_frame *frame, struct timespec *ts_kern, struct ti struct sockaddr_can addr; int nbytes; static uint64_t dropcnt = 0; + bool have_hwtstamp = 0; iov.iov_base = frame; msg.msg_name = &addr; @@ -482,8 +501,15 @@ void receive(int s, struct can_frame *frame, struct timespec *ts_kern, struct ti for (cmsg = CMSG_FIRSTHDR(&msg); cmsg && (cmsg->cmsg_level == SOL_SOCKET); cmsg = CMSG_NXTHDR(&msg,cmsg)) { - if (cmsg->cmsg_type == SO_TIMESTAMPNS) - memcpy(ts_kern, CMSG_DATA(cmsg), sizeof(struct timespec)); + if (cmsg->cmsg_type == SO_TIMESTAMPNS) { + if(!have_hwtstamp) + memcpy(ts_kern, CMSG_DATA(cmsg), sizeof(struct timespec)); + } + else if (cmsg->cmsg_type == SO_TIMESTAMPING) { + struct timespec *ts = (struct timespec *) CMSG_DATA(cmsg); + memcpy(ts_kern, &ts[2], sizeof(struct timespec)); + have_hwtstamp = 1; + } else if (cmsg->cmsg_type == SO_RXQ_OVFL) { uint32_t ovfl; memcpy(&ovfl, CMSG_DATA(cmsg), sizeof(ovfl)); @@ -526,11 +552,6 @@ void process_final_rx(int s) mi->ts_rx_final = ts_user; mi->received = frame; - calc_msg_latencies(mi); - - histogram_add(&histogram, mi->lat_measured_us); - histogram_add(&histogram_gw, mi->lat_measured_us - mi->tx_time_us); - ret = write(completion_pipe[1], &mi, sizeof(mi)); if (ret == -1) error(1, errno, "completion_pipe write"); @@ -565,10 +586,20 @@ void *measure_thread(void *arg) if (bind(s, (struct sockaddr *)&addr, sizeof(addr)) < 0) error(1, errno, "bind"); - const int timestamp_on = 1; - if (setsockopt(s, SOL_SOCKET, SO_TIMESTAMPNS, - ×tamp_on, sizeof(timestamp_on)) < 0) - error(1, errno, "setsockopt SO_TIMESTAMP"); + // TODO: set HW TSTAMP flags? + const int so_timestamping_flags = SOF_TIMESTAMPING_RAW_HARDWARE; + if (setsockopt(s, SOL_SOCKET, SO_TIMESTAMPING, + &so_timestamping_flags, + sizeof(so_timestamping_flags)) < 0) + { + perror("setsockopt SO_TIMESTAMPING"); + fprintf(stderr, "Falling back to SW timestamps.\n"); + + const int timestamp_on = 1; + if (setsockopt(s, SOL_SOCKET, SO_TIMESTAMPNS, + ×tamp_on, sizeof(timestamp_on)) < 0) + error(1, errno, "setsockopt SO_TIMESTAMPNS"); + } const int dropmonitor_on = 1; if (setsockopt(s, SOL_SOCKET, SO_RXQ_OVFL, @@ -590,11 +621,12 @@ void *measure_thread(void *arg) SEND(); get_tstamp(&stats.tic); - + ret = 0; while (!finish_flag && (opt.count == 0 || count < opt.count || msg_in_progress != 0)) { - get_next_timeout(&timeout); + get_next_timeout(&timeout, ret == 0); + //printf("timeout %ld.%06ld\n", timeout.tv_sec, timeout.tv_nsec/1000); //printf("ppoll"); fflush(stdout); ret = ppoll(pfd, num_interfaces, &timeout, NULL); //printf("=%d\n", ret); @@ -799,7 +831,8 @@ int main(int argc, const char *argv[]) ret = read(completion_pipe[0], &mi, sizeof(mi)); if (ret < sizeof(mi)) error(1, errno, "read completion returned %d", ret); - msg_info_print(opt.f_msgs, mi); + + msg_info_process(opt.f_msgs, mi); msg_info_free(mi); completed++; } @@ -850,6 +883,7 @@ int main(int argc, const char *argv[]) fclose(opt.f_msgs); if (opt.f_stat) { + struct histogram_stats hs; fprintf(opt.f_stat, "cmdline='"); for (i=0; i