lib/timeval.c

   1 /*
   2  * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013, 2014 Nicira, Inc.
   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 <errno.h>
  20 #include <poll.h>
  21 #include <pthread.h>
  22 #include <signal.h>
  23 #include <stdlib.h>
  24 #include <string.h>
  25 #include <sys/time.h>
  26 #include <sys/resource.h>
  27 #include <unistd.h>
  28 #include "coverage.h"
  29 #include "dummy.h"
  30 #include "dynamic-string.h"
  31 #include "fatal-signal.h"
  32 #include "hash.h"
  33 #include "hmap.h"
  34 #include "ovs-thread.h"
  35 #include "signals.h"
  36 #include "seq.h"
  37 #include "unixctl.h"
  38 #include "util.h"
  39 #include "vlog.h"
  40
  41 VLOG_DEFINE_THIS_MODULE(timeval);
  42
  43 #ifdef _WIN32
  44 typedef unsigned int clockid_t;
  45
  46 #ifndef CLOCK_MONOTONIC
  47 #define CLOCK_MONOTONIC 1
  48 #endif
  49
  50 #ifndef CLOCK_REALTIME
  51 #define CLOCK_REALTIME 2
  52 #endif
  53
  54 /* Number of 100 ns intervals from January 1, 1601 till January 1, 1970. */
  55 static ULARGE_INTEGER unix_epoch;
  56 #endif /* _WIN32 */
  57
  58 struct clock {
  59     clockid_t id;               /* CLOCK_MONOTONIC or CLOCK_REALTIME. */
  60
  61     /* Features for use by unit tests.  Protected by 'mutex'. */
  62     struct ovs_mutex mutex;
  63     atomic_bool slow_path;             /* True if warped or stopped. */
  64     struct timespec warp OVS_GUARDED;  /* Offset added for unit tests. */
  65     bool stopped OVS_GUARDED;          /* Disable real-time updates if true. */
  66     struct timespec cache OVS_GUARDED; /* Last time read from kernel. */
  67 };
  68
  69 /* Our clocks. */
  70 static struct clock monotonic_clock; /* CLOCK_MONOTONIC, if available. */
  71 static struct clock wall_clock;      /* CLOCK_REALTIME. */
  72
  73 /* The monotonic time at which the time module was initialized. */
  74 static long long int boot_time;
  75
  76 /* True only when timeval_dummy_register() is called. */
  77 static bool timewarp_enabled;
  78 /* Reference to the seq struct.  Threads other than main thread can
  79  * wait on timewarp_seq and be waken up when time is warped. */
  80 static struct seq *timewarp_seq;
  81 /* Last value of 'timewarp_seq'. */
  82 DEFINE_STATIC_PER_THREAD_DATA(uint64_t, last_seq, 0);
  83
  84 /* Monotonic time in milliseconds at which to die with SIGALRM (if not
  85  * LLONG_MAX). */
  86 static long long int deadline = LLONG_MAX;
  87
  88 /* Monotonic time, in milliseconds, at which the last call to time_poll() woke
  89  * up. */
  90 DEFINE_STATIC_PER_THREAD_DATA(long long int, last_wakeup, 0);
  91
  92 static void log_poll_interval(long long int last_wakeup);
  93 static struct rusage *get_recent_rusage(void);
  94 static void refresh_rusage(void);
  95 static void timespec_add(struct timespec *sum,
  96                          const struct timespec *a, const struct timespec *b);
  97
  98 static void
  99 init_clock(struct clock *c, clockid_t id)
 100 {
 101     memset(c, 0, sizeof *c);
 102     c->id = id;
 103     ovs_mutex_init(&c->mutex);
 104     atomic_init(&c->slow_path, false);
 105     xclock_gettime(c->id, &c->cache);
 106     timewarp_seq = seq_create();
 107 }
 108
 109 static void
 110 do_init_time(void)
 111 {
 112     struct timespec ts;
 113
 114 #ifdef _WIN32
 115     /* Calculate number of 100-nanosecond intervals till 01/01/1970. */
 116     SYSTEMTIME unix_epoch_st = { 1970, 1, 0, 1, 0, 0, 0, 0};
 117     FILETIME unix_epoch_ft;
 118
 119     SystemTimeToFileTime(&unix_epoch_st, &unix_epoch_ft);
 120     unix_epoch.LowPart = unix_epoch_ft.dwLowDateTime;
 121     unix_epoch.HighPart = unix_epoch_ft.dwHighDateTime;
 122 #endif
 123
 124     coverage_init();
 125
 126     init_clock(&monotonic_clock, (!clock_gettime(CLOCK_MONOTONIC, &ts)
 127                                   ? CLOCK_MONOTONIC
 128                                   : CLOCK_REALTIME));
 129     init_clock(&wall_clock, CLOCK_REALTIME);
 130     boot_time = timespec_to_msec(&monotonic_clock.cache);
 131 }
 132
 133 /* Initializes the timetracking module, if not already initialized. */
 134 static void
 135 time_init(void)
 136 {
 137     static pthread_once_t once = PTHREAD_ONCE_INIT;
 138     pthread_once(&once, do_init_time);
 139 }
 140
 141 static void
 142 time_timespec__(struct clock *c, struct timespec *ts)
 143 {
 144     bool slow_path;
 145
 146     time_init();
 147
 148     atomic_read_explicit(&c->slow_path, &slow_path, memory_order_relaxed);
 149     if (!slow_path) {
 150         xclock_gettime(c->id, ts);
 151     } else {
 152         struct timespec warp;
 153         struct timespec cache;
 154         bool stopped;
 155
 156         ovs_mutex_lock(&c->mutex);
 157         stopped = c->stopped;
 158         warp = c->warp;
 159         cache = c->cache;
 160         ovs_mutex_unlock(&c->mutex);
 161
 162         if (!stopped) {
 163             xclock_gettime(c->id, &cache);
 164         }
 165         timespec_add(ts, &cache, &warp);
 166     }
 167 }
 168
 169 /* Stores a monotonic timer, accurate within TIME_UPDATE_INTERVAL ms, into
 170  * '*ts'. */
 171 void
 172 time_timespec(struct timespec *ts)
 173 {
 174     time_timespec__(&monotonic_clock, ts);
 175 }
 176
 177 /* Stores the current time, accurate within TIME_UPDATE_INTERVAL ms, into
 178  * '*ts'. */
 179 void
 180 time_wall_timespec(struct timespec *ts)
 181 {
 182     time_timespec__(&wall_clock, ts);
 183 }
 184
 185 static time_t
 186 time_sec__(struct clock *c)
 187 {
 188     struct timespec ts;
 189
 190     time_timespec__(c, &ts);
 191     return ts.tv_sec;
 192 }
 193
 194 /* Returns a monotonic timer, in seconds. */
 195 time_t
 196 time_now(void)
 197 {
 198     return time_sec__(&monotonic_clock);
 199 }
 200
 201 /* Returns the current time, in seconds. */
 202 time_t
 203 time_wall(void)
 204 {
 205     return time_sec__(&wall_clock);
 206 }
 207
 208 static long long int
 209 time_msec__(struct clock *c)
 210 {
 211     struct timespec ts;
 212
 213     time_timespec__(c, &ts);
 214     return timespec_to_msec(&ts);
 215 }
 216
 217 /* Returns a monotonic timer, in ms (within TIME_UPDATE_INTERVAL ms). */
 218 long long int
 219 time_msec(void)
 220 {
 221     return time_msec__(&monotonic_clock);
 222 }
 223
 224 /* Returns the current time, in ms (within TIME_UPDATE_INTERVAL ms). */
 225 long long int
 226 time_wall_msec(void)
 227 {
 228     return time_msec__(&wall_clock);
 229 }
 230
 231 /* Configures the program to die with SIGALRM 'secs' seconds from now, if
 232  * 'secs' is nonzero, or disables the feature if 'secs' is zero. */
 233 void
 234 time_alarm(unsigned int secs)
 235 {
 236     long long int now;
 237     long long int msecs;
 238
 239     assert_single_threaded();
 240     time_init();
 241
 242     now = time_msec();
 243     msecs = secs * 1000LL;
 244     deadline = now < LLONG_MAX - msecs ? now + msecs : LLONG_MAX;
 245 }
 246
 247 /* Like poll(), except:
 248  *
 249  *      - The timeout is specified as an absolute time, as defined by
 250  *        time_msec(), instead of a duration.
 251  *
 252  *      - On error, returns a negative error code (instead of setting errno).
 253  *
 254  *      - If interrupted by a signal, retries automatically until the original
 255  *        timeout is reached.  (Because of this property, this function will
 256  *        never return -EINTR.)
 257  *
 258  * Stores the number of milliseconds elapsed during poll in '*elapsed'. */
 259 int
 260 time_poll(struct pollfd *pollfds, int n_pollfds, HANDLE *handles OVS_UNUSED,
 261           long long int timeout_when, int *elapsed)
 262 {
 263     long long int *last_wakeup = last_wakeup_get();
 264     long long int start;
 265     int retval = 0;
 266
 267     time_init();
 268     coverage_clear();
 269     coverage_run();
 270     if (*last_wakeup) {
 271         log_poll_interval(*last_wakeup);
 272     }
 273     start = time_msec();
 274
 275     timeout_when = MIN(timeout_when, deadline);
 276
 277     for (;;) {
 278         long long int now = time_msec();
 279         int time_left;
 280
 281         if (now >= timeout_when) {
 282             time_left = 0;
 283         } else if ((unsigned long long int) timeout_when - now > INT_MAX) {
 284             time_left = INT_MAX;
 285         } else {
 286             time_left = timeout_when - now;
 287         }
 288
 289 #ifndef _WIN32
 290         retval = poll(pollfds, n_pollfds, time_left);
 291         if (retval < 0) {
 292             retval = -errno;
 293         }
 294 #else
 295         if (n_pollfds > MAXIMUM_WAIT_OBJECTS) {
 296             VLOG_ERR("Cannot handle more than maximum wait objects\n");
 297         } else if (n_pollfds != 0) {
 298             retval = WaitForMultipleObjects(n_pollfds, handles, FALSE,
 299                                             time_left);
 300         }
 301         if (retval < 0) {
 302             /* XXX This will be replace by a win error to errno
 303                conversion function */
 304             retval = -WSAGetLastError();
 305             retval = -EINVAL;
 306         }
 307 #endif
 308
 309         if (deadline <= time_msec()) {
 310 #ifndef _WIN32
 311             fatal_signal_handler(SIGALRM);
 312 #else
 313             VLOG_ERR("wake up from WaitForMultipleObjects after deadline");
 314             fatal_signal_handler(SIGTERM);
 315 #endif
 316             if (retval < 0) {
 317                 retval = 0;
 318             }
 319             break;
 320         }
 321
 322         if (retval != -EINTR) {
 323             break;
 324         }
 325     }
 326     *last_wakeup = time_msec();
 327     refresh_rusage();
 328     *elapsed = *last_wakeup - start;
 329     return retval;
 330 }
 331
 332 long long int
 333 timespec_to_msec(const struct timespec *ts)
 334 {
 335     return (long long int) ts->tv_sec * 1000 + ts->tv_nsec / (1000 * 1000);
 336 }
 337
 338 long long int
 339 timeval_to_msec(const struct timeval *tv)
 340 {
 341     return (long long int) tv->tv_sec * 1000 + tv->tv_usec / 1000;
 342 }
 343
 344 /* Returns the monotonic time at which the "time" module was initialized, in
 345  * milliseconds. */
 346 long long int
 347 time_boot_msec(void)
 348 {
 349     time_init();
 350     return boot_time;
 351 }
 352
 353 #ifdef _WIN32
 354 static ULARGE_INTEGER
 355 xgetfiletime(void)
 356 {
 357     ULARGE_INTEGER current_time;
 358     FILETIME current_time_ft;
 359
 360     /* Returns current time in UTC as a 64-bit value representing the number
 361      * of 100-nanosecond intervals since January 1, 1601 . */
 362     GetSystemTimePreciseAsFileTime(&current_time_ft);
 363     current_time.LowPart = current_time_ft.dwLowDateTime;
 364     current_time.HighPart = current_time_ft.dwHighDateTime;
 365
 366     return current_time;
 367 }
 368
 369 static int
 370 clock_gettime(clock_t id, struct timespec *ts)
 371 {
 372     if (id == CLOCK_MONOTONIC) {
 373         static LARGE_INTEGER freq;
 374         LARGE_INTEGER count;
 375         long long int ns;
 376
 377         if (!freq.QuadPart) {
 378             /* Number of counts per second. */
 379             QueryPerformanceFrequency(&freq);
 380         }
 381         /* Total number of counts from a starting point. */
 382         QueryPerformanceCounter(&count);
 383
 384         /* Total nano seconds from a starting point. */
 385         ns = (double) count.QuadPart / freq.QuadPart * 1000000000;
 386
 387         ts->tv_sec = count.QuadPart / freq.QuadPart;
 388         ts->tv_nsec = ns % 1000000000;
 389     } else if (id == CLOCK_REALTIME) {
 390         ULARGE_INTEGER current_time = xgetfiletime();
 391
 392         /* Time from Epoch to now. */
 393         ts->tv_sec = (current_time.QuadPart - unix_epoch.QuadPart) / 10000000;
 394         ts->tv_nsec = ((current_time.QuadPart - unix_epoch.QuadPart) %
 395                        10000000) * 100;
 396     } else {
 397         return -1;
 398     }
 399 }
 400 #endif /* _WIN32 */
 401
 402 void
 403 xgettimeofday(struct timeval *tv)
 404 {
 405     if (gettimeofday(tv, NULL) == -1) {
 406         VLOG_FATAL("gettimeofday failed (%s)", ovs_strerror(errno));
 407     }
 408 }
 409
 410 void
 411 xclock_gettime(clock_t id, struct timespec *ts)
 412 {
 413     if (clock_gettime(id, ts) == -1) {
 414         /* It seems like a bad idea to try to use vlog here because it is
 415          * likely to try to check the current time. */
 416         ovs_abort(errno, "xclock_gettime() failed");
 417     }
 418 }
 419
 420 /* Makes threads wait on timewarp_seq and be waken up when time is warped.
 421  * This function will be no-op unless timeval_dummy_register() is called. */
 422 void
 423 timewarp_wait(void)
 424 {
 425     if (timewarp_enabled) {
 426         uint64_t *last_seq = last_seq_get();
 427
 428         *last_seq = seq_read(timewarp_seq);
 429         seq_wait(timewarp_seq, *last_seq);
 430     }
 431 }
 432
 433 static long long int
 434 timeval_diff_msec(const struct timeval *a, const struct timeval *b)
 435 {
 436     return timeval_to_msec(a) - timeval_to_msec(b);
 437 }
 438
 439 static void
 440 timespec_add(struct timespec *sum,
 441              const struct timespec *a,
 442              const struct timespec *b)
 443 {
 444     struct timespec tmp;
 445
 446     tmp.tv_sec = a->tv_sec + b->tv_sec;
 447     tmp.tv_nsec = a->tv_nsec + b->tv_nsec;
 448     if (tmp.tv_nsec >= 1000 * 1000 * 1000) {
 449         tmp.tv_nsec -= 1000 * 1000 * 1000;
 450         tmp.tv_sec++;
 451     }
 452
 453     *sum = tmp;
 454 }
 455
 456 static bool
 457 is_warped(const struct clock *c)
 458 {
 459     bool warped;
 460
 461     ovs_mutex_lock(&c->mutex);
 462     warped = monotonic_clock.warp.tv_sec || monotonic_clock.warp.tv_nsec;
 463     ovs_mutex_unlock(&c->mutex);
 464
 465     return warped;
 466 }
 467
 468 static void
 469 log_poll_interval(long long int last_wakeup)
 470 {
 471     long long int interval = time_msec() - last_wakeup;
 472
 473     if (interval >= 1000 && !is_warped(&monotonic_clock)) {
 474         const struct rusage *last_rusage = get_recent_rusage();
 475         struct rusage rusage;
 476
 477         getrusage(RUSAGE_SELF, &rusage);
 478         VLOG_WARN("Unreasonably long %lldms poll interval"
 479                   " (%lldms user, %lldms system)",
 480                   interval,
 481                   timeval_diff_msec(&rusage.ru_utime,
 482                                     &last_rusage->ru_utime),
 483                   timeval_diff_msec(&rusage.ru_stime,
 484                                     &last_rusage->ru_stime));
 485         if (rusage.ru_minflt > last_rusage->ru_minflt
 486             || rusage.ru_majflt > last_rusage->ru_majflt) {
 487             VLOG_WARN("faults: %ld minor, %ld major",
 488                       rusage.ru_minflt - last_rusage->ru_minflt,
 489                       rusage.ru_majflt - last_rusage->ru_majflt);
 490         }
 491         if (rusage.ru_inblock > last_rusage->ru_inblock
 492             || rusage.ru_oublock > last_rusage->ru_oublock) {
 493             VLOG_WARN("disk: %ld reads, %ld writes",
 494                       rusage.ru_inblock - last_rusage->ru_inblock,
 495                       rusage.ru_oublock - last_rusage->ru_oublock);
 496         }
 497         if (rusage.ru_nvcsw > last_rusage->ru_nvcsw
 498             || rusage.ru_nivcsw > last_rusage->ru_nivcsw) {
 499             VLOG_WARN("context switches: %ld voluntary, %ld involuntary",
 500                       rusage.ru_nvcsw - last_rusage->ru_nvcsw,
 501                       rusage.ru_nivcsw - last_rusage->ru_nivcsw);
 502         }
 503         coverage_log();
 504     }
 505 }
 506 \f
 507 /* CPU usage tracking. */
 508
 509 struct cpu_usage {
 510     long long int when;         /* Time that this sample was taken. */
 511     unsigned long long int cpu; /* Total user+system CPU usage when sampled. */
 512 };
 513
 514 struct cpu_tracker {
 515     struct cpu_usage older;
 516     struct cpu_usage newer;
 517     int cpu_usage;
 518
 519     struct rusage recent_rusage;
 520 };
 521 DEFINE_PER_THREAD_MALLOCED_DATA(struct cpu_tracker *, cpu_tracker_var);
 522
 523 static struct cpu_tracker *
 524 get_cpu_tracker(void)
 525 {
 526     struct cpu_tracker *t = cpu_tracker_var_get();
 527     if (!t) {
 528         t = xzalloc(sizeof *t);
 529         t->older.when = LLONG_MIN;
 530         t->newer.when = LLONG_MIN;
 531         cpu_tracker_var_set_unsafe(t);
 532     }
 533     return t;
 534 }
 535
 536 static struct rusage *
 537 get_recent_rusage(void)
 538 {
 539     return &get_cpu_tracker()->recent_rusage;
 540 }
 541
 542 static int
 543 getrusage_thread(struct rusage *rusage OVS_UNUSED)
 544 {
 545 #ifdef RUSAGE_THREAD
 546     return getrusage(RUSAGE_THREAD, rusage);
 547 #else
 548     errno = EINVAL;
 549     return -1;
 550 #endif
 551 }
 552
 553 static void
 554 refresh_rusage(void)
 555 {
 556     struct cpu_tracker *t = get_cpu_tracker();
 557     struct rusage *recent_rusage = &t->recent_rusage;
 558
 559     if (!getrusage_thread(recent_rusage)) {
 560         long long int now = time_msec();
 561         if (now >= t->newer.when + 3 * 1000) {
 562             t->older = t->newer;
 563             t->newer.when = now;
 564             t->newer.cpu = (timeval_to_msec(&recent_rusage->ru_utime) +
 565                             timeval_to_msec(&recent_rusage->ru_stime));
 566
 567             if (t->older.when != LLONG_MIN && t->newer.cpu > t->older.cpu) {
 568                 unsigned int dividend = t->newer.cpu - t->older.cpu;
 569                 unsigned int divisor = (t->newer.when - t->older.when) / 100;
 570                 t->cpu_usage = divisor > 0 ? dividend / divisor : -1;
 571             } else {
 572                 t->cpu_usage = -1;
 573             }
 574         }
 575     }
 576 }
 577
 578 /* Returns an estimate of this process's CPU usage, as a percentage, over the
 579  * past few seconds of wall-clock time.  Returns -1 if no estimate is available
 580  * (which will happen if the process has not been running long enough to have
 581  * an estimate, and can happen for other reasons as well). */
 582 int
 583 get_cpu_usage(void)
 584 {
 585     return get_cpu_tracker()->cpu_usage;
 586 }
 587 \f
 588 /* Unixctl interface. */
 589
 590 /* "time/stop" stops the monotonic time returned by e.g. time_msec() from
 591  * advancing, except due to later calls to "time/warp". */
 592 static void
 593 timeval_stop_cb(struct unixctl_conn *conn,
 594                  int argc OVS_UNUSED, const char *argv[] OVS_UNUSED,
 595                  void *aux OVS_UNUSED)
 596 {
 597     ovs_mutex_lock(&monotonic_clock.mutex);
 598     atomic_store(&monotonic_clock.slow_path, true);
 599     monotonic_clock.stopped = true;
 600     xclock_gettime(monotonic_clock.id, &monotonic_clock.cache);
 601     ovs_mutex_unlock(&monotonic_clock.mutex);
 602
 603     unixctl_command_reply(conn, NULL);
 604 }
 605
 606 /* "time/warp MSECS" advances the current monotonic time by the specified
 607  * number of milliseconds.  Unless "time/stop" has also been executed, the
 608  * monotonic clock continues to tick forward at the normal rate afterward.
 609  *
 610  * Does not affect wall clock readings. */
 611 static void
 612 timeval_warp_cb(struct unixctl_conn *conn,
 613                 int argc OVS_UNUSED, const char *argv[], void *aux OVS_UNUSED)
 614 {
 615     struct timespec ts;
 616     int msecs;
 617
 618     msecs = atoi(argv[1]);
 619     if (msecs <= 0) {
 620         unixctl_command_reply_error(conn, "invalid MSECS");
 621         return;
 622     }
 623
 624     ts.tv_sec = msecs / 1000;
 625     ts.tv_nsec = (msecs % 1000) * 1000 * 1000;
 626
 627     ovs_mutex_lock(&monotonic_clock.mutex);
 628     atomic_store(&monotonic_clock.slow_path, true);
 629     timespec_add(&monotonic_clock.warp, &monotonic_clock.warp, &ts);
 630     ovs_mutex_unlock(&monotonic_clock.mutex);
 631     seq_change(timewarp_seq);
 632     poll(NULL, 0, 10); /* give threads (eg. monitor) some chances to run */
 633     unixctl_command_reply(conn, "warped");
 634 }
 635
 636 void
 637 timeval_dummy_register(void)
 638 {
 639     timewarp_enabled = true;
 640     unixctl_command_register("time/stop", "", 0, 0, timeval_stop_cb, NULL);
 641     unixctl_command_register("time/warp", "MSECS", 1, 1,
 642                              timeval_warp_cb, NULL);
 643 }
 644
 645
 646
 647 /* strftime() with an extension for high-resolution timestamps.  Any '#'s in
 648  * 'format' will be replaced by subseconds, e.g. use "%S.###" to obtain results
 649  * like "01.123".  */
 650 size_t
 651 strftime_msec(char *s, size_t max, const char *format,
 652               const struct tm_msec *tm)
 653 {
 654     size_t n;
 655
 656     n = strftime(s, max, format, &tm->tm);
 657     if (n) {
 658         char decimals[4];
 659         char *p;
 660
 661         sprintf(decimals, "%03d", tm->msec);
 662         for (p = strchr(s, '#'); p; p = strchr(p, '#')) {
 663             char *d = decimals;
 664             while (*p == '#')  {
 665                 *p++ = *d ? *d++ : '0';
 666             }
 667         }
 668     }
 669
 670     return n;
 671 }
 672
 673 struct tm_msec *
 674 localtime_msec(long long int now, struct tm_msec *result)
 675 {
 676   time_t now_sec = now / 1000;
 677   localtime_r(&now_sec, &result->tm);
 678   result->msec = now % 1000;
 679   return result;
 680 }
 681
 682 struct tm_msec *
 683 gmtime_msec(long long int now, struct tm_msec *result)
 684 {
 685   time_t now_sec = now / 1000;
 686   gmtime_r(&now_sec, &result->tm);
 687   result->msec = now % 1000;
 688   return result;
 689 }