lib/timeval.c

   1 /*
   2  * Copyright (c) 2008, 2009, 2010 Nicira Networks.
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at:
   7  *
   8  *     http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 #include <config.h>
  18 #include "timeval.h"
  19 #include <assert.h>
  20 #include <errno.h>
  21 #include <poll.h>
  22 #include <signal.h>
  23 #include <string.h>
  24 #include <sys/time.h>
  25 #include <sys/resource.h>
  26 #include <unistd.h>
  27 #include "coverage.h"
  28 #include "fatal-signal.h"
  29 #include "util.h"
  30
  31 #include "vlog.h"
  32 #define THIS_MODULE VLM_timeval
  33
  34 /* Initialized? */
  35 static bool inited;
  36
  37 /* The clock to use for measuring time intervals.  This is CLOCK_MONOTONIC by
  38  * preference, but on systems that don't have a monotonic clock we fall back
  39  * to CLOCK_REALTIME. */
  40 static clockid_t monotonic_clock;
  41
  42 /* Has a timer tick occurred? */
  43 static volatile sig_atomic_t wall_tick;
  44 static volatile sig_atomic_t monotonic_tick;
  45
  46 /* The current time, as of the last refresh. */
  47 static struct timespec wall_time;
  48 static struct timespec monotonic_time;
  49
  50 /* Time at which to die with SIGALRM (if not TIME_MIN). */
  51 static time_t deadline = TIME_MIN;
  52
  53 static void set_up_timer(void);
  54 static void set_up_signal(int flags);
  55 static void sigalrm_handler(int);
  56 static void refresh_wall_if_ticked(void);
  57 static void refresh_monotonic_if_ticked(void);
  58 static time_t time_add(time_t, time_t);
  59 static void block_sigalrm(sigset_t *);
  60 static void unblock_sigalrm(const sigset_t *);
  61 static void log_poll_interval(long long int last_wakeup,
  62                               const struct rusage *last_rusage);
  63
  64 /* Initializes the timetracking module. */
  65 void
  66 time_init(void)
  67 {
  68     if (inited) {
  69         return;
  70     }
  71
  72     coverage_init();
  73
  74     inited = true;
  75     time_refresh();
  76
  77     if (!clock_gettime(CLOCK_MONOTONIC, &monotonic_time)) {
  78         monotonic_clock = CLOCK_MONOTONIC;
  79     } else {
  80         monotonic_clock = CLOCK_REALTIME;
  81         VLOG_DBG("monotonic timer not available");
  82     }
  83
  84     set_up_signal(SA_RESTART);
  85     set_up_timer();
  86 }
  87
  88 static void
  89 set_up_signal(int flags)
  90 {
  91     struct sigaction sa;
  92
  93     memset(&sa, 0, sizeof sa);
  94     sa.sa_handler = sigalrm_handler;
  95     sigemptyset(&sa.sa_mask);
  96     sa.sa_flags = flags;
  97     if (sigaction(SIGALRM, &sa, NULL)) {
  98         ovs_fatal(errno, "sigaction(SIGALRM) failed");
  99     }
 100 }
 101
 102 /* Remove SA_RESTART from the flags for SIGALRM, so that any system call that
 103  * is interrupted by the periodic timer interrupt will return EINTR instead of
 104  * continuing after the signal handler returns.
 105  *
 106  * time_disable_restart() and time_enable_restart() may be usefully wrapped
 107  * around function calls that might otherwise block forever unless interrupted
 108  * by a signal, e.g.:
 109  *
 110  *   time_disable_restart();
 111  *   fcntl(fd, F_SETLKW, &lock);
 112  *   time_enable_restart();
 113  */
 114 void
 115 time_disable_restart(void)
 116 {
 117     set_up_signal(0);
 118 }
 119
 120 /* Add SA_RESTART to the flags for SIGALRM, so that any system call that
 121  * is interrupted by the periodic timer interrupt will continue after the
 122  * signal handler returns instead of returning EINTR. */
 123 void
 124 time_enable_restart(void)
 125 {
 126     set_up_signal(SA_RESTART);
 127 }
 128
 129 static void
 130 set_up_timer(void)
 131 {
 132     static timer_t timer_id;    /* "static" to avoid apparent memory leak. */
 133     struct itimerspec itimer;
 134
 135     if (timer_create(monotonic_clock, NULL, &timer_id)) {
 136         ovs_fatal(errno, "timer_create failed");
 137     }
 138
 139     itimer.it_interval.tv_sec = 0;
 140     itimer.it_interval.tv_nsec = TIME_UPDATE_INTERVAL * 1000 * 1000;
 141     itimer.it_value = itimer.it_interval;
 142
 143     if (timer_settime(timer_id, 0, &itimer, NULL)) {
 144         ovs_fatal(errno, "timer_settime failed");
 145     }
 146 }
 147
 148 /* Set up the interval timer, to ensure that time advances even without calling
 149  * time_refresh().
 150  *
 151  * A child created with fork() does not inherit the parent's interval timer, so
 152  * this function needs to be called from the child after fork(). */
 153 void
 154 time_postfork(void)
 155 {
 156     time_init();
 157     set_up_timer();
 158 }
 159
 160 static void
 161 refresh_wall(void)
 162 {
 163     clock_gettime(CLOCK_REALTIME, &wall_time);
 164     wall_tick = false;
 165 }
 166
 167 static void
 168 refresh_monotonic(void)
 169 {
 170     time_init();
 171
 172     if (monotonic_clock == CLOCK_MONOTONIC) {
 173         clock_gettime(monotonic_clock, &monotonic_time);
 174     } else {
 175         refresh_wall_if_ticked();
 176         monotonic_time = wall_time;
 177     }
 178
 179     monotonic_tick = false;
 180 }
 181
 182 /* Forces a refresh of the current time from the kernel.  It is not usually
 183  * necessary to call this function, since the time will be refreshed
 184  * automatically at least every TIME_UPDATE_INTERVAL milliseconds. */
 185 void
 186 time_refresh(void)
 187 {
 188     wall_tick = monotonic_tick = true;
 189 }
 190
 191 /* Returns a monotonic timer, in seconds. */
 192 time_t
 193 time_now(void)
 194 {
 195     refresh_monotonic_if_ticked();
 196     return monotonic_time.tv_sec;
 197 }
 198
 199 /* Same as time_now() except does not write to static variables, for use in
 200  * signal handlers.  */
 201 static time_t
 202 time_now_sig(void)
 203 {
 204     struct timespec cur_time;
 205
 206     clock_gettime(monotonic_clock, &cur_time);
 207     return cur_time.tv_sec;
 208 }
 209
 210 /* Returns the current time, in seconds. */
 211 time_t
 212 time_wall(void)
 213 {
 214     refresh_wall_if_ticked();
 215     return wall_time.tv_sec;
 216 }
 217
 218 /* Returns a monotonic timer, in ms (within TIME_UPDATE_INTERVAL ms). */
 219 long long int
 220 time_msec(void)
 221 {
 222     refresh_monotonic_if_ticked();
 223     return timespec_to_msec(&monotonic_time);
 224 }
 225
 226 /* Returns the current time, in ms (within TIME_UPDATE_INTERVAL ms). */
 227 long long int
 228 time_wall_msec(void)
 229 {
 230     refresh_wall_if_ticked();
 231     return timespec_to_msec(&wall_time);
 232 }
 233
 234 /* Stores a monotonic timer, accurate within TIME_UPDATE_INTERVAL ms, into
 235  * '*ts'. */
 236 void
 237 time_timespec(struct timespec *ts)
 238 {
 239     refresh_monotonic_if_ticked();
 240     *ts = monotonic_time;
 241 }
 242
 243 /* Stores the current time, accurate within TIME_UPDATE_INTERVAL ms, into
 244  * '*ts'. */
 245 void
 246 time_wall_timespec(struct timespec *ts)
 247 {
 248     refresh_wall_if_ticked();
 249     *ts = wall_time;
 250 }
 251
 252 /* Configures the program to die with SIGALRM 'secs' seconds from now, if
 253  * 'secs' is nonzero, or disables the feature if 'secs' is zero. */
 254 void
 255 time_alarm(unsigned int secs)
 256 {
 257     sigset_t oldsigs;
 258
 259     time_init();
 260     block_sigalrm(&oldsigs);
 261     deadline = secs ? time_add(time_now(), secs) : TIME_MIN;
 262     unblock_sigalrm(&oldsigs);
 263 }
 264
 265 /* Like poll(), except:
 266  *
 267  *      - On error, returns a negative error code (instead of setting errno).
 268  *
 269  *      - If interrupted by a signal, retries automatically until the original
 270  *        'timeout' expires.  (Because of this property, this function will
 271  *        never return -EINTR.)
 272  *
 273  *      - As a side effect, refreshes the current time (like time_refresh()).
 274  */
 275 int
 276 time_poll(struct pollfd *pollfds, int n_pollfds, int timeout)
 277 {
 278     static long long int last_wakeup;
 279     static struct rusage last_rusage;
 280     long long int start;
 281     sigset_t oldsigs;
 282     bool blocked;
 283     int retval;
 284
 285     time_refresh();
 286     log_poll_interval(last_wakeup, &last_rusage);
 287     coverage_clear();
 288     start = time_msec();
 289     blocked = false;
 290     for (;;) {
 291         int time_left;
 292         if (timeout > 0) {
 293             long long int elapsed = time_msec() - start;
 294             time_left = timeout >= elapsed ? timeout - elapsed : 0;
 295         } else {
 296             time_left = timeout;
 297         }
 298
 299         retval = poll(pollfds, n_pollfds, time_left);
 300         if (retval < 0) {
 301             retval = -errno;
 302         }
 303         time_refresh();
 304         if (retval != -EINTR) {
 305             break;
 306         }
 307
 308         if (!blocked && deadline == TIME_MIN) {
 309             block_sigalrm(&oldsigs);
 310             blocked = true;
 311         }
 312     }
 313     if (blocked) {
 314         unblock_sigalrm(&oldsigs);
 315     }
 316     last_wakeup = time_msec();
 317     getrusage(RUSAGE_SELF, &last_rusage);
 318     return retval;
 319 }
 320
 321 /* Returns the sum of 'a' and 'b', with saturation on overflow or underflow. */
 322 static time_t
 323 time_add(time_t a, time_t b)
 324 {
 325     return (a >= 0
 326             ? (b > TIME_MAX - a ? TIME_MAX : a + b)
 327             : (b < TIME_MIN - a ? TIME_MIN : a + b));
 328 }
 329
 330 static void
 331 sigalrm_handler(int sig_nr)
 332 {
 333     wall_tick = true;
 334     monotonic_tick = true;
 335     if (deadline != TIME_MIN && time_now_sig() > deadline) {
 336         fatal_signal_handler(sig_nr);
 337     }
 338 }
 339
 340 static void
 341 refresh_wall_if_ticked(void)
 342 {
 343     assert(inited);
 344     if (wall_tick) {
 345         refresh_wall();
 346     }
 347 }
 348
 349 static void
 350 refresh_monotonic_if_ticked(void)
 351 {
 352     assert(inited);
 353     if (monotonic_tick) {
 354         refresh_monotonic();
 355     }
 356 }
 357
 358 static void
 359 block_sigalrm(sigset_t *oldsigs)
 360 {
 361     sigset_t sigalrm;
 362     sigemptyset(&sigalrm);
 363     sigaddset(&sigalrm, SIGALRM);
 364     if (sigprocmask(SIG_BLOCK, &sigalrm, oldsigs)) {
 365         ovs_fatal(errno, "sigprocmask");
 366     }
 367 }
 368
 369 static void
 370 unblock_sigalrm(const sigset_t *oldsigs)
 371 {
 372     if (sigprocmask(SIG_SETMASK, oldsigs, NULL)) {
 373         ovs_fatal(errno, "sigprocmask");
 374     }
 375 }
 376
 377 long long int
 378 timespec_to_msec(const struct timespec *ts)
 379 {
 380     return (long long int) ts->tv_sec * 1000 + ts->tv_nsec / (1000 * 1000);
 381 }
 382
 383 long long int
 384 timeval_to_msec(const struct timeval *tv)
 385 {
 386     return (long long int) tv->tv_sec * 1000 + tv->tv_usec / 1000;
 387 }
 388
 389 static long long int
 390 timeval_diff_msec(const struct timeval *a, const struct timeval *b)
 391 {
 392     return timeval_to_msec(a) - timeval_to_msec(b);
 393 }
 394
 395 static void
 396 log_poll_interval(long long int last_wakeup, const struct rusage *last_rusage)
 397 {
 398     static unsigned int mean_interval; /* In 16ths of a millisecond. */
 399     static unsigned int n_samples;
 400
 401     long long int now;
 402     unsigned int interval;      /* In 16ths of a millisecond. */
 403
 404     /* Compute interval from last wakeup to now in 16ths of a millisecond,
 405      * capped at 10 seconds (16000 in this unit). */
 406     now = time_msec();
 407     interval = MIN(10000, now - last_wakeup) << 4;
 408
 409     /* Warn if we took too much time between polls. */
 410     if (n_samples > 10 && interval > mean_interval * 8) {
 411         struct rusage rusage;
 412
 413         getrusage(RUSAGE_SELF, &rusage);
 414         VLOG_WARN("%lld ms poll interval (%lld ms user, %lld ms system) "
 415                   "is over %u times the weighted mean interval %u ms "
 416                   "(%u samples)",
 417                   now - last_wakeup,
 418                   timeval_diff_msec(&rusage.ru_utime, &last_rusage->ru_utime),
 419                   timeval_diff_msec(&rusage.ru_stime, &last_rusage->ru_stime),
 420                   interval / mean_interval,
 421                   (mean_interval + 8) / 16, n_samples);
 422         if (rusage.ru_minflt > last_rusage->ru_minflt
 423             || rusage.ru_majflt > last_rusage->ru_majflt) {
 424             VLOG_WARN("faults: %ld minor, %ld major",
 425                       rusage.ru_minflt - last_rusage->ru_minflt,
 426                       rusage.ru_majflt - last_rusage->ru_majflt);
 427         }
 428         if (rusage.ru_inblock > last_rusage->ru_inblock
 429             || rusage.ru_oublock > last_rusage->ru_oublock) {
 430             VLOG_WARN("disk: %ld reads, %ld writes",
 431                       rusage.ru_inblock - last_rusage->ru_inblock,
 432                       rusage.ru_oublock - last_rusage->ru_oublock);
 433         }
 434         if (rusage.ru_nvcsw > last_rusage->ru_nvcsw
 435             || rusage.ru_nivcsw > last_rusage->ru_nivcsw) {
 436             VLOG_WARN("context switches: %ld voluntary, %ld involuntary",
 437                       rusage.ru_nvcsw - last_rusage->ru_nvcsw,
 438                       rusage.ru_nivcsw - last_rusage->ru_nivcsw);
 439         }
 440
 441         /* Care should be taken in the value chosen for logging.  Depending
 442          * on the configuration, syslog can write changes synchronously,
 443          * which can cause the coverage messages to take longer to log
 444          * than the processing delay that triggered it. */
 445         coverage_log(VLL_INFO, true);
 446     }
 447
 448     /* Update exponentially weighted moving average.  With these parameters, a
 449      * given value decays to 1% of its value in about 100 time steps.  */
 450     if (n_samples++) {
 451         mean_interval = (mean_interval * 122 + interval * 6 + 64) / 128;
 452     } else {
 453         mean_interval = interval;
 454     }
 455 }