Unified time for whole BIRD

In previous versions, every thread used its own time structures,
effectively leading to different time in every thread and strange
logging messages.

The time processing code now uses global atomic variables to keep
current time available for fast concurrent reading and safe updates.

diff --git a/lib/timer.c b/lib/timer.c
index 6efcadb4b480dbb46e23d8e003e108b65b4edefe..ff1fb5eff2b7e1dbd30162e60d263948b36b5592 100644 (file)
--- a/lib/timer.c
+++ b/lib/timer.c
@@ -32,6 +32,7 @@
 
 #include "nest/bird.h"
 
+#include "lib/coro.h"
 #include "lib/heap.h"
 #include "lib/resource.h"
 #include "lib/timer.h"
@@ -45,22 +46,10 @@ struct timeloop main_timeloop;
 /* Data accessed and modified from proto/bfd/io.c */
 _Thread_local struct timeloop *local_timeloop;
 
-void wakeup_kick_current(void);
-
-btime
-current_time(void)
-{
-  return local_timeloop->last_time;
-}
+_Atomic btime last_time;
+_Atomic btime real_time;
 
-btime
-current_real_time(void)
-{
-  if (!local_timeloop->real_time)
-    times_update_real_time(local_timeloop);
-
-  return local_timeloop->real_time;
-}
+void wakeup_kick_current(void);
 
 
 #define TIMER_LESS(a,b)                ((a)->expires < (b)->expires)
@@ -164,8 +153,6 @@ tm_stop(timer *t)
 void
 timers_init(struct timeloop *loop, pool *p)
 {
-  times_init(loop);
-
   BUFFER_INIT(loop->timers, p, 4);
   BUFFER_PUSH(loop->timers) = NULL;
 }
@@ -178,8 +165,8 @@ timers_fire(struct timeloop *loop)
   btime base_time;
   timer *t;
 
-  times_update(loop);
-  base_time = loop->last_time;
+  times_update();
+  base_time = current_time();
 
   while (t = timers_first(loop))
   {
@@ -190,8 +177,8 @@ timers_fire(struct timeloop *loop)
     {
       btime when = t->expires + t->recurrent;
 
-      if (when <= loop->last_time)
-       when = loop->last_time + t->recurrent;
+      if (when <= base_time)
+       when = base_time + t->recurrent;
 
       if (t->randomize)
        when += random() % (t->randomize + 1);

diff --git a/lib/timer.h b/lib/timer.h
index bc568ee67dc9aff13e9a33823a36e89150d0d142..b201b8c82e635fc0e5ee523b754f709284dc5d58 100644 (file)
--- a/lib/timer.h
+++ b/lib/timer.h
@@ -14,6 +14,10 @@
 #include "lib/buffer.h"
 #include "lib/resource.h"
 
+#include <stdatomic.h>
+
+extern _Atomic btime last_time;
+extern _Atomic btime real_time;
 
 typedef struct timer
 {
@@ -31,8 +35,6 @@ typedef struct timer
 struct timeloop
 {
   BUFFER_(timer *) timers;
-  btime last_time;
-  btime real_time;
 };
 
 static inline uint timers_count(struct timeloop *loop)
@@ -44,8 +46,8 @@ static inline timer *timers_first(struct timeloop *loop)
 extern struct timeloop main_timeloop;
 extern _Thread_local struct timeloop *local_timeloop;
 
-btime current_time(void);
-btime current_real_time(void);
+#define current_time()         atomic_load_explicit(&last_time, memory_order_acquire)
+#define current_real_time()    atomic_load_explicit(&real_time, memory_order_acquire)
 
 //#define now (current_time() TO_S)
 //#define now_real (current_real_time() TO_S)
@@ -95,9 +97,7 @@ tm_start_max(timer *t, btime after)
 }
 
 /* In sysdep code */
-void times_init(struct timeloop *loop);
-void times_update(struct timeloop *loop);
-void times_update_real_time(struct timeloop *loop);
+void times_update(void);
 
 /* For I/O loop */
 void timers_init(struct timeloop *loop, pool *p);

diff --git a/proto/bfd/io.c b/proto/bfd/io.c
index 8fdc84fb0851ec4426b231513c18e925858992b0..c5f1e024d64e8b8386f0b6a9fdf8bf8aed347c65 100644 (file)
--- a/proto/bfd/io.c
+++ b/proto/bfd/io.c
@@ -172,7 +172,7 @@ events_init(struct birdloop *loop)
 static void
 events_fire(struct birdloop *loop)
 {
-  times_update(&loop->time);
+  times_update();
   ev_run_list(&loop->event_list);
 }
 
@@ -332,7 +332,7 @@ sockets_fire(struct birdloop *loop)
   sock **psk = loop->poll_sk.data;
   int poll_num = loop->poll_fd.used - 1;
 
-  times_update(&loop->time);
+  times_update();
 
   /* Last fd is internal wakeup fd */
   if (pfd[poll_num].revents & POLLIN)
@@ -365,7 +365,7 @@ sockets_fire(struct birdloop *loop)
  *     Birdloop
  */
 
-static void * birdloop_main(void *arg);
+static void *birdloop_main(void *arg);
 
 struct birdloop *
 birdloop_new(void)
@@ -461,7 +461,7 @@ birdloop_main(void *arg)
     events_fire(loop);
     timers_fire(&loop->time);
 
-    times_update(&loop->time);
+    times_update();
     if (events_waiting(loop))
       timeout = 0;
     else if (t = timers_first(&loop->time))

diff --git a/sysdep/unix/io.c b/sysdep/unix/io.c
index 40841ea4482803d0c84b5c5236baa8f0d77863c1..90bb5d641b1eec94e1d744632d9ae73077b2ece4 100644 (file)
--- a/sysdep/unix/io.c
+++ b/sysdep/unix/io.c
@@ -123,55 +123,50 @@ rf_fileno(struct rfile *f)
 
 btime boot_time;
 
+
 void
-times_init(struct timeloop *loop)
+times_update(void)
 {
   struct timespec ts;
   int rv;
 
+  btime old_time = current_time();
+  btime old_real_time = current_real_time();
+
   rv = clock_gettime(CLOCK_MONOTONIC, &ts);
   if (rv < 0)
     die("Monotonic clock is missing");
 
   if ((ts.tv_sec < 0) || (((u64) ts.tv_sec) > ((u64) 1 << 40)))
     log(L_WARN "Monotonic clock is crazy");
-
-  loop->last_time = ts.tv_sec S + ts.tv_nsec NS;
-  loop->real_time = 0;
-}
-
-void
-times_update(struct timeloop *loop)
-{
-  struct timespec ts;
-  int rv;
-
-  rv = clock_gettime(CLOCK_MONOTONIC, &ts);
-  if (rv < 0)
-    die("clock_gettime: %m");
-
+  
   btime new_time = ts.tv_sec S + ts.tv_nsec NS;
 
-  if (new_time < loop->last_time)
+  if (new_time < old_time)
     log(L_ERR "Monotonic clock is broken");
 
-  loop->last_time = new_time;
-  loop->real_time = 0;
-}
-
-void
-times_update_real_time(struct timeloop *loop)
-{
-  struct timespec ts;
-  int rv;
-
   rv = clock_gettime(CLOCK_REALTIME, &ts);
   if (rv < 0)
     die("clock_gettime: %m");
 
-  loop->real_time = ts.tv_sec S + ts.tv_nsec NS;
-}
+  btime new_real_time = ts.tv_sec S + ts.tv_nsec NS;
 
+  if (!atomic_compare_exchange_strong_explicit(
+      &last_time,
+      &old_time,
+      new_time,
+      memory_order_acq_rel,
+      memory_order_relaxed))
+    DBG("Time update collision: last_time");
+
+  if (!atomic_compare_exchange_strong_explicit(
+      &real_time,
+      &old_real_time,
+      new_real_time,
+      memory_order_acq_rel,
+      memory_order_relaxed))
+    DBG("Time update collision: real_time");
+}
 
 /**
  * DOC: Sockets
@@ -2017,30 +2012,17 @@ struct event_log_entry
 static struct event_log_entry event_log[EVENT_LOG_LENGTH];
 static struct event_log_entry *event_open;
 static int event_log_pos, event_log_num, watchdog_active;
-static btime last_time;
+static btime last_io_time;
 static btime loop_time;
 
 static void
 io_update_time(void)
 {
-  struct timespec ts;
-  int rv;
-
-  /*
-   * This is third time-tracking procedure (after update_times() above and
-   * times_update() in BFD), dedicated to internal event log and latency
-   * tracking. Hopefully, we consolidate these sometimes.
-   */
-
-  rv = clock_gettime(CLOCK_MONOTONIC, &ts);
-  if (rv < 0)
-    die("clock_gettime: %m");
-
-  last_time = ts.tv_sec S + ts.tv_nsec NS;
+  last_io_time = current_time();
 
   if (event_open)
   {
-    event_open->duration = last_time - event_open->timestamp;
+    event_open->duration = last_io_time - event_open->timestamp;
 
     if (event_open->duration > config->latency_limit)
       log(L_WARN "Event 0x%p 0x%p took %d ms",
@@ -2069,7 +2051,7 @@ io_log_event(void *hook, void *data)
 
   en->hook = hook;
   en->data = data;
-  en->timestamp = last_time;
+  en->timestamp = last_io_time;
   en->duration = 0;
 
   event_log_num++;
@@ -2097,14 +2079,14 @@ io_log_dump(void)
     struct event_log_entry *en = event_log + (event_log_pos + i) % EVENT_LOG_LENGTH;
     if (en->hook)
       log(L_DEBUG "  Event 0x%p 0x%p at %8d for %d ms", en->hook, en->data,
-         (int) ((last_time - en->timestamp) TO_MS), (int) (en->duration TO_MS));
+         (int) ((last_io_time - en->timestamp) TO_MS), (int) (en->duration TO_MS));
   }
 }
 
 void
 watchdog_sigalrm(int sig UNUSED)
 {
-  /* Update last_time and duration, but skip latency check */
+  /* Update last_io_time and duration, but skip latency check */
   config->latency_limit = 0xffffffff;
   io_update_time();
 
@@ -2117,7 +2099,7 @@ watchdog_start1(void)
 {
   io_update_time();
 
-  loop_time = last_time;
+  loop_time = last_io_time;
 }
 
 static inline void
@@ -2125,7 +2107,7 @@ watchdog_start(void)
 {
   io_update_time();
 
-  loop_time = last_time;
+  loop_time = last_io_time;
   event_log_num = 0;
 
   if (config->watchdog_timeout)
@@ -2146,7 +2128,7 @@ watchdog_stop(void)
     watchdog_active = 0;
   }
 
-  btime duration = last_time - loop_time;
+  btime duration = last_io_time - loop_time;
   if (duration > config->watchdog_warning)
     log(L_WARN "I/O loop cycle took %d ms for %d events",
        (int) (duration TO_MS), event_log_num);
@@ -2202,7 +2184,7 @@ io_loop(void)
   watchdog_start1();
   for(;;)
     {
-      times_update(&main_timeloop);
+      times_update();
       events = ev_run_list(&global_event_list);
       events = ev_run_list_limited(&global_work_list, WORK_EVENTS_MAX) || events;
       timers_fire(&main_timeloop);
@@ -2212,7 +2194,7 @@ io_loop(void)
       poll_tout = (events ? 0 : 3000); /* Time in milliseconds */
       if (t = timers_first(&main_timeloop))
       {
-       times_update(&main_timeloop);
+       times_update();
        timeout = (tm_remains(t) TO_MS) + 1;
        poll_tout = MIN(poll_tout, timeout);
       }
@@ -2302,7 +2284,7 @@ io_loop(void)
            continue;
          }
 
-         times_update(&main_timeloop);
+         times_update();
 
          /* guaranteed to be non-empty */
          current_sock = SKIP_BACK(sock, n, HEAD(sock_list));

diff --git a/sysdep/unix/main.c b/sysdep/unix/main.c
index dabfc5546c7238e3cc462178d876d52487cc4a59..d35424fff4346ac5b109469f037e1b688ae21be4 100644 (file)
--- a/sysdep/unix/main.c
+++ b/sysdep/unix/main.c
@@ -903,6 +903,7 @@ main(int argc, char **argv)
     dmalloc_debug(0x2f03d00);
 #endif
 
+  times_update();
   resource_sys_init();
   parse_args(argc, argv);
   log_switch(1, NULL, NULL);