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