Added realtime clock support, and better timestamping.

The realtime clock is not (yet) exposed for user applications, but it
is used for logging timestamps accurately.

6 files changed, 125 insertions, 36 deletions

diff --git a/src/core/log.c b/src/core/log.c
index b560f6c7..cef3169c 100644
--- a/src/core/log.c
+++ b/src/core/log.c
@@ -58,17 +58,29 @@ nng_null_logger(nng_log_level level, nng_log_facility facility,
 }
 
 void
-nng_stderr_logger(nng_log_level level, nng_log_facility facility,
-    const char *msgid, const char *msg)
+stderr_logger(nng_log_level level, nng_log_facility facility,
+    const char *msgid, const char *msg, bool timechk)
 {
 	const char *sgr, *sgr0;
 	// Initial implementation.
-	bool        colors = false;
-	const char *level_str;
-	time_t      now;
-	char        when[64];
+	bool             colors = false;
+	const char      *level_str;
+	char             when[64];
+	struct tm       *tm;
+	static struct tm last_log = { 0 };
+	time_t           now;
+	uint64_t         sec;
+	uint32_t         nsec;
+
 	NNI_ARG_UNUSED(facility);
 
+	if (nni_time_get(&sec, &nsec) != 0) {
+		// default to the epoch if we can't get a clock for some reason
+		sec  = 0;
+		nsec = 0;
+	}
+	now = (time_t) sec;
+
 #ifdef NNG_PLATFORM_WINDOWS
 	// NB: We are blithely assuming the user has a modern console.
 	colors = _isatty(_fileno(stderr));
@@ -79,7 +91,6 @@ nng_stderr_logger(nng_log_level level, nng_log_facility facility,
 	colors = isatty(fileno(stderr)) && (getenv("TERM") != NULL) &&
 	    (getenv("TERM")[0] != 0);
 #else
-	now    = 0;
 	colors = false;
 #endif
 
@@ -92,15 +103,13 @@ nng_stderr_logger(nng_log_level level, nng_log_facility facility,
 	    (getenv("NO_COLOR") != NULL)) {
 		colors = false;
 	}
-	now = time(NULL);
 #ifdef NNG_HAVE_LOCALTIME_R
-	struct tm tm;
+	struct tm tm_buf;
 	// No timezone offset, not strictly ISO8601 compliant
-	strftime(when, sizeof(when), "%Y-%m-%d %T", localtime_r(&now, &tm));
+	tm = localtime_r(&now, &tm_buf);
 #else
-	strftime(when, sizeof(when), "%Y-%m-%d %T", localtime(&now));
+	tm = localtime(&now);
 #endif
-
 	switch (level) {
 	case NNG_LOG_ERR:
 		sgr       = "\x1b[31m"; // red
@@ -139,8 +148,30 @@ nng_stderr_logger(nng_log_level level, nng_log_facility facility,
 		sgr0 = "";
 	}
 
-	(void) fprintf(stderr, "%s[%-6s]: %s: %s%s%s%s\n", sgr, level_str,
-	    when, msgid ? msgid : "", msgid ? ": " : "", msg, sgr0);
+	if (timechk &&
+	    ((last_log.tm_mday != tm->tm_mday) ||
+	        (last_log.tm_mon != tm->tm_mon) ||
+	        (last_log.tm_year != tm->tm_year))) {
+		char new_day[64];
+		strftime(new_day, sizeof(new_day),
+		    "Date changed to %Y-%m-%d, TZ is %z", tm);
+		stderr_logger(
+		    NNG_LOG_DEBUG, facility, "NNG-DATE", new_day, false);
+		last_log = *tm;
+	}
+
+	strftime(when, sizeof(when), "%H:%M:%S", tm);
+	// we print with millisecond resolution
+	(void) fprintf(stderr, "%s[%-6s]: %s.%03d: %s%s%s%s\n", sgr, level_str,
+	    when, nsec / 1000000, msgid ? msgid : "", msgid ? ": " : "", msg,
+	    sgr0);
+}
+
+void
+nng_stderr_logger(nng_log_level level, nng_log_facility facility,
+    const char *msgid, const char *msg)
+{
+	stderr_logger(level, facility, msgid, msg, true);
 }
 
 void
diff --git a/src/core/platform.h b/src/core/platform.h
index 2e6c7eb8..53ef53af 100644
--- a/src/core/platform.h
+++ b/src/core/platform.h
@@ -234,8 +234,8 @@ extern bool nni_atomic_cas(nni_atomic_int *, int, int);
 
 // atomic pointers.  We only support a few operations.
 typedef struct nni_atomic_ptr nni_atomic_ptr;
-extern void nni_atomic_set_ptr(nni_atomic_ptr *, void *);
-extern void *nni_atomic_get_ptr(nni_atomic_ptr *);
+extern void                   nni_atomic_set_ptr(nni_atomic_ptr *, void *);
+extern void                  *nni_atomic_get_ptr(nni_atomic_ptr *);
 
 //
 // Clock Support
@@ -249,6 +249,9 @@ extern void *nni_atomic_get_ptr(nni_atomic_ptr *);
 // option of using negative values for other purposes in the future.)
 extern nni_time nni_clock(void);
 
+// Get the real time, in seconds and nanoseconds
+extern int nni_time_get(uint64_t *seconds, uint32_t *nanoseconds);
+
 // nni_msleep sleeps for the specified number of milliseconds (at least).
 extern void nni_msleep(nni_duration);
 
@@ -445,7 +448,7 @@ extern int nni_plat_udp_sockname(nni_plat_udp *, nni_sockaddr *);
 // in APIs to transport file descriptors, or across a fork/exec boundary (so
 // that child processes may use these with socket to inherit a socket that is
 // connected to the parent.)
-extern int nni_socket_pair(int [2]);
+extern int nni_socket_pair(int[2]);
 
 //
 // File/Store Support
diff --git a/src/platform/posix/CMakeLists.txt b/src/platform/posix/CMakeLists.txt
index a00ffa50..857c340a 100644
--- a/src/platform/posix/CMakeLists.txt
+++ b/src/platform/posix/CMakeLists.txt
@@ -63,6 +63,7 @@ if (NNG_PLATFORM_POSIX)
     nng_check_sym(atomic_flag_test_and_set stdatomic.h NNG_HAVE_STDATOMIC)
     nng_check_sym(socketpair sys/socket.h NNG_HAVE_SOCKETPAIR)
     nng_check_sym(AF_INET6 netinet/in.h NNG_HAVE_INET6)
+    nng_check_sym(timespec_get time.h NNG_HAVE_TIMESPEC_GET)
 
     nng_sources(
             posix_impl.h
diff --git a/src/platform/posix/posix_clock.c b/src/platform/posix/posix_clock.c
index 0db447e9..fa64c2d6 100644
--- a/src/platform/posix/posix_clock.c
+++ b/src/platform/posix/posix_clock.c
@@ -10,13 +10,44 @@
 
 // POSIX clock stuff.
 #include "core/nng_impl.h"
+#include "platform/posix/posix_impl.h"
 
 #ifdef NNG_PLATFORM_POSIX
 
 #include <errno.h>
 #include <string.h>
+#include <sys/time.h>
 #include <time.h>
 
+int
+nni_time_get(uint64_t *sec, uint32_t *nsec)
+{
+	int rv;
+#if defined(NNG_HAVE_TIMESPEC_GET)
+	struct timespec ts;
+	if ((rv = timespec_get(&ts, TIME_UTC)) == TIME_UTC) {
+		*sec  = ts.tv_sec;
+		*nsec = ts.tv_nsec;
+		return (0);
+	}
+#elif defined(NNG_HAVE_CLOCK_GETTIME)
+	struct timespec ts;
+	if ((rv = clock_gettime(CLOCK_REALTIME, &ts)) == 0) {
+		*sec  = ts.tv_sec;
+		*nsec = ts.tv_nsec;
+		return (0);
+	}
+#else
+	struct timeval tv;
+	if ((rv = gettimeofday(&tv, NULL)) == 0) {
+		*sec  = tv.tv_sec;
+		*nsec = tv.tv_usec * 1000;
+		return (0);
+	}
+#endif
+	return (nni_plat_errno(errno));
+}
+
 #if defined(NNG_HAVE_CLOCK_GETTIME) && !defined(NNG_USE_GETTIMEOFDAY)
 
 // Use POSIX realtime stuff
@@ -45,7 +76,8 @@ nni_msleep(nni_duration ms)
 	ts.tv_sec  = ms / 1000;
 	ts.tv_nsec = (ms % 1000) * 1000000;
 
-	// Do this in a loop, so that interrupts don't actually wake us.
+	// Do this in a loop, so that interrupts don't actually wake
+	// us.
 	while (ts.tv_sec || ts.tv_nsec) {
 		if (nanosleep(&ts, &ts) == 0) {
 			break;
@@ -55,14 +87,15 @@ nni_msleep(nni_duration ms)
 
 #else // NNG_USE_GETTIMEOFDAY
 
-// If you're here, its because you don't have a modern clock_gettime with
-// monotonic clocks, or the necessary pthread_condattr_settclock().  In
-// this case, you should be advised that *bad* things can happen if your
-// system clock changes time while programs using this library are running.
-// (Basically, timeouts can take longer or shorter, leading to either hangs
-// or apparent spurious errors.  Eventually it should all sort itself out,
-// but if you change the clock by a large amount you might wonder what the
-// heck is happening until it does.)
+// If you're here, its because you don't have a modern clock_gettime
+// with monotonic clocks, or the necessary
+// pthread_condattr_settclock().  In this case, you should be advised
+// that *bad* things can happen if your system clock changes time while
+// programs using this library are running. (Basically, timeouts can
+// take longer or shorter, leading to either hangs or apparent spurious
+// errors.  Eventually it should all sort itself out, but if you change
+// the clock by a large amount you might wonder what the heck is
+// happening until it does.)
 
 #include <poll.h>
 #include <pthread.h>
@@ -90,18 +123,18 @@ nni_msleep(nni_duration ms)
 {
 	// So probably there is no nanosleep.  We could in theory use
 	// pthread condition variables, but that means doing memory
-	// allocation, or forcing the use of pthreads where the platform
-	// might be preferring the use of another threading package.
-	// Additionally, use of pthreads means that we cannot use
-	// relative times in a clock_settime safe manner.
-	// So we can use poll() instead.
+	// allocation, or forcing the use of pthreads where the
+	// platform might be preferring the use of another threading
+	// package. Additionally, use of pthreads means that we cannot
+	// use relative times in a clock_settime safe manner. So we can
+	// use poll() instead.
 	struct pollfd pfd;
 	nni_time      now;
 	nni_time      expire;
 
-	// Possibly we could pass NULL instead of pfd, but passing a valid
-	// pointer ensures that if the system dereferences the pointer it
-	// won't come back with EFAULT.
+	// Possibly we could pass NULL instead of pfd, but passing a
+	// valid pointer ensures that if the system dereferences the
+	// pointer it won't come back with EFAULT.
 	pfd.fd     = -1;
 	pfd.events = 0;
 
diff --git a/src/platform/windows/win_clock.c b/src/platform/windows/win_clock.c
index fc338fdb..2beeec45 100644
--- a/src/platform/windows/win_clock.c
+++ b/src/platform/windows/win_clock.c
@@ -1,5 +1,5 @@
 //
-// Copyright 2017 Garrett D'Amore <garrett@damore.org>
+// Copyright 2024 Garrett D'Amore <garrett@damore.org>
 // Copyright 2017 Capitar IT Group BV <info@capitar.com>
 //
 // This software is supplied under the terms of the MIT License, a
@@ -10,6 +10,8 @@
 
 #include "core/nng_impl.h"
 
+#include <time.h>
+
 #ifdef NNG_PLATFORM_WINDOWS
 
 nni_time
@@ -19,6 +21,19 @@ nni_clock(void)
 	return (GetTickCount64());
 }
 
+int
+nni_time_get(uint64_t *seconds, uint32_t *nanoseconds)
+{
+	int             rv;
+	struct timespec ts;
+	if (timespec_get(&ts, TIME_UTC) == TIME_UTC) {
+		*seconds     = ts.tv_sec;
+		*nanoseconds = ts.tv_nsec;
+		return (0);
+	}
+	return (nni_win_error(GetLastError()));
+}
+
 void
 nni_msleep(nni_duration dur)
 {
diff --git a/src/testing/nuts.h b/src/testing/nuts.h
index ce75fc66..6321b005 100644
--- a/src/testing/nuts.h
+++ b/src/testing/nuts.h
@@ -1,5 +1,5 @@
 //
-// Copyright 2021 Staysail Systems, Inc. <info@staysail.tech>
+// Copyright 2024 Staysail Systems, Inc. <info@staysail.tech>
 //
 // This software is supplied under the terms of the MIT License, a
 // copy of which should be located in the distribution where this
@@ -203,6 +203,12 @@ extern const char *nuts_client_crt;
 
 #define NUTS_PROTO(x, y) (((x) << 4u) | (y))
 
+#define NUTS_ENABLE_LOG(level)                         \
+	do {                                           \
+		nng_log_set_logger(nng_stderr_logger); \
+		nng_log_set_level(level);              \
+	} while (0)
+
 #ifdef __cplusplus
 };
 #endif