Log more messages using logger().

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) {
+static void real_logger(int level, int priority, const char *message) {
-		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;
 	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:

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;

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",
+			logger(DEBUG_ALWAYS, LOG_ERR, "Couldn't detach from terminal: %s", strerror(errno));
-					strerror(errno));
 			return false;
 		}
 #else

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) {
+static bool error(sptps_t *s, int s_errno, const char *format, ...) {
-	fprintf(stderr, "SPTPS error: %s\n", msg);
+	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) {
+		if(seqno != s->inseqno)
-			fprintf(stderr, "Received invalid packet seqno: %d != %d\n", seqno, s->inseqno);
+			return error(s, EIO, "Invalid packet seqno: %d != %d", seqno, s->inseqno);
-			return error(s, EIO, "Invalid packet seqno");
-		}
 
 		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) {
+				if(s->farfuture++ < s->replaywin >> 2)
-					fprintf(stderr, "Packet is %d seqs in the future, dropped (%u)\n", seqno - s->inseqno, s->farfuture);
+					return error(s, EIO, "Packet is %d seqs in the future, dropped (%u)\n", seqno - s->inseqno, s->farfuture);
-					return false;
+
-				}
 				// 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))) {
+				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 error(s, EIO, "Received late or replayed packet, seqno %d, last received %d\n", seqno, s->inseqno);
-					return false;
-				}
 			} else {
 				// We missed some packets. Mark them in the bitmap as being late.
 				for(int i = s->inseqno; i < seqno; i++)

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);