Commit ff422c33 authored by Alessandro Rubini's avatar Alessandro Rubini Committed by Grzegorz Daniluk

ltest: minute-based reporting to syslog (fixes lost-frame counting)

Signed-off-by: Alessandro Rubini's avatarAlessandro Rubini <rubini@gnudd.com>
parent ed72fea2
...@@ -65,7 +65,6 @@ int check_dest_ip(unsigned char *buf); ...@@ -65,7 +65,6 @@ int check_dest_ip(unsigned char *buf);
void syslog_init(void); void syslog_init(void);
int syslog_poll(void); int syslog_poll(void);
void syslog_latency_report(int prio, struct wr_timestamp *lat, int lost[2]); void syslog_report(char *buf);
#endif #endif
...@@ -11,6 +11,10 @@ ...@@ -11,6 +11,10 @@
#include <ptpd_netif.h> #include <ptpd_netif.h>
#include <shell.h> #include <shell.h>
#include "ipv4.h" #include "ipv4.h"
#include <endpoint.h> /* get_mac_addr() */
#include <ppsi/jiffies.h> /* time_before() */
#define jiffies timer_get_tics()
#ifdef CONFIG_LATENCY_SYSLOG #ifdef CONFIG_LATENCY_SYSLOG
#define HAS_SYSLOG 1 #define HAS_SYSLOG 1
...@@ -73,11 +77,51 @@ static void latency_warning(void) { ...@@ -73,11 +77,51 @@ static void latency_warning(void) {
frame.sequence, frame.type, prev_sequence, prev_type); frame.sequence, frame.type, prev_sequence, prev_type);
} }
/* report once a minute */
static void latency_report(struct wr_timestamp *lat)
{
static unsigned long nextj;
static unsigned long min[2], max[2], tot[2], n;
char buf[128];
int i;
if (!nextj) {
unsigned char mac[6];
/* first time; pick a time in the future */
get_mac_addr(mac);
nextj = jiffies + TICS_PER_SECOND * (10 + (mac[5] % 60));
pp_printf("%s: first sending at %li\n", __func__, nextj);
}
n++;
for (i = 0; i < 2; i++) {
if (!min[i] || lat[i].nsec < min[i])
min[i] = lat[i].nsec;
if ( lat[i].nsec > max[i])
max[i] = lat[i].nsec;
tot[i] += lat[i].nsec;
}
if (time_before(jiffies, nextj))
return;
nextj += 60 * TICS_PER_SECOND;
if (!n)
return;
pp_sprintf(buf, "ltest: %li samples, "
"min %li %li, avg %li %li, max %li %li\n",
n, min[0], min[1], tot[0]/n, tot[1]/n, max[0], max[1]);
n = min[0] = min[1] = max[0] = max[1] = tot[0] = tot[1] = 0;
syslog_report(buf);
}
static int latency_poll_rx(void) static int latency_poll_rx(void)
{ {
static struct wr_timestamp ts[2]; static struct wr_timestamp ts[2];
static int nframes; static int nframes;
static int lost[2]; static unsigned lost;
struct wr_timestamp ts_tmp, lat[2]; struct wr_timestamp ts_tmp, lat[2];
struct wr_sockaddr addr; struct wr_sockaddr addr;
int i, j; int i, j;
...@@ -119,10 +163,13 @@ static int latency_poll_rx(void) ...@@ -119,10 +163,13 @@ static int latency_poll_rx(void)
/* count lost frames */ /* count lost frames */
i = prev_sequence * 3 + prev_type - 1; /* type: 1..3 -> 0..2 */ i = prev_sequence * 3 + prev_type - 1; /* type: 1..3 -> 0..2 */
j = frame.sequence * 3 + frame.type - 2; j = frame.sequence * 3 + frame.type - 2;
if (HAS_SYSLOG && j != i && j < i + 100) { if (HAS_SYSLOG && j != i) {
lost[1] = j; char buf[64];
lost[0] += j;
syslog_latency_report(-1, NULL, lost); lost += (j - i);
pp_sprintf(buf, "ltest: lost %i frames, total %i\n",
j - i, lost);
syslog_report(buf);
} }
prev_sequence = frame.sequence; prev_sequence = frame.sequence;
...@@ -152,22 +199,15 @@ static int latency_poll_rx(void) ...@@ -152,22 +199,15 @@ static int latency_poll_rx(void)
frame.sequence, frame.sequence,
lat[0].nsec, lat[0].phase, lat[0].nsec, lat[0].phase,
lat[1].nsec, lat[1].phase); lat[1].nsec, lat[1].phase);
return 1;
} else { } else {
/* keep a running average of 8 samples */ latency_report(lat);
static unsigned long avg_ns[2];
int i;
for (i = 0; i < 2; i++) {
if (!avg_ns[i])
avg_ns[i] = 2 * lat[i].nsec;
if (lat[i].nsec > avg_ns[i] * 2)
syslog_latency_report(prios[i], lat + i, lost);
avg_ns[i] = (7 * avg_ns[i] + lat[i].nsec) / 8;
}
} }
return 1; return 1;
} }
static int latency_poll_tx(void) static int latency_poll_tx(void)
{ {
static uint32_t sequence; static uint32_t sequence;
......
...@@ -203,11 +203,11 @@ int syslog_poll(void) ...@@ -203,11 +203,11 @@ int syslog_poll(void)
send: send:
syslog_send(buf, ip, len); syslog_send(buf, ip, len);
return 1;
} }
#ifdef CONFIG_LATENCY_SYSLOG /* A report tool for others to call (used by ltest at least) */
void syslog_report(char *msg)
void syslog_latency_report(int prio, struct wr_timestamp *ts, int lost[2])
{ {
char buf[256]; char buf[256];
unsigned char ip[4]; unsigned char ip[4];
...@@ -219,15 +219,7 @@ void syslog_latency_report(int prio, struct wr_timestamp *ts, int lost[2]) ...@@ -219,15 +219,7 @@ void syslog_latency_report(int prio, struct wr_timestamp *ts, int lost[2])
return; return;
len = syslog_header(buf, SYSLOG_DEFAULT_LEVEL, ip); len = syslog_header(buf, SYSLOG_DEFAULT_LEVEL, ip);
if (lost[1]) { strcpy(buf + len, msg);
len += pp_sprintf(buf + len, len += strlen(msg);
"ltest: lost %i frames (total %i)\n",
lost[1], lost[0]);
} else {
len += pp_sprintf(buf + len, "ltest: prio %i, %i ns\n",
prio, ts->nsec);
}
syslog_send(buf, ip, len); syslog_send(buf, ip, len);
} }
#endif
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment