From: Dave Hart Date: Tue, 1 Mar 2011 04:48:43 +0000 (+0000) Subject: libevent: When building on systems with CLOCK_MONOTONIC available, X-Git-Tag: NTP_4_2_7P135~1 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=7e2726b91af024a2883ed89473c64ad978204754;p=thirdparty%2Fntp.git libevent: When building on systems with CLOCK_MONOTONIC available, separate the internal timeline (possibly counting since system boot) from the gettimeofday() timeline in event_base cached timevals. Adds new event_base_tv_cached() to retrieve cached callback round start time on the internal timeline, and changes event_based_gettimeofday_cached() to always return times using the namesake timeline. This preserves the benefit of using the never- stepped monotonic clock for event timeouts while providing clients with times consistently using gettimeofday(). Correct event_base_gettimeofday_cached() workaround code in sntp to work with corrected libevent. Remove sntp l_fp_output() test now that it uses prettydate(). bk: 4d6c7aab7u--IikFUIPlBR6g54vUYw --- diff --git a/ChangeLog b/ChangeLog index b27476fee..d5a895d09 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,15 @@ +* libevent: When building on systems with CLOCK_MONOTONIC available, + separate the internal timeline (possibly counting since system boot) + from the gettimeofday() timeline in event_base cached timevals. Adds + new event_base_tv_cached() to retrieve cached callback round start + time on the internal timeline, and changes + event_based_gettimeofday_cached() to always return times using the + namesake timeline. This preserves the benefit of using the never- + stepped monotonic clock for event timeouts while providing clients + with times consistently using gettimeofday(). +* Correct event_base_gettimeofday_cached() workaround code in + sntp to work with corrected libevent. +* Remove sntp l_fp_output() test now that it uses prettydate(). * [Bug 1839] 4.2.7p131 installs libevent ev*.h headers. * Ensure CONFIG_SHELL is not empty before relying on it for #! scripts. (4.2.7p134) 2011/02/24 Released by Harlan Stenn diff --git a/libntp/socket.c b/libntp/socket.c index 957852079..ccea6f0fd 100644 --- a/libntp/socket.c +++ b/libntp/socket.c @@ -101,7 +101,7 @@ move_fd( socket_boundary = max(0, min(GETDTABLESIZE() - FD_CHUNK, min(FOPEN_MAX, FD_PREFERRED_SOCKBOUNDARY))); DPRINTF(1,("move_fd: estimated max descriptors: %d, " - "initial socket boundary: %d", + "initial socket boundary: %d\n", GETDTABLESIZE(), socket_boundary)); } @@ -124,11 +124,8 @@ move_fd( return fd; } socket_boundary = max(0, socket_boundary - FD_CHUNK); -#ifdef DEBUG - msyslog(LOG_DEBUG, - "move_fd: selecting new socket boundary: %d", - socket_boundary); -#endif + DPRINTF(1, ("move_fd: selecting new socket boundary: %d\n", + socket_boundary)); } while (socket_boundary > 0); #else NTP_REQUIRE((int)fd >= 0); diff --git a/libntp/work_fork.c b/libntp/work_fork.c index b7dc0ec99..f09a87dd2 100644 --- a/libntp/work_fork.c +++ b/libntp/work_fork.c @@ -450,7 +450,7 @@ fork_blocking_child( if (childpid) { /* this is the parent */ - DPRINTF(1, ("forked worker child (pid %d)", childpid)); + DPRINTF(1, ("forked worker child (pid %d)\n", childpid)); c->pid = childpid; c->ispipe = is_pipe; diff --git a/sntp/libevent/configure.in b/sntp/libevent/configure.in index e11562761..d856f0514 100644 --- a/sntp/libevent/configure.in +++ b/sntp/libevent/configure.in @@ -6,6 +6,10 @@ AC_INIT(event.c) AC_CONFIG_MACRO_DIR([m4]) AM_INIT_AUTOMAKE(libevent,2.0.10-stable-dev) +m4_ifdef( + [AM_SILENT_RULES], + [AM_SILENT_RULES([no])] +) AM_CONFIG_HEADER(config.h) AC_DEFINE(NUMERIC_VERSION, 0x02000a01, [Numeric representation of the version]) diff --git a/sntp/libevent/event-internal.h b/sntp/libevent/event-internal.h index e3da33da7..99f39ab3f 100644 --- a/sntp/libevent/event-internal.h +++ b/sntp/libevent/event-internal.h @@ -32,6 +32,7 @@ extern "C" { #endif #include "event2/event-config.h" +#include /* for CLOCK_MONOTONIC */ #include #include "event2/event_struct.h" #include "minheap-internal.h" @@ -235,8 +236,14 @@ struct event_base { /** Priority queue of events with timeouts. */ struct min_heap timeheap; - /** Stored timeval: used to avoid calling gettimeofday too often. */ + /** Stored timevals: used to avoid calling gettimeofday/getclock too + * often. tv_cache uses the internal timeline, which may be getclock + * CLOCK_MONOTONIC or gettimeofday. tod_tv_cache always is from + * gettimeofday. */ struct timeval tv_cache; +#if defined(_EVENT_HAVE_CLOCK_GETTIME) && defined(CLOCK_MONOTONIC) + struct timeval tod_tv_cache; +#endif #ifndef _EVENT_DISABLE_THREAD_SUPPORT /* threading support */ diff --git a/sntp/libevent/event.c b/sntp/libevent/event.c index fedb9c73c..b32492e60 100644 --- a/sntp/libevent/event.c +++ b/sntp/libevent/event.c @@ -361,6 +361,61 @@ gettime(struct event_base *base, struct timeval *tp) return (evutil_gettimeofday(tp, NULL)); } +/** Set 'tp' to the current time according to 'base'. We must hold the lock + * on 'base'. If there is a cached time, return it. Otherwise, use + * gettimeofday to find out the right time. + * Return 0 on success, -1 on failure. + */ +static int +gettod(struct event_base *base, struct timeval *tp) +{ + EVENT_BASE_ASSERT_LOCKED(base); + +#if defined(_EVENT_HAVE_CLOCK_GETTIME) && defined(CLOCK_MONOTONIC) + if (base->tod_tv_cache.tv_sec) { + *tp = base->tod_tv_cache; + return (0); + } +#else + if (base->tv_cache.tv_sec) { + *tp = base->tv_cache; + return (0); + } +#endif + + return (evutil_gettimeofday(tp, NULL)); +} + +int +event_base_tv_cached(struct event_base *base, struct timeval *tv) +{ + int r; + if (!base) { + base = current_base; + if (!current_base) { +#if defined(_EVENT_HAVE_CLOCK_GETTIME) && defined(CLOCK_MONOTONIC) + if (use_monotonic) { + struct timespec ts; + + if (clock_gettime(CLOCK_MONOTONIC, &ts) == -1) + return (-1); + + tv->tv_sec = ts.tv_sec; + tv->tv_usec = ts.tv_nsec / 1000; + return (0); + } +#endif + + return evutil_gettimeofday(tv, NULL); + } + } + + EVBASE_ACQUIRE_LOCK(base, th_base_lock); + r = gettime(base, tv); + EVBASE_RELEASE_LOCK(base, th_base_lock); + return r; +} + int event_base_gettimeofday_cached(struct event_base *base, struct timeval *tv) { @@ -372,7 +427,7 @@ event_base_gettimeofday_cached(struct event_base *base, struct timeval *tv) } EVBASE_ACQUIRE_LOCK(base, th_base_lock); - r = gettime(base, tv); + r = gettod(base, tv); EVBASE_RELEASE_LOCK(base, th_base_lock); return r; } @@ -382,15 +437,28 @@ static inline void clear_time_cache(struct event_base *base) { base->tv_cache.tv_sec = 0; +#if defined(_EVENT_HAVE_CLOCK_GETTIME) && defined(CLOCK_MONOTONIC) + base->tod_tv_cache.tv_sec = 0; +#endif } /** Replace the cached time in 'base' with the current time. */ static inline void update_time_cache(struct event_base *base) { - base->tv_cache.tv_sec = 0; - if (!(base->flags & EVENT_BASE_FLAG_NO_CACHE_TIME)) - gettime(base, &base->tv_cache); + clear_time_cache(base); + if (base->flags & EVENT_BASE_FLAG_NO_CACHE_TIME) + return; + +#if defined(_EVENT_HAVE_CLOCK_GETTIME) && defined(CLOCK_MONOTONIC) + gettod(base, &base->tod_tv_cache); + if (use_monotonic) + gettime(base, &base->tv_cache); + else + base->tv_cache = base->tod_tv_cache; +#else + gettime(base, &base->tv_cache); +#endif } struct event_base * @@ -1795,7 +1863,7 @@ event_pending(const struct event *ev, short event, struct timeval *tv) /* See if there is a timeout that we should report */ if (tv != NULL && (flags & event & EV_TIMEOUT)) { struct timeval tmp = ev->ev_timeout; - event_base_gettimeofday_cached(ev->ev_base, &now); + event_base_tv_cached(ev->ev_base, &now); tmp.tv_usec &= MICROSECONDS_MASK; evutil_timersub(&tmp, &now, &res); /* correctly remap to real time */ diff --git a/sntp/libevent/evthread.c b/sntp/libevent/evthread.c index 35f14b2b2..af142ec89 100644 --- a/sntp/libevent/evthread.c +++ b/sntp/libevent/evthread.c @@ -108,7 +108,10 @@ evthread_set_condition_callbacks(const struct evthread_condition_callbacks *cbs) return 0; } +#define DEBUG_LOCK_SIG 0xdeb0b10c + struct debug_lock { + unsigned signature; unsigned locktype; unsigned long held_by; /* XXXX if we ever use read-write locks, we will need a separate @@ -132,6 +135,7 @@ debug_lock_alloc(unsigned locktype) } else { result->lock = NULL; } + result->signature = DEBUG_LOCK_SIG; result->locktype = locktype; result->count = 0; result->held_by = 0; @@ -144,6 +148,7 @@ debug_lock_free(void *lock_, unsigned locktype) struct debug_lock *lock = lock_; EVUTIL_ASSERT(lock->count == 0); EVUTIL_ASSERT(locktype == lock->locktype); + EVUTIL_ASSERT(DEBUG_LOCK_SIG == lock->signature); if (_original_lock_fns.free) { _original_lock_fns.free(lock->lock, lock->locktype|EVTHREAD_LOCKTYPE_RECURSIVE); @@ -156,6 +161,7 @@ debug_lock_free(void *lock_, unsigned locktype) static void evthread_debug_lock_mark_locked(unsigned mode, struct debug_lock *lock) { + EVUTIL_ASSERT(DEBUG_LOCK_SIG == lock->signature); ++lock->count; if (!(lock->locktype & EVTHREAD_LOCKTYPE_RECURSIVE)) EVUTIL_ASSERT(lock->count == 1); @@ -188,12 +194,15 @@ debug_lock_lock(unsigned mode, void *lock_) static void evthread_debug_lock_mark_unlocked(unsigned mode, struct debug_lock *lock) { + EVUTIL_ASSERT(DEBUG_LOCK_SIG == lock->signature); if (lock->locktype & EVTHREAD_LOCKTYPE_READWRITE) EVUTIL_ASSERT(mode & (EVTHREAD_READ|EVTHREAD_WRITE)); else EVUTIL_ASSERT((mode & (EVTHREAD_READ|EVTHREAD_WRITE)) == 0); if (_evthread_id_fn) { - EVUTIL_ASSERT(lock->held_by == _evthread_id_fn()); + unsigned long me; + me = _evthread_id_fn(); + EVUTIL_ASSERT(lock->held_by == me); if (lock->count == 1) lock->held_by = 0; } @@ -217,6 +226,7 @@ debug_cond_wait(void *_cond, void *_lock, const struct timeval *tv) { int r; struct debug_lock *lock = _lock; + EVUTIL_ASSERT(DEBUG_LOCK_SIG == lock->signature); EVLOCK_ASSERT_LOCKED(_lock); evthread_debug_lock_mark_unlocked(0, lock); r = _original_cond_fns.wait_condition(_cond, lock->lock, tv); diff --git a/sntp/libevent/include/event2/event.h b/sntp/libevent/include/event2/event.h index 4b05b3253..c0f136ab5 100644 --- a/sntp/libevent/include/event2/event.h +++ b/sntp/libevent/include/event2/event.h @@ -764,13 +764,28 @@ void event_set_mem_functions( void event_base_dump_events(struct event_base *, FILE *); -/** Sets 'tv' to the current time (as returned by gettimeofday()), +/** Sets 'tv' to the internal time (used for timeout scheduling), looking at the cached value in 'base' if possible, and calling gettimeofday() or clock_gettime() as appropriate if there is no - cached time. + cached time. If clock_gettime(CLOCK_MONOTONIC) is being used + internally, the tv_sec of internal times represent system uptime + rather than time since UNIX epoch. + + Generally, this value will only be cached while actually + processing event callbacks, and may be very inaccurate if your + callbacks take a long time to execute. + + Returns 0 on success, negative on failure. + */ +int event_base_tv_cached(struct event_base *base, + struct timeval *tv); + +/** Sets 'tv' to the current time (as returned by gettimeofday()), + looking at the cached value in 'base' if possible, and calling + gettimeofday() if there is no cached time. Generally, this value will only be cached while actually - processing event callbacks, and may be very inaccuate if your + processing event callbacks, and may be very inaccurate if your callbacks take a long time to execute. Returns 0 on success, negative on failure. diff --git a/sntp/m4/ntp_libevent.m4 b/sntp/m4/ntp_libevent.m4 index 2720146b8..8d96757cf 100644 --- a/sntp/m4/ntp_libevent.m4 +++ b/sntp/m4/ntp_libevent.m4 @@ -46,7 +46,7 @@ case "$ntp_use_local_libevent" in ntp_use_local_libevent=no AC_MSG_NOTICE([Using the installed libevent]) CPPFLAGS_LIBEVENT=`$PKG_CONFIG --cflags-only-I libevent` - LDADD_LIBEVENT=`$PKG_CONFIG --libs-only-L libevent` + LDADD_LIBEVENT=`$PKG_CONFIG --libs libevent | sed 's:-levent::'` case "$LIBISC_PTHREADS_NOTHREADS" in pthreads) LDADD_LIBEVENT="$LDADD_LIBEVENT -levent_pthreads" @@ -102,6 +102,7 @@ case "$ntp_use_local_libevent" in ac_configure_args=" --disable-shared${ac_configure_args}" ac_configure_args=" --disable-libevent-regress${ac_configure_args}" ac_configure_args=" --disable-libevent-install${ac_configure_args}" + ac_configure_args=" --enable-silent-rules${ac_configure_args}" AC_CONFIG_SUBDIRS([libevent]) ;; *) diff --git a/sntp/m4/ntp_openssl.m4 b/sntp/m4/ntp_openssl.m4 index 27931d6ff..49ab0c912 100644 --- a/sntp/m4/ntp_openssl.m4 +++ b/sntp/m4/ntp_openssl.m4 @@ -224,7 +224,7 @@ NTPO_SAVED_CPPFLAGS="$CPPFLAGS" NTPO_SAVED_LIBS="$LIBS" # -# check for linking with -lcrypto failure, and try -lz -lcrypto. +# check for linking with -lcrypto failure, and try -lcrypto -lz. # Helps m68k-atari-mint # case "$ntp_openssl" in diff --git a/sntp/main.c b/sntp/main.c index bd2cd64b0..12499c636 100644 --- a/sntp/main.c +++ b/sntp/main.c @@ -3,6 +3,11 @@ #include #include +#include "ntp_workimpl.h" +#ifdef WORK_THREAD +# include +#endif + #include "main.h" #include "ntp_libopts.h" #include "kod_management.h" @@ -109,6 +114,7 @@ void sntp_libevent_log_cb(int, const char *); void set_li_vn_mode(struct pkt *spkt, char leap, char version, char mode); int sntp_main(int argc, char **argv); int set_time(double offset); +void dec_pending_ntp(const char *, sockaddr_u *); int libevent_version_ok(void); int gettimeofday_cached(struct event_base *b, struct timeval *tv); @@ -208,6 +214,12 @@ sntp_main ( event_set_log_callback(&sntp_libevent_log_cb); if (debug > 0) event_enable_debug_mode(); +#ifdef WORK_THREAD + evthread_use_pthreads(); + /* we use libevent from main thread only, locks should be academic */ + if (debug > 0) + evthread_enable_lock_debuging(); +#endif evcfg = event_config_new(); if (NULL == evcfg) { printf("%s: event_config_new() failed!\n", progname); @@ -216,6 +228,8 @@ sntp_main ( #ifndef HAVE_SOCKETPAIR event_config_require_features(evcfg, EV_FEATURE_FDS); #endif + /* all libevent calls are from main thread */ + /* event_config_set_flag(evcfg, EVENT_BASE_FLAG_NOLOCK); */ base = event_base_new_with_config(evcfg); event_config_free(evcfg); if (NULL == base) { @@ -519,6 +533,7 @@ queue_xmt( { sockaddr_u * dest; sent_pkt ** pkt_listp; + sent_pkt * match; xmt_ctx * xctx; struct timeval start_cb; struct timeval delay; @@ -529,6 +544,25 @@ queue_xmt( else pkt_listp = &v4_pkts_list; + /* reject attempts to add address already listed */ + for (match = *pkt_listp; match != NULL; match = match->link) { + if (ADDR_PORT_EQ(&spkt->addr, &match->addr)) { + if (strcasecmp(spkt->dctx->name, + match->dctx->name)) + printf("%s %s duplicate address from %s ignored.\n", + sptoa(&match->addr), + match->dctx->name, + spkt->dctx->name); + else + printf("%s %s, duplicate address ignored.\n", + sptoa(&match->addr), + match->dctx->name); + dec_pending_ntp(spkt->dctx->name, &spkt->addr); + free(spkt); + return; + } + } + LINK_SLIST(*pkt_listp, spkt, link); xctx = emalloc_zero(sizeof(*xctx)); @@ -587,7 +621,7 @@ xmt_timer_cb( gettimeofday_cached(base, &start_cb); if (xmt_q->sched <= start_cb.tv_sec) { UNLINK_HEAD_SLIST(x, xmt_q, link); - DPRINTF(2, ("xmt_timer_cb: at .%6.6u -> %s", + DPRINTF(2, ("xmt_timer_cb: at .%6.6u -> %s\n", (u_int)start_cb.tv_usec, stoa(&x->spkt->addr))); xmt(x); free(x); @@ -626,7 +660,7 @@ xmt( struct pkt x_pkt; int pkt_len; - if (0 != GETTIMEOFDAY(&tv_xmt, NULL)) { + if (0 != gettimeofday(&tv_xmt, NULL)) { msyslog(LOG_ERR, "xmt: gettimeofday() failed: %m"); exit(1); @@ -642,7 +676,7 @@ xmt( memcpy(&spkt->x_pkt, &x_pkt, min(sizeof(spkt->x_pkt), pkt_len)); spkt->stime = tv_xmt.tv_sec - JAN_1970; - DPRINTF(2, ("xmt: %lu.%6.6u %s %s\n", (u_long)tv_xmt.tv_sec, + DPRINTF(2, ("xmt: %lx.%6.6u %s %s\n", (u_long)tv_xmt.tv_sec, (u_int)tv_xmt.tv_usec, dctx->name, stoa(dst))); /* @@ -685,6 +719,22 @@ timeout_queries(void) } +void dec_pending_ntp( + const char * name, + sockaddr_u * server + ) +{ + if (n_pending_ntp > 0) { + --n_pending_ntp; + check_exit_conditions(); + } else { + INSIST(0 == n_pending_ntp); + DPRINTF(1, ("n_pending_ntp reached zero before dec for %s %s\n", + name, stoa(server))); + } +} + + void timeout_query( sent_pkt * spkt ) @@ -695,14 +745,7 @@ void timeout_query( server = &spkt->addr; msyslog(LOG_NOTICE, "%s %s no response after %d seconds", spkt->dctx->name, stoa(server), ucst_timeout); - if (n_pending_ntp > 0) { - --n_pending_ntp; - check_exit_conditions(); - } else { - INSIST(0 == n_pending_ntp); - DPRINTF(1, ("n_pending_ntp reached zero before dec for %s %s\n", - spkt->dctx->name, stoa(server))); - } + dec_pending_ntp(spkt->dctx->name, server); } @@ -753,7 +796,7 @@ sock_cb( { sockaddr_u sender; sockaddr_u * psau; - sent_pkt * pktlist; + sent_pkt ** p_pktlist; sent_pkt * spkt; int rpktl; int rc; @@ -783,11 +826,11 @@ sock_cb( } if (sock6 == fd) - pktlist = v6_pkts_list; + p_pktlist = &v6_pkts_list; else - pktlist = v4_pkts_list; + p_pktlist = &v4_pkts_list; - for (spkt = pktlist; spkt != NULL; spkt = spkt->link) { + for (spkt = *p_pktlist; spkt != NULL; spkt = spkt->link) { psau = &spkt->addr; if (SOCK_EQ(&sender, psau)) break; @@ -808,14 +851,8 @@ sock_cb( DPRINTF(2, ("sock_cb: process_pkt returned %d\n", rpktl)); /* If this is a Unicast packet, one down ... */ - if (!spkt->done && CTX_UCST & spkt->dctx->flags) { - if (n_pending_ntp > 0) { - --n_pending_ntp; - } else { - INSIST(0 == n_pending_ntp); - DPRINTF(1, ("n_pending_ntp reached zero before dec for %s %s\n", - spkt->dctx->name, stoa(&sender))); - } + if (!spkt->done && (CTX_UCST & spkt->dctx->flags)) { + dec_pending_ntp(spkt->dctx->name, &spkt->addr); spkt->done = TRUE; } @@ -1177,7 +1214,7 @@ handle_pkt( void -offset_calculation ( +offset_calculation( struct pkt *rpkt, int rpktl, struct timeval *tv_dst, @@ -1199,7 +1236,7 @@ offset_calculation ( NTOHL_FP(&rpkt->xmt, &p_xmt); *precision = LOGTOD(rpkt->precision); - DPRINTF(3, ("offset_calculation: precision: %f", *precision)); + DPRINTF(3, ("offset_calculation: precision: %f\n", *precision)); *root_dispersion = FPTOD(p_rdsp); @@ -1211,17 +1248,13 @@ offset_calculation ( pkt_output(rpkt, rpktl, stdout); printf("sntp offset_calculation: rpkt->reftime:\n"); - l_fp_output(&(rpkt->reftime), stdout); + l_fp_output(&p_ref, stdout); printf("sntp offset_calculation: rpkt->org:\n"); - l_fp_output(&(rpkt->org), stdout); - printf("sntp offset_calculation: rpkt->rec:\n"); - l_fp_output(&(rpkt->rec), stdout); - printf("sntp offset_calculation: rpkt->rec:\n"); - l_fp_output_bin(&(rpkt->rec), stdout); + l_fp_output(&p_org, stdout); printf("sntp offset_calculation: rpkt->rec:\n"); - l_fp_output_dec(&(rpkt->rec), stdout); + l_fp_output(&p_rec, stdout); printf("sntp offset_calculation: rpkt->xmt:\n"); - l_fp_output(&(rpkt->xmt), stdout); + l_fp_output(&p_xmt, stdout); } #endif @@ -1237,7 +1270,9 @@ offset_calculation ( *offset = (t21 + t34) / 2.; delta = t21 - t34; - DPRINTF(3, ("sntp offset_calculation:\tt21: %.6f\t\t t34: %.6f\n\t\tdelta: %.6f\t offset: %.6f\n", t21, t34, delta, *offset)); + DPRINTF(3, ("sntp offset_calculation:\trec - org t21: %.6f\n" + "\txmt - dst t34: %.6f\tdelta: %.6f\toffset: %.6f\n", + t21, t34, delta, *offset)); } @@ -1348,7 +1383,27 @@ libevent_version_ok(void) return 1; } - +/* + * gettimeofday_cached() + * + * Clones the event_base_gettimeofday_cached() interface but ensures the + * times are always on the gettimeofday() 1970 scale. Older libevent 2 + * sometimes used gettimeofday(), sometimes the since-system-start + * clock_gettime(CLOCK_MONOTONIC), depending on the platform. + * + * It is not cleanly possible to tell which timescale older libevent is + * using. + * + * The strategy involves 1 hour thresholds chosen to be far longer than + * the duration of a round of libevent callbacks, which share a cached + * start-of-round time. First compare the last cached time with the + * current gettimeofday() time. If they are within one hour, libevent + * is using the proper timescale so leave the offset 0. Otherwise, + * compare libevent's cached time and the current time on the monotonic + * scale. If they are within an hour, libevent is using the monotonic + * scale so calculate the offset to add to such times to bring them to + * gettimeofday()'s scale. + */ int gettimeofday_cached( struct event_base * b, @@ -1366,7 +1421,8 @@ gettimeofday_cached( struct timespec ts; struct timeval mono; struct timeval diff; - int rc; + int cgt_rc; + int gtod_rc; event_base_gettimeofday_cached(b, &latest); if (b == cached_b && @@ -1377,25 +1433,41 @@ gettimeofday_cached( cached = latest; cached_b = b; if (!offset_ready) { - rc = clock_gettime(CLOCK_MONOTONIC, &ts); - if (0 == rc) { - rc = evutil_gettimeofday(&systemt, NULL); - if (0 != rc) { - msyslog(LOG_ERR, - "%s: gettimeofday() error %m", - progname); - exit(1); - } + cgt_rc = clock_gettime(CLOCK_MONOTONIC, &ts); + gtod_rc = gettimeofday(&systemt, NULL); + if (0 != gtod_rc) { + msyslog(LOG_ERR, + "%s: gettimeofday() error %m", + progname); + exit(1); + } + timeval_sub(&diff, &systemt, &latest); + if (debug > 1) + printf("system minus cached %+ld.%06ld\n", + (long)diff.tv_sec, diff.tv_usec); + if (0 != cgt_rc || labs((long)diff.tv_sec) < 3600) { + /* + * Either use_monotonic == 0, or this libevent + * has been repaired. Leave offset at zero. + */ + } else { mono.tv_sec = ts.tv_sec; mono.tv_usec = ts.tv_nsec / 1000; - evutil_timersub(&systemt, &mono, &diff); - if (labs((long)diff.tv_sec) > 3600) { - offset = diff; + timeval_sub(&diff, &latest, &mono); + if (debug > 1) + printf("cached minus monotonic %+ld.%06ld\n", + (long)diff.tv_sec, diff.tv_usec); + if (labs((long)diff.tv_sec) < 3600) { + /* older libevent2 using monotonic */ + timeval_sub(&offset, &systemt, &mono); + msyslog(LOG_NOTICE, + "Offsetting CLOCK_MONOTONIC times by %+ld.%06ld\n", + (long)offset.tv_sec, offset.tv_usec); } } offset_ready = TRUE; } - evutil_timeradd(&cached, &offset, &adj_cached); + timeval_add(&adj_cached, &cached, &offset); *caller_tv = adj_cached; return 0; diff --git a/sntp/networking.c b/sntp/networking.c index bf213a127..f3f966705 100644 --- a/sntp/networking.c +++ b/sntp/networking.c @@ -82,12 +82,19 @@ process_pkt ( const char * func_name ) { - unsigned int key_id = 0; - struct key *pkt_key = NULL; - int is_authentic; - unsigned int exten_words, exten_words_used = 0; - int mac_size; + u_int key_id; + struct key * pkt_key; + int is_authentic; + u_int exten_words; + u_int exten_words_used; + int mac_size; + u_int exten_len; + l_fp sent_xmt; + l_fp resp_org; + key_id = 0; + pkt_key = NULL; + exten_words_used = 0; is_authentic = (HAVE_OPT(AUTHENTICATION)) ? 0 : -1; /* @@ -105,15 +112,13 @@ process_pkt ( if (pkt_len < LEN_PKT_NOMAC || (pkt_len & 3) != 0) { unusable: msyslog(LOG_ERR, - "%s: Funny packet length: %i. Discarding packet.", + "%s: Incredible packet length: %d. Discarding.", func_name, pkt_len); return PACKET_UNUSEABLE; } /* skip past the extensions, if any */ exten_words = ((unsigned)pkt_len - LEN_PKT_NOMAC) >> 2; while (exten_words > 6) { - unsigned int exten_len; - exten_len = ntohl(rpkt->exten[exten_words_used]) & 0xffff; exten_len = (exten_len + 7) >> 2; /* convert to words, add 1 */ if (exten_len > exten_words || exten_len < 5) @@ -188,7 +193,7 @@ unusable: if (PKT_VERSION(rpkt->li_vn_mode) < NTP_OLDVERSION || PKT_VERSION(rpkt->li_vn_mode) > NTP_VERSION) { msyslog(LOG_ERR, - "%s: Packet shows wrong version (%i)", + "%s: Packet shows wrong version (%d)", func_name, PKT_VERSION(rpkt->li_vn_mode)); return SERVER_UNUSEABLE; } @@ -196,7 +201,7 @@ unusable: if (PKT_MODE(rpkt->li_vn_mode) != mode && PKT_MODE(rpkt->li_vn_mode) != MODE_PASSIVE) { msyslog(LOG_ERR, - "%s: mode %d stratum %i", func_name, + "%s: mode %d stratum %d", func_name, PKT_MODE(rpkt->li_vn_mode), rpkt->stratum); return SERVER_UNUSEABLE; } @@ -204,11 +209,11 @@ unusable: if (STRATUM_PKT_UNSPEC == rpkt->stratum) { char *ref_char; - DPRINTF(1, ("%s: Stratum unspecified, going to check for KOD (stratum: %i)\n", - func_name, rpkt->stratum)); + DPRINTF(1, ("%s: Stratum unspecified, going to check for KOD (stratum: %d)\n", + func_name, rpkt->stratum)); ref_char = (char *) &rpkt->refid; DPRINTF(1, ("%s: Packet refid: %c%c%c%c\n", func_name, - ref_char[0], ref_char[1], ref_char[2], ref_char[3])); + ref_char[0], ref_char[1], ref_char[2], ref_char[3])); /* If it's a KOD packet we'll just use the KOD information */ if (ref_char[0] != 'X') { if (strncmp(ref_char, "DENY", 4) == 0) @@ -226,7 +231,8 @@ unusable: /* If the server is not synced it's not really useable for us */ if (LEAP_NOTINSYNC == PKT_LEAP(rpkt->li_vn_mode)) { msyslog(LOG_ERR, - "%s: Server not in sync, skipping this server", func_name); + "%s: %s not in sync, skipping this server", + func_name, stoa(sender)); return SERVER_UNUSEABLE; } @@ -234,17 +240,17 @@ unusable: * Decode the org timestamp and make sure we're getting a response * to our last request, but only if we're not in broadcast mode. */ -#ifdef DEBUG - if (debug > 2) { - printf("rpkt->org:\n"); - l_fp_output(&rpkt->org, stdout); - printf("spkt->xmt:\n"); - l_fp_output(&spkt->xmt, stdout); - } -#endif - if (mode != MODE_BROADCAST && !L_ISEQU(&rpkt->org, &spkt->xmt)) { + if (MODE_BROADCAST == mode) + return pkt_len; + + if (!L_ISEQU(&rpkt->org, &spkt->xmt)) { + NTOHL_FP(&rpkt->org, &resp_org); + NTOHL_FP(&spkt->xmt, &sent_xmt); msyslog(LOG_ERR, - "process_pkt: pkt.org and peer.xmt differ"); + "%s response org expected to match sent xmt", + stoa(sender)); + msyslog(LOG_ERR, "resp org: %s\n", prettydate(&resp_org)); + msyslog(LOG_ERR, "sent xmt: %s\n", prettydate(&sent_xmt)); return PACKET_UNUSEABLE; } diff --git a/sntp/tests/Makefile.am b/sntp/tests/Makefile.am index 5ccee063e..93f84c833 100644 --- a/sntp/tests/Makefile.am +++ b/sntp/tests/Makefile.am @@ -46,7 +46,6 @@ dist_check_SCRIPTS = test-driver EXTRA_DIST = \ data/debug-input-lfp-bin \ data/debug-input-lfp-dec \ - data/debug-input-lfp-hex \ data/debug-input-pkt \ data/key-test-ascii \ data/key-test-comments \ @@ -67,7 +66,6 @@ CLEANFILES = \ data/debug-output-lfp-dec \ data/kod-output-blank \ data/debug-output-lfp-bin \ - data/debug-output-lfp-hex \ $(NULL) LDADD = \ diff --git a/sntp/tests/data/debug-input-lfp-hex b/sntp/tests/data/debug-input-lfp-hex deleted file mode 100644 index 3355c4814..000000000 --- a/sntp/tests/data/debug-input-lfp-hex +++ /dev/null @@ -1,3 +0,0 @@ --------------------------------------------------------------------------------- -0: 0 1: 0 2: 0 3: 7f 4: 7f 5: ff 6: ff 7: ff --------------------------------------------------------------------------------- diff --git a/sntp/tests/packetProcessing.cpp b/sntp/tests/packetProcessing.cpp index 02a7e5e6b..322b8938e 100644 --- a/sntp/tests/packetProcessing.cpp +++ b/sntp/tests/packetProcessing.cpp @@ -278,12 +278,12 @@ TEST_F(packetProcessingTest, AcceptNoSentPacketBroadcastMode) { ASSERT_FALSE(ENABLED_OPT(AUTHENTICATION)); testpkt.li_vn_mode = PKT_LI_VN_MODE(LEAP_NOWARNING, - NTP_VERSION, - MODE_BROADCAST); + NTP_VERSION, + MODE_BROADCAST); EXPECT_EQ(LEN_PKT_NOMAC, - process_pkt(&testpkt, &testsock, LEN_PKT_NOMAC, - MODE_BROADCAST, NULL, "UnitTest")); + process_pkt(&testpkt, &testsock, LEN_PKT_NOMAC, + MODE_BROADCAST, NULL, "UnitTest")); } TEST_F(packetProcessingTest, CorrectUnauthenticatedPacket) { diff --git a/sntp/tests/utilities.cpp b/sntp/tests/utilities.cpp index bd4c58b20..7db611b5a 100644 --- a/sntp/tests/utilities.cpp +++ b/sntp/tests/utilities.cpp @@ -142,22 +142,6 @@ TEST_F(debugUtilitiesTest, PktOutput) { FinishDebugTest(CreatePath("debug-input-pkt", INPUT_DIR), filename); } -TEST_F(debugUtilitiesTest, LfpOutputHexFormat) { - string filename = CreatePath("debug-output-lfp-hex", OUTPUT_DIR); - InitDebugTest(filename); - - l_fp test; - test.l_ui = 127; // 0x7f - test.l_uf = 2147483647; // 0x7fffffff - - l_fp network; - HTONL_FP(&test, &network); - - l_fp_output(&network, outputFile); - - FinishDebugTest(CreatePath("debug-input-lfp-hex", INPUT_DIR), filename); -} - TEST_F(debugUtilitiesTest, LfpOutputBinaryFormat) { string filename = CreatePath("debug-output-lfp-bin", OUTPUT_DIR); InitDebugTest(filename); diff --git a/sntp/utilities.c b/sntp/utilities.c index 2ce9b8e49..a65af2913 100644 --- a/sntp/utilities.c +++ b/sntp/utilities.c @@ -33,21 +33,12 @@ pkt_output ( /* Output a long floating point value in hex in the style described above */ void -l_fp_output ( - l_fp *ts, - FILE *output - ) +l_fp_output( + l_fp * ts, + FILE * output + ) { - register int a; - - fprintf(output, HLINE); - - for(a=0; a<8; a++) - fprintf(output, "%i: %x \t", a, ((unsigned char *) ts)[a]); - - fprintf(output, "\n"); - fprintf(output, HLINE); - + fprintf(output, "%s\n", prettydate(ts)); } /* Output a long floating point value in binary in the style described above