From: Dave Hart Date: Sun, 14 Nov 2010 07:00:29 +0000 (+0000) Subject: [Bug 1681] More sntp logging cleanup. X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=1336341a5c1f554b6e6bd911649c8a3ebb7d2caf;p=thirdparty%2Fntp.git [Bug 1681] More sntp logging cleanup. bk: 4cdf890dk0i1ulY22lfNFpNYBb0BlQ --- diff --git a/ChangeLog b/ChangeLog index 7bdf9004a3..f850bb5ae5 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,6 @@ --- +* [Bug 1681] More sntp logging cleanup. * [Bug 1683] Non-localhost on loopback exempted from nic rules. --- diff --git a/include/ntp_syslog.h b/include/ntp_syslog.h index 38021e2516..e8443ec7c1 100644 --- a/include/ntp_syslog.h +++ b/include/ntp_syslog.h @@ -15,7 +15,9 @@ extern void msyslog(); # include extern int syslogit; -extern FILE *syslog_file; +extern int msyslog_term; /* duplicate to stdout/err */ +extern FILE *syslog_file; /* if syslogit is FALSE, log to + this file and not syslog */ #if defined(VMS) || defined (SYS_VXWORKS) #define LOG_EMERG 0 /* system is unusable */ diff --git a/libntp/msyslog.c b/libntp/msyslog.c index 43466b81c9..833a6cc1f0 100644 --- a/libntp/msyslog.c +++ b/libntp/msyslog.c @@ -13,34 +13,27 @@ #ifdef HAVE_UNISTD_H # include #endif - #include -#include "ntp_types.h" +#include "ntp.h" #include "ntp_string.h" #include "ntp_syslog.h" -#include "ntp_stdlib.h" #ifdef SYS_WINNT # include # include "..\ports\winnt\libntp\messages.h" #endif -int syslogit = 1; -FILE *syslog_file = NULL; +extern char * progname; -u_long ntp_syslogmask = ~ (u_long) 0; - -#ifdef SYS_WINNT -static char separator = '\\'; -#else -static char separator = '/'; -#endif /* SYS_WINNT */ -extern char *progname; +int syslogit = 1; +int msyslog_term = FALSE; /* duplicate to stdout/err */ +FILE * syslog_file = NULL; +u_long ntp_syslogmask = ~(u_long)0; /* Declare the local functions */ -void addto_syslog (int, char *); +void addto_syslog (int, const char *); void format_errmsg (char *, int, const char *, int); @@ -48,34 +41,57 @@ void format_errmsg (char *, int, const char *, int); * This routine adds the contents of a buffer to the log */ void -addto_syslog(int level, char * buf) +addto_syslog( + int level, + const char * buf + ) { - char *prog; - FILE *out_file = syslog_file; + static char * prevcall_progname; + static char * prog; + FILE * term_file; + int log_to_term; + const char * human_time; + + human_time = humanlogtime(); + log_to_term = msyslog_term; + /* setup program basename static var prog if needed */ + if (progname != prevcall_progname) { + prevcall_progname = progname; + prog = strrchr(progname, DIR_SEP); + if (prog != NULL) + prog++; + else + prog = progname; + } -#if !defined(VMS) && !defined (SYS_VXWORKS) +#if !defined(VMS) && !defined(SYS_VXWORKS) if (syslogit) - syslog(level, "%s", buf); + syslog(level, "%s", buf); else #endif /* VMS && SYS_VXWORKS*/ - { - out_file = syslog_file ? syslog_file: level <= LOG_ERR ? stderr : stdout; - /* syslog() provides the timestamp, so if we're not using - syslog, we must provide it. */ - prog = strrchr(progname, separator); - if (prog == NULL) - prog = progname; - else - prog++; - (void) fprintf(out_file, "%s ", humanlogtime ()); - (void) fprintf(out_file, "%s[%d]: %s", prog, (int)getpid(), buf); - fflush (out_file); + if (syslog_file != NULL) { + /* syslog() provides the timestamp, program, and pid */ + fprintf(syslog_file, "%s %s[%d]: %s", human_time, prog, + (int)getpid(), buf); + fflush(syslog_file); + } else { + log_to_term = TRUE; } #if DEBUG - if (debug && out_file != stdout && out_file != stderr) - printf("addto_syslog: %s\n", buf); + if (debug > 0) + log_to_term = TRUE; #endif + if (log_to_term) { + term_file = (level <= LOG_ERR) + ? stderr + : stdout; + fprintf(term_file, "%s %s[%d]: %s", human_time, prog, + (int)getpid(), buf); + fflush(term_file); + } } + + void format_errmsg(char *nfmt, int lennfmt, const char *fmt, int errval) { @@ -106,10 +122,8 @@ format_errmsg(char *nfmt, int lennfmt, const char *fmt, int errval) n += len; } } -#if !defined(VMS) - if (!syslogit) -#endif /* VMS */ - *n++ = '\n'; + if (n > nfmt && '\n' != *(n - 1)) + *n++ = '\n'; *n = '\0'; } @@ -152,6 +166,6 @@ void msyslog(int level, const char *fmt, ...) format_errmsg(nfmt, sizeof(nfmt), fmt, errval); vsnprintf(buf, sizeof(buf), nfmt, ap); - addto_syslog(level, buf); va_end(ap); + addto_syslog(level, buf); } diff --git a/sntp/crypto.c b/sntp/crypto.c index 0e582a9a27..7a46232919 100644 --- a/sntp/crypto.c +++ b/sntp/crypto.c @@ -122,9 +122,6 @@ auth_init( octothorpe = strchr(kbuf, '#'); if (octothorpe) *octothorpe = '\0'; -#ifdef DEBUG - printf("sntp auth_init: fgets: %s", kbuf); -#endif scan_cnt = sscanf(kbuf, "%d %9s %128s", &act->key_id, act->type, keystring); if (scan_cnt == 3) { int len = strlen(keystring); @@ -158,34 +155,15 @@ auth_init( prev->next = act; prev = act; key_cnt++; -#ifdef DEBUG - printf("sntp auth_init: key_id %i type %s with key %s\n", act->key_id, act->type, act->key_seq); -#endif } else { -#ifdef DEBUG - printf("sntp auth_init: scanf read %i items, doesn't look good, skipping line %i.\n", scan_cnt, line_cnt); -#endif + msyslog(LOG_DEBUG, "auth_init: scanf %d items, skipping line %d.", + scan_cnt, line_cnt); free(act); } line_cnt++; } fclose(keyf); -#ifdef DEBUG - STDLINE - printf("sntp auth_init: Read %i keys from file %s:\n", line_cnt, keyfile); - { - struct key *kptr = *keys; - register int a; - - for (a = 0; a < key_cnt; a++) { - printf("key_id %i type %s with key %s (key length: %i)\n", - kptr->key_id, kptr->type, kptr->key_seq, kptr->key_len); - kptr = kptr->next; - } - } - STDLINE -#endif key_ptr = *keys; return key_cnt; } diff --git a/sntp/kod_management.c b/sntp/kod_management.c index dfc989d14b..a0cd23c487 100644 --- a/sntp/kod_management.c +++ b/sntp/kod_management.c @@ -141,15 +141,8 @@ write_kod_db(void) } if (NULL == db_s) { - char msg[80]; - - snprintf(msg, sizeof(msg), - "Can't open KOD db file %s for writing!", - kod_db_file); -#ifdef DEBUG - debug_msg(msg); -#endif - log_msg(msg, LOG_WARNING | LOG_CONS); + msyslog(LOG_WARNING, "Can't open KOD db file %s for writing!", + kod_db_file); return; } @@ -193,14 +186,8 @@ kod_init_kod_db( db_s = fopen(db_file, "r"); if (NULL == db_s) { - char msg[80]; - - snprintf(msg, sizeof(msg), "kod_init_kod_db(): Cannot open KoD db file %s", db_file); -#ifdef DEBUG - debug_msg(msg); - printf("%s\n", msg); -#endif - log_msg(msg, LOG_WARNING | LOG_CONS); + msyslog(LOG_WARNING, "kod_init_kod_db(): Cannot open KoD db file %s", + db_file); return; } @@ -223,17 +210,11 @@ kod_init_kod_db( if ('\n' == fbuf[a]) { if (sepc != 2) { - if (strcmp(db_file, "/dev/null")) { - char msg[80]; - snprintf(msg, sizeof(msg), - "Syntax error in KoD db file %s in line %i (missing space)", - db_file, kod_db_cnt + 1); - #ifdef DEBUG - debug_msg(msg); - printf("%s\n", msg); - #endif - log_msg(msg, LOG_DEBUG | LOG_CONS); - } + if (strcmp(db_file, "/dev/null")) + msyslog(LOG_DEBUG, + "Syntax error in KoD db file %s in line %i (missing space)", + db_file, + kod_db_cnt + 1); fclose(db_s); return; } @@ -291,14 +272,9 @@ kod_init_kod_db( } if (ferror(db_s) || error) { - char msg[80]; - kod_db_cnt = b; - snprintf(msg, sizeof(msg), "An error occured while parsing the KoD db file %s", db_file); -#ifdef DEBUG - debug_msg(msg); -#endif - log_msg(msg, LOG_WARNING | LOG_CONS); + msyslog(LOG_WARNING, "An error occured while parsing the KoD db file %s", + db_file); fclose(db_s); return; diff --git a/sntp/log.c b/sntp/log.c index 5b39acc797..aad4949f3d 100644 --- a/sntp/log.c +++ b/sntp/log.c @@ -1,64 +1,59 @@ #include + #include "log.h" -#include "sntp-opts.h" -int init = 0; -int filelog = 0; +char *progname = "sntp"; /* for msyslog use too */ -FILE *log_file; +static void cleanup_log(void); +void +log_msg( + const char * text, + int type + ) +{ + msyslog(type, "%s", text); +} -void log_msg(char *message, int type) { - if (init) { - time_t cur_time = time(NULL); - char *timestamp = ctime(&cur_time); - fprintf(log_file, "%s: %s\n", timestamp, message); - fflush(log_file); - } else { - syslog(type, "%s", message); - } +void +debug_msg( + const char *text + ) +{ + msyslog(LOG_DEBUG, "%s", text); } -void debug_msg(char *message) { - if(HAVE_OPT(FILELOG)) { - time_t cur_time = time(NULL); - char *timestamp = ctime(&cur_time); - fprintf(stderr, "%s: %s\n", timestamp, message); - } - else { - syslog(LOG_DEBUG -#ifdef LOG_PERROR - | LOG_PERROR -#endif - | LOG_CONS, "%s", message); - } +void +init_logging(void) +{ + openlog(progname, LOG_PID | LOG_CONS, OPENLOG_FAC); + msyslog_term = TRUE; } -void init_log( + +void +open_logfile( const char *logfile ) { - char error_msg[80]; - - log_file = fopen(logfile, "a"); - if (log_file == NULL) { - filelog = 0; - - snprintf(error_msg, 80, "init_log(): Cannot open logfile %s", logfile); - debug_msg(error_msg); - + syslog_file = fopen(logfile, "a"); + if (syslog_file == NULL) { + msyslog(LOG_ERR, "sntp: Cannot open logfile %s", + logfile); return; - } else { - filelog = 1; - init = 1; - atexit(cleanup_log); } + syslogit = FALSE; + atexit(cleanup_log); } -void cleanup_log(void) { - init = 0; - fflush(log_file); - fclose(log_file); + +static void +cleanup_log(void) +{ + syslogit = TRUE; + fflush(syslog_file); + fclose(syslog_file); + syslog_file = NULL; } diff --git a/sntp/log.h b/sntp/log.h index b35d5e40b0..5786441df6 100644 --- a/sntp/log.h +++ b/sntp/log.h @@ -1,19 +1,28 @@ #ifndef LOG_H #define LOG_H -#include "config.h" - +#include "ntp.h" +#include "ntp_stdlib.h" #include #include #include #include #include +/* syslog as ntpd does, even though we are not a daemon */ +#ifdef LOG_NTP +# define OPENLOG_FAC LOG_NTP +#else +# ifndef LOG_DAEMON +# define LOG_DAEMON 0 +# endif +# define OPENLOG_FAC LOG_DAEMON +#endif -void log_msg(char *message, int type); -void debug_msg(char *message); +void log_msg(const char *text, int type); +void debug_msg(const char *text); -void init_log(const char *logfile); -void cleanup_log(void); +void init_logging(void); +void open_logfile(const char *logfile); #endif diff --git a/sntp/main.c b/sntp/main.c index b32800ced5..fc32170b60 100644 --- a/sntp/main.c +++ b/sntp/main.c @@ -1,5 +1,6 @@ -#include "main.h" +#include +#include "main.h" #include "kod_management.h" #include "networking.h" #include "utilities.h" @@ -49,6 +50,17 @@ sntp_main ( int bcast = 0; char *hostname; + optct = optionProcess(&sntpOptions, argc, argv); + argc -= optct; + argv += optct; + + /* Initialize logging system */ + init_logging(); + if (HAVE_OPT(FILELOG)) + open_logfile(OPT_ARG(FILELOG)); + + log_msg("Started sntp", LOG_INFO); + /* IPv6 available? */ if (isc_net_probeipv6() != ISC_R_SUCCESS) { ai_fam_pref = AF_INET; @@ -63,18 +75,8 @@ sntp_main ( ai_fam_pref = AF_INET6; } - optct = optionProcess(&sntpOptions, argc, argv); - argc -= optct; - argv += optct; - /* Parse config file if declared TODO */ - /* Initialize logging system */ - if (HAVE_OPT(FILELOG)) - init_log(OPT_ARG(FILELOG)); - - log_msg("Started sntp", LOG_CONS); - /* * If there's a specified KOD file init KOD system. If not use * default file. For embedded systems with no writable @@ -130,10 +132,8 @@ sntp_main ( if ((kodc = search_entry(hostname, &reason)) == 0) { if (is_reachable(ai)) { ow_ret = on_wire(ai, bcast ? bcastaddr[0] : NULL); - if (ow_ret < 0) - printf("on_wire failed for server %s!\n", hostname); - else - sync_data_suc = 1; + if (0 == ow_ret) + sync_data_suc = TRUE; } } else { printf("%d prior KoD%s for %s, skipping.\n", @@ -146,7 +146,11 @@ sntp_main ( freeaddrinfo(resh[c]); } free(resh); - return 0; + + if (sync_data_suc) + return 0; + else + return 1; } static union { @@ -228,7 +232,7 @@ handle_pkt ( "Received a KOD packet with code %c%c%c%c from %s, demobilizing all connections", ref[0], ref[1], ref[2], ref[3], hostname); - log_msg(log_str, LOG_WARNING | LOG_CONS); + log_msg(log_str, LOG_WARNING); free(log_str); break; @@ -255,7 +259,7 @@ handle_pkt ( ts_str = tv_to_str(&tv_dst); printf("%s ", ts_str); - if(offset > 0) + if (offset > 0) printf("+"); printf("%.*f", digits, offset); if (root_dispersion > 0.) @@ -263,7 +267,7 @@ handle_pkt ( printf("\n"); free(ts_str); - if(ENABLED_OPT(SETTOD) || ENABLED_OPT(ADJTIME)) + if (ENABLED_OPT(SETTOD) || ENABLED_OPT(ADJTIME)) return set_time(offset); return 0; @@ -332,7 +336,7 @@ offset_calculation ( *offset = (t21 + t34) / 2.; delta = t21 - t34; - if(ENABLED_OPT(NORMALVERBOSE)) + if (ENABLED_OPT(NORMALVERBOSE)) printf("sntp offset_calculation:\tt21: %.6f\t\t t34: %.6f\n\t\tdelta: %.6f\t offset: %.6f\n", t21, t34, delta, *offset); } @@ -344,22 +348,21 @@ on_wire ( struct addrinfo *bcast ) { - char logmsg[32 + INET6_ADDRSTRLEN]; char addr_buf[INET6_ADDRSTRLEN]; register int try; SOCKET sock; struct key *pkt_key = NULL; int key_id = 0; + struct timeval tv_xmt; + struct pkt x_pkt; + int error, rpktl, handle_pkt_res; + if (ENABLED_OPT(AUTHENTICATION)) { key_id = (int) OPT_ARG(AUTHENTICATION); get_key(key_id, &pkt_key); } - for(try=0; try<5; try++) { - struct timeval tv_xmt; - struct pkt x_pkt; - int error, rpktl, handle_pkt_res; - + for (try=0; try<5; try++) { memset(&r_pkt, 0, sizeof rbuf); error = GETTIMEOFDAY(&tv_xmt, (struct timezone *)NULL); @@ -389,12 +392,7 @@ on_wire ( } getnameinfo(host->ai_addr, host->ai_addrlen, addr_buf, sizeof(addr_buf), NULL, 0, NI_NUMERICHOST); - - snprintf(logmsg, sizeof(logmsg), "Received no useable packet from %s!", addr_buf); - log_msg(logmsg, LOG_DEBUG | LOG_CONS); - - if (ENABLED_OPT(NORMALVERBOSE)) - printf("sntp on_wire: Received no useable packet from %s!\n", addr_buf); + msyslog(LOG_DEBUG, "Received no useable packet from %s!", addr_buf); return -1; } @@ -408,13 +406,12 @@ set_li_vn_mode ( char mode ) { - - if(leap > 3) { + if (leap > 3) { debug_msg("set_li_vn_mode: leap > 3 using max. 3"); leap = 3; } - if(mode > 7) { + if (mode > 7) { debug_msg("set_li_vn_mode: mode > 7, using client mode 3"); mode = 3; } @@ -442,8 +439,7 @@ set_time( NORMALIZE_TIMEVAL(tp); if (SETTIMEOFDAY(&tp, NULL) < 0) { - printf("set_time: settimeofday(): Time not set: %s\n", - strerror(errno)); + msyslog(LOG_ERR, "Time not set: settimeofday(): %m"); return -1; } return 0; @@ -454,8 +450,7 @@ set_time( NORMALIZE_TIMEVAL(tp); if (ADJTIMEOFDAY(&tp, NULL) < 0) { - printf("set_time: adjtime(): Time not set: %s\n", - strerror(errno)); + msyslog(LOG_ERR, "Time not set: adjtime(): %m"); return -1; } return 0; diff --git a/sntp/main.h b/sntp/main.h index cbdeda2db4..e6965e1728 100644 --- a/sntp/main.h +++ b/sntp/main.h @@ -1,7 +1,6 @@ #ifndef MAIN_H #define MAIN_H -#include #include #include #include diff --git a/sntp/networking.c b/sntp/networking.c index 07928083ec..d17874eb90 100644 --- a/sntp/networking.c +++ b/sntp/networking.c @@ -42,15 +42,13 @@ resolve_hosts ( hints.ai_socktype = SOCK_DGRAM; error = getaddrinfo(hosts[a], "123", &hints, &tres[resc]); if (error) { - size_t msg_length = strlen(hosts[a]) + 21; - char *logmsg = (char *) emalloc(sizeof(char) * msg_length); - - snprintf(logmsg, msg_length, "Error looking up %s", hosts[a]); -#ifdef DEBUG - printf("%s\n", logmsg); -#endif - log_msg(logmsg, LOG_DEBUG | LOG_CONS); - free(logmsg); + msyslog(LOG_DEBUG, "Error looking up %s%s: %s", + (AF_UNSPEC == hints.ai_family) + ? "" + : (AF_INET == hints.ai_family) + ? "(A) " + : "(AAAA) ", + hosts[a], gai_strerror(error)); } else { #ifdef DEBUG for (dres = tres[resc]; dres; dres = dres->ai_next) { @@ -176,6 +174,9 @@ recv_bcst_data ( struct ip_mreq mdevadr; TYPEOF_IP_MULTICAST_LOOP mtrue = 1; #endif +#ifdef INCLUDE_IPV6_MULTICAST_SUPPORT + struct ipv6_mreq mdevadr6; +#endif setsockopt(rsock, SOL_SOCKET, SO_REUSEADDR, &btrue, sizeof(btrue)); if (IS_IPV4(sas)) { @@ -215,14 +216,13 @@ recv_bcst_data ( printf("sntp recv_bcst_data: Couldn't bind() address.\n"); } #ifdef INCLUDE_IPV6_MULTICAST_SUPPORT - struct ipv6_mreq mdevadr; if (setsockopt(rsock, IPPROTO_IPV6, IPV6_MULTICAST_LOOP, &btrue, sizeof (btrue)) < 0) { /* some error message regarding setting up multicast loop */ return BROADCAST_FAILED; } - memset(&mdevadr, 0, sizeof(mdevadr)); - mdevadr.ipv6mr_multiaddr = SOCK_ADDR6(sas); - if (!IN6_IS_ADDR_MULTICAST(&mdevadr.ipv6mr_multiaddr)) { + memset(&mdevadr6, 0, sizeof(mdevadr6)); + mdevadr6.ipv6mr_multiaddr = SOCK_ADDR6(sas); + if (!IN6_IS_ADDR_MULTICAST(&mdevadr6.ipv6mr_multiaddr)) { if (ENABLED_OPT(NORMALVERBOSE)) { buf = ss_to_str(sas); printf("sntp recv_bcst_data: %s is not a broad-/multicast address, aborting...\n", buf); @@ -230,7 +230,7 @@ recv_bcst_data ( } return BROADCAST_FAILED; } - if (setsockopt(rsock, IPPROTO_IPV6, IPV6_JOIN_GROUP, &mdevadr, sizeof(mdevadr)) < 0) { + if (setsockopt(rsock, IPPROTO_IPV6, IPV6_JOIN_GROUP, &mdevadr6, sizeof(mdevadr)) < 0) { if (ENABLED_OPT(NORMALVERBOSE)) { buf = ss_to_str(sas); printf("sntp recv_bcst_data: Couldn't join group for %s\n", buf); diff --git a/sntp/sntp-opts.def b/sntp/sntp-opts.def index 604123707a..7309df705e 100644 --- a/sntp/sntp-opts.def +++ b/sntp/sntp-opts.def @@ -194,7 +194,7 @@ run interactively from the command line or as a .I cron job. -NTP and SNTP are defined by draft-ietf-ntp-ntpv4-proto-13, which +NTP and SNTP are defined by RFC 5905, which obsoletes RFC 4330 and RFC 1305. _END_DETAIL; @@ -207,9 +207,7 @@ run as an interactive command or in a job. NTP (the Network Time Protocol) and SNTP (the Simple Network Time Protocol) -are defined and described by -draft-ietf-ntp-ntpv4-proto-13, -which should become a full RFC any month now. +are defined and described by RFC 5905. .PP The default is to write the estimated correct local date and time (i.e. not diff --git a/sntp/sntp.c b/sntp/sntp.c index 28101a03f5..bdc8e4e7fd 100644 --- a/sntp/sntp.c +++ b/sntp/sntp.c @@ -1,6 +1,7 @@ +#include + #include "main.h" -char *progname = "sntp"; /* for msyslog */ volatile int debug; int