Skip to content

S
Software for White Rabbit PTP Core
Commit 9d04f61f authored by Alessandro Rubini's avatar Alessandro Rubini Committed by Adam Wujek
Browse files
Options

syslog: tell not-critical track-lost events 

Under frame loss, most track-lost are just because of ptp timeouts.
But since the underlying pll is unaffected, and the RTT is almost constant,
we can tell in the logs whether the lost/resync was actually a time
jump or not.

This is what happens with moderate frame loss (fhe first track-lost is
real, due to a ptp restart, the following ones are not and max delta
between calculated setpoint and current setpoint is reported):

   Jan  1 00:00:02 192.168.128.84 (00: 26:7b:00:04:27) Node up since 1 seconds
   Jun 12 14:16:06 192.168.128.84 Tracking after 19.141 s
   Jun 12 14:17:14 192.168.128.84 Lost track
   Jun 12 14:17:20 192.168.128.84 2-th re-rtrack after 6.119 s
   Jun 12 14:17:43 192.168.128.84 Lost track
   Jun 12 14:17:46 192.168.128.84 3-th re-rtrack after 3.287 s (max delta 2 ps)
   Jun 12 14:18:48 192.168.128.84 Lost track
   Jun 12 14:19:00 192.168.128.84 4-th re-rtrack after 12.388 s (max delta 0 ps)
   Jun 12 14:19:14 192.168.128.84 Lost track
   Jun 12 14:19:18 192.168.128.84 5-th re-rtrack after 4.126 s (max delta 3 ps)
   Jun 12 14:19:25 192.168.128.84 Lost track
   Jun 12 14:19:31 192.168.128.84 6-th re-rtrack after 6.022 s (max delta 4 ps)
   Jun 12 14:19:36 192.168.128.84 Lost track
   Jun 12 14:19:38 192.168.128.84 7-th re-rtrack after 2.229 s (max delta 1 ps)
   Jun 12 14:19:52 192.168.128.84 Lost track
   Jun 12 14:20:03 192.168.128.84 8-th re-rtrack after 10.997 s (max delta 1 ps)
   Jun 12 14:21:02 192.168.128.84 Lost track
   Jun 12 14:21:21 192.168.128.84 9-th re-rtrack after 18.906 s (max delta 2 ps)
Signed-off-by: Alessandro Rubini's avatarAlessandro Rubini <rubini@gnudd.com>
parent 7408338a
Hide whitespace changes
Inline Side-by-side
Showing with 35 additions and 1 deletion
lib/syslog.c
View file @ 9d04f61f
......@@ -112,6 +112,7 @@ int syslog_poll(void)
extern struct pp_instance *ppi;
struct wr_servo_state *s;
static uint32_t prev_tics;
static int last_setp, worst_delta, bad_track_lost;
static int track_ok_count, prev_servo_state = -1;
if (IS_HOST_PROCESS)
......@@ -148,10 +149,15 @@ int syslog_poll(void)
goto send;
}
/*
* The following section is all about track-lost events
*/
if (!prev_tics)
prev_tics = now;
if (s && s->state == WR_TRACK_PHASE) /* monitor setpoint while ok */
last_setp = s->cur_setpoint;
if (s && s->state == WR_TRACK_PHASE &&
prev_servo_state != WR_TRACK_PHASE) {
/* we reached sync: log it */
......@@ -171,8 +177,33 @@ int syslog_poll(void)
"%i-th re-rtrack after %i.%03i s",
track_ok_count,
prev_tics / 1000, prev_tics % 1000);
/* Report if we didn't really loose time */
if (!bad_track_lost)
len += pp_sprintf(buf + len, " (max delta %i ps)",
worst_delta);
bad_track_lost = worst_delta = 0;
goto send;
}
if (s && s->state == WR_SYNC_PHASE && (s->flags & WR_FLAG_WAIT_HW)) {
/*
* Passing through SYNC_NSEC is a glimpse, and we won't notice.
* Check, rather if we are waiting beofre sync_phase.
*/
bad_track_lost = 1;
}
if (s && s->state != WR_TRACK_PHASE) {
int delta = s->cur_setpoint - last_setp;
/* "abs(x - y)" is not working, unexpectedly) */
if (delta < 0)
delta = - delta;
if (delta > worst_delta)
worst_delta = delta;
}
if (s && s->state != WR_TRACK_PHASE &&
prev_servo_state == WR_TRACK_PHASE) {
prev_servo_state = s->state;
......@@ -182,6 +213,9 @@ int syslog_poll(void)
goto send;
}
/*
* A section about temperature monitoring
*/
if (!next_temp_check) {
next_temp_check = now + 1000;
......
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