From 40ed0c07dd3d4667054b0f5952b89ee39686493b Mon Sep 17 00:00:00 2001 From: Guus Sliepen Date: Sun, 14 Oct 2012 15:37:24 +0200 Subject: [PATCH] Log more messages using logger(). --- src/logger.c | 139 ++++++++++++++++++++++++++++-------------------- src/net_setup.c | 4 +- src/process.c | 3 +- src/sptps.c | 49 +++++++++++------ src/sptps.h | 3 ++ 5 files changed, 120 insertions(+), 78 deletions(-) diff --git a/src/logger.c b/src/logger.c index e0a42d5b..123f0229 100644 --- a/src/logger.c +++ b/src/logger.c @@ -25,6 +25,7 @@ #include "logger.h" #include "connection.h" #include "control_common.h" +#include "sptps.h" debug_t debug_level = DEBUG_NOTHING; static logmode_t logmode = LOGMODE_STDERR; @@ -37,60 +38,9 @@ static HANDLE loghandle = NULL; static const char *logident = NULL; bool logcontrol = false; -void openlogger(const char *ident, logmode_t mode) { - logident = ident; - logmode = mode; - switch(mode) { - case LOGMODE_STDERR: - logpid = getpid(); - break; - case LOGMODE_FILE: - logpid = getpid(); - logfile = fopen(logfilename, "a"); - if(!logfile) { - fprintf(stderr, "Could not open log file %s: %s\n", logfilename, strerror(errno)); - logmode = LOGMODE_NULL; - } - break; - case LOGMODE_SYSLOG: -#ifdef HAVE_MINGW - loghandle = RegisterEventSource(NULL, logident); - if(!loghandle) { - fprintf(stderr, "Could not open log handle!"); - logmode = LOGMODE_NULL; - } - break; -#else -#ifdef HAVE_SYSLOG_H - openlog(logident, LOG_CONS | LOG_PID, LOG_DAEMON); - break; -#endif -#endif - case LOGMODE_NULL: - break; - } -} - -void reopenlogger() { - if(logmode != LOGMODE_FILE) - return; - - fflush(logfile); - FILE *newfile = fopen(logfilename, "a"); - if(!newfile) { - logger(DEBUG_ALWAYS, LOG_ERR, "Unable to reopen log file %s: %s", logfilename, strerror(errno)); - return; - } - fclose(logfile); - logfile = newfile; -} - -void logger(int level, int priority, const char *format, ...) { - va_list ap; - int len; +static void real_logger(int level, int priority, const char *message) { char timestr[32] = ""; - char message[1024] = ""; time_t now; static bool suppress = false; @@ -101,13 +51,6 @@ void logger(int level, int priority, const char *format, ...) { if(!logcontrol && (level > debug_level || logmode == LOGMODE_NULL)) return; - va_start(ap, format); - len = vsnprintf(message, sizeof message, format, ap); - va_end(ap); - - if(len > 0 && len < sizeof message && message[len - 1] == '\n') - message[len - 1] = 0; - if(level <= debug_level) { switch(logmode) { case LOGMODE_STDERR: @@ -154,6 +97,84 @@ void logger(int level, int priority, const char *format, ...) { } } +void logger(int level, int priority, const char *format, ...) { + va_list ap; + char message[1024] = ""; + + va_start(ap, format); + int len = vsnprintf(message, sizeof message, format, ap); + va_end(ap); + + if(len > 0 && len < sizeof message && message[len - 1] == '\n') + message[len - 1] = 0; + + real_logger(level, priority, message); +} + +static void sptps_logger(sptps_t *s, int s_errno, const char *format, va_list ap) { + char message[1024] = ""; + int len = vsnprintf(message, sizeof message, format, ap); + if(len > 0 && len < sizeof message && message[len - 1] == '\n') + message[len - 1] = 0; + + real_logger(DEBUG_ALWAYS, LOG_ERR, message); +} + +void openlogger(const char *ident, logmode_t mode) { + logident = ident; + logmode = mode; + + switch(mode) { + case LOGMODE_STDERR: + logpid = getpid(); + break; + case LOGMODE_FILE: + logpid = getpid(); + logfile = fopen(logfilename, "a"); + if(!logfile) { + fprintf(stderr, "Could not open log file %s: %s\n", logfilename, strerror(errno)); + logmode = LOGMODE_NULL; + } + break; + case LOGMODE_SYSLOG: +#ifdef HAVE_MINGW + loghandle = RegisterEventSource(NULL, logident); + if(!loghandle) { + fprintf(stderr, "Could not open log handle!"); + logmode = LOGMODE_NULL; + } + break; +#else +#ifdef HAVE_SYSLOG_H + openlog(logident, LOG_CONS | LOG_PID, LOG_DAEMON); + break; +#endif +#endif + case LOGMODE_NULL: + break; + } + + if(logmode != LOGMODE_NULL) + sptps_log = sptps_logger; + else + sptps_log = sptps_log_quiet; +} + +void reopenlogger() { + if(logmode != LOGMODE_FILE) + return; + + fflush(logfile); + FILE *newfile = fopen(logfilename, "a"); + if(!newfile) { + logger(DEBUG_ALWAYS, LOG_ERR, "Unable to reopen log file %s: %s", logfilename, strerror(errno)); + return; + } + fclose(logfile); + logfile = newfile; +} + + void closelogger(void) { switch(logmode) { case LOGMODE_FILE: diff --git a/src/net_setup.c b/src/net_setup.c index b2cfe28f..95ff5c3e 100644 --- a/src/net_setup.c +++ b/src/net_setup.c @@ -359,12 +359,12 @@ char *get_name(void) { char *envname = getenv(name + 1); if(!envname) { if(strcmp(name + 1, "HOST")) { - fprintf(stderr, "Invalid Name: environment variable %s does not exist\n", name + 1); + logger(DEBUG_ALWAYS, LOG_ERR, "Invalid Name: environment variable %s does not exist\n", name + 1); return false; } envname = alloca(32); if(gethostname(envname, 32)) { - fprintf(stderr, "Could not get hostname: %s\n", strerror(errno)); + logger(DEBUG_ALWAYS, LOG_ERR, "Could not get hostname: %s\n", strerror(errno)); return false; } envname[31] = 0; diff --git a/src/process.c b/src/process.c index 680d3179..19c05829 100644 --- a/src/process.c +++ b/src/process.c @@ -204,8 +204,7 @@ bool detach(void) { if(do_detach) { #ifndef HAVE_MINGW if(daemon(0, 0)) { - fprintf(stderr, "Couldn't detach from terminal: %s", - strerror(errno)); + logger(DEBUG_ALWAYS, LOG_ERR, "Couldn't detach from terminal: %s", strerror(errno)); return false; } #else diff --git a/src/sptps.c b/src/sptps.c index 78001400..5a99055d 100644 --- a/src/sptps.c +++ b/src/sptps.c @@ -25,6 +25,7 @@ #include "digest.h" #include "ecdh.h" #include "ecdsa.h" +#include "logger.h" #include "prf.h" #include "sptps.h" @@ -50,13 +51,36 @@ unsigned int sptps_replaywin = 16; Make sure ECC operations are fixed time (aka prevent side-channel attacks). */ +void sptps_log_quiet(sptps_t *s, int s_errno, const char *format, va_list ap) { +} + +void sptps_log_stderr(sptps_t *s, int s_errno, const char *format, va_list ap) { + vfprintf(stderr, format, ap); + fputc('\n', stderr); +} + +void (*sptps_log)(sptps_t *s, int s_errno, const char *format, va_list ap) = sptps_log_stderr; + // Log an error message. -static bool error(sptps_t *s, int s_errno, const char *msg) { - fprintf(stderr, "SPTPS error: %s\n", msg); +static bool error(sptps_t *s, int s_errno, const char *format, ...) { + if(format) { + va_list ap; + va_start(ap, format); + sptps_log(s, s_errno, format, ap); + va_end(ap); + } + errno = s_errno; return false; } +static void warning(sptps_t *s, const char *format, ...) { + va_list ap; + va_start(ap, format); + sptps_log(s, 0, format, ap); + va_end(ap); +} + // Send a record (datagram version, accepts all record types, handles encryption and authentication). static bool send_record_priv_datagram(sptps_t *s, uint8_t type, const char *data, uint16_t len) { char buffer[len + 23UL]; @@ -402,10 +426,8 @@ static bool sptps_receive_data_datagram(sptps_t *s, const char *data, size_t len seqno = ntohl(seqno); if(!s->instate) { - if(seqno != s->inseqno) { - fprintf(stderr, "Received invalid packet seqno: %d != %d\n", seqno, s->inseqno); - return error(s, EIO, "Invalid packet seqno"); - } + if(seqno != s->inseqno) + return error(s, EIO, "Invalid packet seqno: %d != %d", seqno, s->inseqno); s->inseqno = seqno + 1; @@ -426,19 +448,16 @@ static bool sptps_receive_data_datagram(sptps_t *s, const char *data, size_t len if(seqno != s->inseqno) { if(seqno >= s->inseqno + s->replaywin * 8) { // Prevent packets that jump far ahead of the queue from causing many others to be dropped. - if(s->farfuture++ < s->replaywin >> 2) { - fprintf(stderr, "Packet is %d seqs in the future, dropped (%u)\n", seqno - s->inseqno, s->farfuture); - return false; - } + if(s->farfuture++ < s->replaywin >> 2) + return error(s, EIO, "Packet is %d seqs in the future, dropped (%u)\n", seqno - s->inseqno, s->farfuture); + // Unless we have seen lots of them, in which case we consider the others lost. - fprintf(stderr, "Lost %d packets\n", seqno - s->inseqno); + warning(s, "Lost %d packets\n", seqno - s->inseqno); memset(s->late, 0, s->replaywin); } else if (seqno < s->inseqno) { // If the sequence number is farther in the past than the bitmap goes, or if the packet was already received, drop it. - if((s->inseqno >= s->replaywin * 8 && seqno < s->inseqno - s->replaywin * 8) || !(s->late[(seqno / 8) % s->replaywin] & (1 << seqno % 8))) { - fprintf(stderr, "Received late or replayed packet, seqno %d, last received %d\n", seqno, s->inseqno); - return false; - } + if((s->inseqno >= s->replaywin * 8 && seqno < s->inseqno - s->replaywin * 8) || !(s->late[(seqno / 8) % s->replaywin] & (1 << seqno % 8))) + return error(s, EIO, "Received late or replayed packet, seqno %d, last received %d\n", seqno, s->inseqno); } else { // We missed some packets. Mark them in the bitmap as being late. for(int i = s->inseqno; i < seqno; i++) diff --git a/src/sptps.h b/src/sptps.h index 5037c46f..2159028d 100644 --- a/src/sptps.h +++ b/src/sptps.h @@ -81,6 +81,9 @@ typedef struct sptps { } sptps_t; extern unsigned int sptps_replaywin; +extern void sptps_log_quiet(sptps_t *s, int s_errno, const char *format, va_list ap); +extern void sptps_log_stderr(sptps_t *s, int s_errno, const char *format, va_list ap); +extern void (*sptps_log)(sptps_t *s, int s_errno, const char *format, va_list ap); extern bool sptps_start(sptps_t *s, void *handle, bool initiator, bool datagram, ecdsa_t mykey, ecdsa_t hiskey, const char *label, size_t labellen, send_data_t send_data, receive_record_t receive_record); extern bool sptps_stop(sptps_t *s); extern bool sptps_send_record(sptps_t *s, uint8_t type, const char *data, uint16_t len); -- 2.20.1