From 125aad0ea4fe15c7dbd11defd2c76fa22d144b8e Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sat, 13 Apr 2024 10:59:05 -0700 Subject: [PATCH 01/22] fixes #543 Add logging support framework Signed-off-by: jaylin --- docs/man/CMakeLists.txt | 4 + docs/man/libnng.3.adoc | 10 + docs/man/nng_log.3.adoc | 62 ++++++ docs/man/nng_log_set_facility.3.adoc | 47 +++++ docs/man/nng_log_set_level.adoc | 42 ++++ docs/man/nng_log_set_logger.adoc | 52 +++++ include/nng/nng.h | 88 ++++++++- src/core/CMakeLists.txt | 3 + src/core/log.c | 284 +++++++++++++++++++++++++++ src/core/log_test.c | 188 ++++++++++++++++++ 10 files changed, 778 insertions(+), 2 deletions(-) create mode 100644 docs/man/nng_log.3.adoc create mode 100644 docs/man/nng_log_set_facility.3.adoc create mode 100644 docs/man/nng_log_set_level.adoc create mode 100644 docs/man/nng_log_set_logger.adoc create mode 100644 src/core/log.c create mode 100644 src/core/log_test.c diff --git a/docs/man/CMakeLists.txt b/docs/man/CMakeLists.txt index d6185ca6..7f47f006 100644 --- a/docs/man/CMakeLists.txt +++ b/docs/man/CMakeLists.txt @@ -115,6 +115,10 @@ if (NNG_ENABLE_DOC) nng_listener_set nng_listener_setopt nng_listener_start + nng_log + nng_log_set_facility + nng_log_set_loevel + nng_log_set_logger nng_msg_alloc nng_msg_append nng_msg_body diff --git a/docs/man/libnng.3.adoc b/docs/man/libnng.3.adoc index 22b56cf1..b202f200 100644 --- a/docs/man/libnng.3.adoc +++ b/docs/man/libnng.3.adoc @@ -283,6 +283,16 @@ universal resource locators (URLS). |xref:nng_url_parse.3.adoc[nng_url_parse()]|create URL structure from string |=== +=== Logging Support + +Common functionality for message logging. + +|=== +|xref:nng_log.3.adoc[nng_log()]|log a message +|xref:nng_log_facility.3.adoc[nng_log_set_facility()]|set log facility +|xref:nng_log_level.3.adoc[nng_log_set_level()]|set log level +|xref:nng_log_logger.3.adoc[nng_log_set_logger()]|set logging handler +|=== === Supplemental API diff --git a/docs/man/nng_log.3.adoc b/docs/man/nng_log.3.adoc new file mode 100644 index 00000000..852f765b --- /dev/null +++ b/docs/man/nng_log.3.adoc @@ -0,0 +1,62 @@ += nng_log(3) +// +// Copyright 2024 Staysail Systems, Inc. +// +// This document is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +== NAME + +nng_log - log messages + +== SYNOPSIS + +[source, c] +---- +#include + +void nng_log_err(const char *msgid, const char *msg, ...); +void nng_log_warn(const char *msgid, const char *msg, ...); +void nng_log_notice(const char *msgid, const char *msg, ...); +void nng_log_info(const char *msgid, const char *msg, ...); +void nng_log_debug(const char *msgid, const char *msg, ...); + +void nng_log_auth(nng_log_level level, const char *msgid, const char *msg, ...); +---- + +== DESCRIPTION + +These functions are used to post a message to system or application logs. + +The first five forms all post a message at the severity indicated by the function name. +The _msgid_ should be a short message identifier that should indicate the message in question. +A `NULL` value for _msgid_ canbe used as well. + +Message identifiers can be used to assist in filtering logs. +These should uniquely identify the nature of the problem, whe possible, to assist in trouble-shooting. +They should also be short. +Eight characters or less is ideal, and more than sixteen is strongly discouraged. + +The message is formatting as if by `sprintf`, using `msg` as the format, and remaining arguments as arguments to the format. + +The final function, `nng_log_auth`, is used for posting authentication related messages which might be treated specially, such as be storing them in a separate secured log file. +It takes the severity as a level in _level_. +The severity can be one of the following values: + +* `NNG_LOG_ERR` +* `NNG_LOG_WARN` +* `NNG_LOG_NOTICE` +* `NNG_LOG_INFO` +* `NNG_LOG_DEBUG` + +The message itself is handled according to the logging facility set up with xref:nng_mg_set_logger.3.adoc[`nng_log_set_logger`]. +Message delivery is best effort, and messages may be suppressed based on the priority set with xref:nng_log_set_level.3.adoc[`nng_log_set_level`]. + +== SEE ALSO + +xref:nng_log_set_facility.3.adoc[nng_log_set_facility(3)], +xref:nng_log_set_level.3.adoc[nng_log_set_level(3)], +xref:nng_log_set_logger.3.adoc[nng_log_set_logger(3)] diff --git a/docs/man/nng_log_set_facility.3.adoc b/docs/man/nng_log_set_facility.3.adoc new file mode 100644 index 00000000..ecd6ab76 --- /dev/null +++ b/docs/man/nng_log_set_facility.3.adoc @@ -0,0 +1,47 @@ += nng_log_set_facility(3) +// +// Copyright 2024 Staysail Systems, Inc. +// +// This document is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +== NAME + +nng_log_set_facility - set facility used for log messages + +== SYNOPSIS + +[source, c] +---- +#include + +typedef enum nng_log_facility { + NNG_LOG_USER = 1, + NNG_LOG_DAEMON = 3, + NNG_LOG_AUTH = 10, + NNG_LOG_LOCAL0 = 16, + NNG_LOG_LOCAL1 = 17, + NNG_LOG_LOCAL2 = 18, + NNG_LOG_LOCAL3 = 19, + NNG_LOG_LOCAL4 = 20, + NNG_LOG_LOCAL5 = 21, + NNG_LOG_LOCAL6 = 22, + NNG_LOG_LOCAL7 = 23, +} nng_log_facility; + +void nng_log_set_facility(nng_log_facility facility); +---- + +== DESCRIPTION + +The `nng_log_set_facility` is used to set the _facility_ of the application posting logs. +This is used to assist with directing log content when handled by services such as `syslog`. + +Note that while the log levels used here overlap with common levels used by the syslog facility on POSIX systems, applications should not rely on this. + +== SEE ALSO + +xref:nng_log_set_level.3.adoc[nng_log_set_level(3)] diff --git a/docs/man/nng_log_set_level.adoc b/docs/man/nng_log_set_level.adoc new file mode 100644 index 00000000..012f93f8 --- /dev/null +++ b/docs/man/nng_log_set_level.adoc @@ -0,0 +1,42 @@ += nng_log_set_level(3) +// +// Copyright 2024 Staysail Systems, Inc. +// +// This document is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +== NAME + +nng_log_set_level - set minimum level for logging messagse + +== SYNOPSIS + +[source, c] +---- +#include + +typedef enum nng_log_level { + NNG_LOG_NONE = 0, // used for filters only, NNG suppresses these + NNG_LOG_ERR = 3, + NNG_LOG_WARN = 4, + NNG_LOG_NOTICE = 5, + NNG_LOG_INFO = 6, + NNG_LOG_DEBUG = 7 +} nng_log_level; + +void nng_log_set_level(nng_log_level level); +---- + +== DESCRIPTION + +The `nng_log_set_level` function is used to set the minimum severity to _level_ for processing log messages. +Any messages with a less severe rating are not processed and simply are discarded. +Use `NNG_LOG_NONE` to suppress all log messages. +Use `NNG_LOG_DEBUG` to receive all log messages. + +== SEE ALSO + +xref:nng_log_set_facility.3.adoc[nng_log_set_facility(3)] diff --git a/docs/man/nng_log_set_logger.adoc b/docs/man/nng_log_set_logger.adoc new file mode 100644 index 00000000..4f3cafc8 --- /dev/null +++ b/docs/man/nng_log_set_logger.adoc @@ -0,0 +1,52 @@ += nng_log_set_logger(3) +// +// Copyright 2024 Staysail Systems, Inc. +// +// This document is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +== NAME + +nng_log_set_logger - set logging handler + +== SYNOPSIS + +[source, c] +---- +#include + +typedef void (*nng_logger)(nng_log_level level, nng_log_facility facility, + const char *msgid, const char *msg); + +void nng_null_logger(nng_log_level, nng_log_facility, const char *, const char *); +void nng_stderr_logger(nng_log_level, nng_log_facility, const char *, const char *); +void nng_system_logger(nng_log_level, nng_log_facility, const char *, const char *); + +void nng_log_set_logger(nng_logger logger); +---- + +== DESCRIPTION + +The `nng_log_set_logger` is used to set the base logging function to _logger_. +The _logger_ may be a user defined function to process log messages. +Only a single logger may be registered at a time. +If needed, the logger should make copies of either _msgid_ or _msg_, as those may not be valid once the logger function returns. + +The `nng_null_logger` function is an implementation of `nng_logger` that simply discards the content. + +The `nng_stderr_logger` function is an implementation that logs messages to the standard error stream. +It will attempt to colorize messages by the severity, if the standard error is a terminal device. +This can be supressed by setting either the `NO_COLOR` or `NNG_LOG_NO_COLOR` environment variables. + +The `nng_system_logger` attempts to use an appropriate system facility to log messages. +For POSIX systems, this means using `syslog` to process the messages. +For other the `nng_stderr_log` may be used as a fallback. + +== SEE ALSO + +xref:nng_log_set_facility.3.adoc[nng_log_set_facility(3)], +xref:nng_log_set_level.3.adoc[nng_log_set_level(3)], +xref:nng_log.3.adoc[nng_log(3)] diff --git a/include/nng/nng.h b/include/nng/nng.h index e54b67c3..b11b7317 100644 --- a/include/nng/nng.h +++ b/include/nng/nng.h @@ -72,7 +72,7 @@ extern "C" { // NNG_PROTOCOL_NUMBER is used by protocol headers to calculate their // protocol number from a major and minor number. Applications should // probably not need to use this. -#define NNG_PROTOCOL_NUMBER(maj, min) (((x) * 16) + (y)) +#define NNG_PROTOCOL_NUMBER(maj, min) (((x) *16) + (y)) // Types common to nng. @@ -626,7 +626,7 @@ NNG_DECL void nng_aio_finish(nng_aio *, int); // final argument is passed to the cancelfn. The final argument of the // cancellation function is the error number (will not be zero) corresponding // to the reason for cancellation, e.g. NNG_ETIMEDOUT or NNG_ECANCELED. -typedef void (*nng_aio_cancelfn)(nng_aio *, void *, int); +typedef void (*nng_aio_cancelfn)(nng_aio *, void *, int); NNG_DECL void nng_aio_defer(nng_aio *, nng_aio_cancelfn, void *); // nng_aio_sleep does a "sleeping" operation, basically does nothing @@ -1589,6 +1589,90 @@ NNG_DECL void nng_cv_wake(nng_cv *); // reduce the thundering herd problem, but care must be taken to ensure // that no waiter starves forever. NNG_DECL void nng_cv_wake1(nng_cv *); +// Logging support. + +// Log levels. These correspond to RFC 5424 (syslog) levels. +// NNG never only uses priorities 3 - 7. +// +// Note that LOG_EMER is 0, but we don't let applications submit' +// such messages, so this is a useful value to prevent logging altogether. +typedef enum nng_log_level { + NNG_LOG_NONE = 0, // used for filters only, NNG suppresses these + NNG_LOG_ERR = 3, + NNG_LOG_WARN = 4, + NNG_LOG_NOTICE = 5, + NNG_LOG_INFO = 6, + NNG_LOG_DEBUG = 7 +} nng_log_level; + +// Facilities. Also from RFC 5424. +// Not all values are enumerated here. Values not enumerated here +// should be assumed reserved for system use, and not available for +// NNG or general applications. +typedef enum nng_log_facility { + NNG_LOG_USER = 1, + NNG_LOG_DAEMON = 3, + NNG_LOG_AUTH = 10, // actually AUTHPRIV, for sensitive logs + NNG_LOG_LOCAL0 = 16, + NNG_LOG_LOCAL1 = 17, + NNG_LOG_LOCAL2 = 18, + NNG_LOG_LOCAL3 = 19, + NNG_LOG_LOCAL4 = 20, + NNG_LOG_LOCAL5 = 21, + NNG_LOG_LOCAL6 = 22, + NNG_LOG_LOCAL7 = 23, +} nng_log_facility; + +// Logging function, which may be supplied by application code. Only +// one logging function may be registered. The level and facility are +// as above. The message ID is chosen by the submitter - internal NNG +// messages will have MSGIDs starting with "NNG-". The MSGID should be +// not more than 8 characters, though this is not a hard requirement. +// Loggers are required ot make a copy of the msgid and message if required, +// because the values will not be valid once the logger returns. +typedef void (*nng_logger)(nng_log_level level, nng_log_facility facility, + const char *msgid, const char *msg); + +// Discard logger, simply throws logs away. +extern void nng_null_logger( + nng_log_level, nng_log_facility, const char *, const char *); + +// Very simple, prints formatted messages to stderr. +extern void nng_stderr_logger( + nng_log_level, nng_log_facility, const char *, const char *); + +// Performs an appropriate logging function for the system. On +// POSIX systems it uses syslog(3). Details vary by system, and the +// logging may be influenced by other APIs not provided by NNG, such as +// openlog() for POSIX systems. This may be nng_stderr_logger on +// other systems. +extern void nng_system_logger( + nng_log_level, nng_log_facility, const char *, const char *); + +// Set the default facility to use when logging. NNG uses NNG_LOG_USER by +// default. +extern void nng_log_set_facility(nng_log_facility facility); + +// Set the default logging level. Use NNG_LOG_DEBUG to get everything. +// Use NNG_LOG_NONE to prevent logging altogether. Logs that are less +// severe (numeric level is higher) will be discarded. +extern void nng_log_set_level(nng_log_level level); + +// Register a logger. +extern void nng_log_set_logger(nng_logger logger); + +// Log a message. The msg is formatted using following arguments as per +// sprintf. The msgid may be NULL. +extern void nng_log_err(const char *msgid, const char *msg, ...); +extern void nng_log_warn(const char *msgid, const char *msg, ...); +extern void nng_log_notice(const char *msgid, const char *msg, ...); +extern void nng_log_info(const char *msgid, const char *msg, ...); +extern void nng_log_debug(const char *msgid, const char *msg, ...); + +// Log an authentication related message. These will use the NNG_LOG_AUTH +// facility. +extern void nng_log_auth( + nng_log_level level, const char *msgid, const char *msg, ...); #ifdef __cplusplus } diff --git a/src/core/CMakeLists.txt b/src/core/CMakeLists.txt index 009d6bb0..48b25265 100644 --- a/src/core/CMakeLists.txt +++ b/src/core/CMakeLists.txt @@ -14,6 +14,7 @@ nng_check_sym(strlcpy string.h NNG_HAVE_STRLCPY) nng_check_sym(strnlen string.h NNG_HAVE_STRNLEN) nng_check_sym(strcasecmp string.h NNG_HAVE_STRCASECMP) nng_check_sym(strncasecmp string.h NNG_HAVE_STRNCASECMP) +nng_check_sym(localtime_r time.h NNG_HAVE_LOCALTIME_R) nng_sources( defs.h @@ -38,6 +39,7 @@ nng_sources( listener.h lmq.c lmq.h + log.c message.c message.h msgqueue.c @@ -80,6 +82,7 @@ nng_test(errors_test) nng_test(id_test) nng_test(init_test) nng_test(list_test) +nng_test(log_test) nng_test(message_test) nng_test(reconnect_test) nng_test(sock_test) diff --git a/src/core/log.c b/src/core/log.c new file mode 100644 index 00000000..b560f6c7 --- /dev/null +++ b/src/core/log.c @@ -0,0 +1,284 @@ + +// Copyright 2024 Staysail Systems, Inc. +// +// This software is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +#include "nng/nng.h" +#include "nng_impl.h" +#include +#include +#include +#ifdef NNG_PLATFORM_WINDOWS +#include +#endif +#ifdef NNG_PLATFORM_POSIX +#include +#include +#endif +#include + +static nng_log_level log_level = NNG_LOG_NOTICE; +static nng_log_facility log_facility = NNG_LOG_USER; +static nng_logger log_logger = nng_null_logger; + +void +nng_log_set_facility(nng_log_facility facility) +{ + log_facility = facility; +} + +void +nng_log_set_level(nng_log_level level) +{ + log_level = level; +} + +void +nng_log_set_logger(nng_logger logger) +{ + if (logger == NULL) { + logger = nng_null_logger; + } + log_logger = logger; +} + +void +nng_null_logger(nng_log_level level, nng_log_facility facility, + const char *msgid, const char *msg) +{ + NNI_ARG_UNUSED(level); + NNI_ARG_UNUSED(facility); + NNI_ARG_UNUSED(msgid); + NNI_ARG_UNUSED(msg); + return; +} + +void +nng_stderr_logger(nng_log_level level, nng_log_facility facility, + const char *msgid, const char *msg) +{ + const char *sgr, *sgr0; + // Initial implementation. + bool colors = false; + const char *level_str; + time_t now; + char when[64]; + NNI_ARG_UNUSED(facility); + +#ifdef NNG_PLATFORM_WINDOWS + // NB: We are blithely assuming the user has a modern console. + colors = _isatty(_fileno(stderr)); +#elif defined(NNG_PLATFORM_POSIX) + // Only assuming we can use colors (and attributes) if stderr is a tty + // and $TERM is reasonable. We assume the terminal supports ECMA-48, + // which is true on every reasonable system these days. + colors = isatty(fileno(stderr)) && (getenv("TERM") != NULL) && + (getenv("TERM")[0] != 0); +#else + now = 0; + colors = false; +#endif + + // Escape hatch to prevent colorizing logs if we have to. Users on + // legacy Windows can set this, or on ancient HP terminals or + // something. Also in the same way that no-color.org proposes. + // The reason for both is to allow suppression *only* for NNG. There + // is no good reason to enable it to override the presence of NO_COLOR. + if ((getenv("NNG_LOG_NO_COLOR") != NULL) || + (getenv("NO_COLOR") != NULL)) { + colors = false; + } + now = time(NULL); +#ifdef NNG_HAVE_LOCALTIME_R + struct tm tm; + // No timezone offset, not strictly ISO8601 compliant + strftime(when, sizeof(when), "%Y-%m-%d %T", localtime_r(&now, &tm)); +#else + strftime(when, sizeof(when), "%Y-%m-%d %T", localtime(&now)); +#endif + + switch (level) { + case NNG_LOG_ERR: + sgr = "\x1b[31m"; // red + sgr0 = "\x1b[0m"; + level_str = "ERROR"; + break; + case NNG_LOG_WARN: + sgr = "\x1b[33m"; // yellow + sgr0 = "\x1b[0m"; + level_str = "WARN"; + break; + case NNG_LOG_NOTICE: + sgr = "\x1b[1m"; // bold + sgr0 = "\x1b[0m"; + level_str = "NOTICE"; + break; + case NNG_LOG_DEBUG: + sgr = "\x1b[36m"; // cyan + sgr0 = "\x1b[0m"; + level_str = "DEBUG"; + break; + case NNG_LOG_INFO: + sgr = ""; + sgr0 = ""; + level_str = "INFO"; + break; + default: + sgr = ""; + sgr0 = ""; + level_str = "NONE"; + break; + } + + if (!colors) { + sgr = ""; + sgr0 = ""; + } + + (void) fprintf(stderr, "%s[%-6s]: %s: %s%s%s%s\n", sgr, level_str, + when, msgid ? msgid : "", msgid ? ": " : "", msg, sgr0); +} + +void +nng_system_logger(nng_log_level level, nng_log_facility facility, + const char *msgid, const char *msg) +{ +#ifdef NNG_PLATFORM_POSIX + int pri; + switch (level) { + case NNG_LOG_ERR: + pri = LOG_ERR; + break; + case NNG_LOG_WARN: + pri = LOG_WARNING; + break; + case NNG_LOG_NOTICE: + pri = LOG_NOTICE; + break; + case NNG_LOG_INFO: + pri = LOG_INFO; + break; + case NNG_LOG_DEBUG: + pri = LOG_DEBUG; + break; + default: + pri = LOG_INFO; + break; + } + switch (facility) { + case NNG_LOG_DAEMON: + pri |= LOG_DAEMON; + break; + case NNG_LOG_USER: + pri |= LOG_USER; + break; + case NNG_LOG_AUTH: + pri |= LOG_AUTHPRIV; + break; + case NNG_LOG_LOCAL0: + pri |= LOG_LOCAL0; + break; + case NNG_LOG_LOCAL1: + pri |= LOG_LOCAL1; + break; + case NNG_LOG_LOCAL2: + pri |= LOG_LOCAL2; + break; + case NNG_LOG_LOCAL3: + pri |= LOG_LOCAL3; + break; + case NNG_LOG_LOCAL4: + pri |= LOG_LOCAL4; + break; + case NNG_LOG_LOCAL5: + pri |= LOG_LOCAL5; + break; + case NNG_LOG_LOCAL6: + pri |= LOG_LOCAL6; + break; + case NNG_LOG_LOCAL7: + pri |= LOG_LOCAL7; + break; + } + + if (msgid) { + syslog(pri, "%s: %s", msgid, msg); + } else { + syslog(pri, "%s", msg); + } +#else + // everyone else just goes to stderr for now + nng_stderr_logger(level, facility, msgid, msg); +#endif +} + +static void +nni_vlog(nng_log_level level, nng_log_facility facility, const char *msgid, + const char *msg, va_list ap) +{ + // nobody allowed to log at LOG_EMERG or using LOG_KERN + if (level > log_level || log_level == 0 || facility == 0) { + return; + } + char formatted[512]; + vsnprintf(formatted, sizeof(formatted), msg, ap); + log_logger(level, facility, msgid, formatted); +} + +void +nng_log_debug(const char *msgid, const char *msg, ...) +{ + va_list ap; + va_start(ap, msg); + nni_vlog(NNG_LOG_DEBUG, log_facility, msgid, msg, ap); + va_end(ap); +} + +void +nng_log_info(const char *msgid, const char *msg, ...) +{ + va_list ap; + va_start(ap, msg); + nni_vlog(NNG_LOG_INFO, log_facility, msgid, msg, ap); + va_end(ap); +} + +void +nng_log_notice(const char *msgid, const char *msg, ...) +{ + va_list ap; + va_start(ap, msg); + nni_vlog(NNG_LOG_NOTICE, log_facility, msgid, msg, ap); + va_end(ap); +} + +void +nng_log_warn(const char *msgid, const char *msg, ...) +{ + va_list ap; + va_start(ap, msg); + nni_vlog(NNG_LOG_WARN, log_facility, msgid, msg, ap); + va_end(ap); +} + +void +nng_log_err(const char *msgid, const char *msg, ...) +{ + va_list ap; + va_start(ap, msg); + nni_vlog(NNG_LOG_ERR, log_facility, msgid, msg, ap); + va_end(ap); +} + +void +nng_log_auth(nng_log_level level, const char *msgid, const char *msg, ...) +{ + va_list ap; + va_start(ap, msg); + nni_vlog(level, NNG_LOG_AUTH, msgid, msg, ap); + va_end(ap); +} diff --git a/src/core/log_test.c b/src/core/log_test.c new file mode 100644 index 00000000..6aa1dd53 --- /dev/null +++ b/src/core/log_test.c @@ -0,0 +1,188 @@ +// +// Copyright 2024 Staysail Systems, Inc. +// +// This software is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +#include +#include + +#include +#include + +#ifdef NNG_PLATFORM_POSIX +#include +#endif + +void +test_log_stderr(void) +{ + nng_log_set_logger(nng_stderr_logger); + nng_log_set_level(NNG_LOG_DEBUG); + nng_log_info(NULL, "something wicked"); + nng_log_err(NULL, "This is an error message"); + nng_log_warn(NULL, "This is a warning message"); + nng_log_notice(NULL, "This is a notice message"); + nng_log_info(NULL, "This is an info message"); + nng_log_debug(NULL, "This is a debug message"); + nng_log_notice("TESTMSG", "This notice has a msg id"); +#ifdef NNG_PLATFORM_POSIX + setenv("NO_COLOR", "", 1); + nng_log_err("MONO", "Uncolored messages"); + unsetenv("NO_COLOR"); + setenv("NNG_LOG_NO_COLOR", "", 1); + nng_log_err("MONO", "Also uncolored messages"); +#endif + // these are intentionally unreasonably large + nng_log_set_level((nng_log_level) 100); + nng_log_auth(99, "WTF", "This should be NONE"); +} + +typedef struct test_log_entry { + nng_log_level level; + nng_log_facility facility; + const char *msgid; + char msg[128]; +} test_log_entry; + +typedef struct { + test_log_entry entries[16]; + int count; +} test_logs; + +void +custom_logger_base(test_logs *logs, nng_log_level level, + nng_log_facility facility, const char *msgid, const char *msg) +{ + test_log_entry *entry; + + if (logs->count >= 16) { + return; + } + entry = &logs->entries[logs->count++]; + entry->level = level; + entry->facility = facility; + entry->msgid = msgid; // ok for constant strings + snprintf(entry->msg, sizeof(entry->msg), "%s", msg); +} + +static test_logs test_logs_priority; +void +test_log_priority_logger(nng_log_level level, nng_log_facility facility, + const char *msgid, const char *msg) +{ + custom_logger_base(&test_logs_priority, level, facility, msgid, msg); +} + +void +test_log_priority(void) +{ + nng_log_set_logger(test_log_priority_logger); + nng_log_set_level(NNG_LOG_WARN); + nng_log_debug(NULL, "This should be filtered"); + nng_log_err("ERR", "This gets through"); + nng_log_notice("NOT", "This gets filtered"); + nng_log_warn("WRN", "This makes it"); + nng_log_info("INF", "Filtered!"); + nng_log_err("ERR", "Another error message"); + nng_log_auth(NNG_LOG_ERR, "AUTH", "authentication err sample message"); + nng_log_set_level(NNG_LOG_NONE); + nng_log_err("ERR", "Yet Another error message - filtered"); + NUTS_ASSERT(test_logs_priority.count == 4); + NUTS_ASSERT(strcmp(test_logs_priority.entries[0].msgid, "ERR") == 0); + NUTS_ASSERT(test_logs_priority.entries[0].level == NNG_LOG_ERR); + NUTS_ASSERT(strcmp(test_logs_priority.entries[1].msgid, "WRN") == 0); + NUTS_ASSERT(test_logs_priority.entries[1].level == NNG_LOG_WARN); + NUTS_ASSERT(strcmp(test_logs_priority.entries[2].msgid, "ERR") == 0); + NUTS_ASSERT(test_logs_priority.entries[2].level == NNG_LOG_ERR); + NUTS_ASSERT(strcmp(test_logs_priority.entries[3].msgid, "AUTH") == 0); + NUTS_ASSERT(test_logs_priority.entries[3].level == NNG_LOG_ERR); + NUTS_ASSERT(test_logs_priority.entries[3].facility == NNG_LOG_AUTH); +} + +static test_logs test_logs_facility; +void +test_log_facility_logger(nng_log_level level, nng_log_facility facility, + const char *msgid, const char *msg) +{ + custom_logger_base(&test_logs_facility, level, facility, msgid, msg); +} + +void +test_log_facility(void) +{ + nng_log_set_logger(test_log_facility_logger); + nng_log_set_facility(NNG_LOG_LOCAL2); + nng_log_set_level(NNG_LOG_WARN); + nng_log_debug(NULL, "This should be filtered"); + nng_log_err("001", "This is local2"); + nng_log_set_facility(NNG_LOG_DAEMON); + nng_log_warn("002", "This is Daemon"); + + NUTS_ASSERT(test_logs_facility.count == 2); + NUTS_ASSERT(strcmp(test_logs_facility.entries[0].msgid, "001") == 0); + NUTS_ASSERT(test_logs_facility.entries[0].level == NNG_LOG_ERR); + NUTS_ASSERT(test_logs_facility.entries[0].facility == NNG_LOG_LOCAL2); + NUTS_ASSERT(strcmp(test_logs_facility.entries[1].msgid, "002") == 0); + NUTS_ASSERT(test_logs_facility.entries[1].facility == NNG_LOG_DAEMON); + NUTS_ASSERT(test_logs_facility.entries[1].level == NNG_LOG_WARN); +} + +void +test_log_null_logger(void) +{ + nng_log_set_logger(nng_null_logger); + nng_log_set_level(NNG_LOG_DEBUG); + nng_log_debug(NULL, "This should be dropped"); + nng_log_err("001", "This is local2"); + nng_log_warn("002", "This is also dropped"); + + // Lets also try setting it to NULL + nng_log_set_logger(nng_null_logger); + nng_log_warn("003", "This is also dropped"); +} + +void +test_log_system_logger(void) +{ + nng_log_set_logger(nng_system_logger); + nng_log_set_level(NNG_LOG_DEBUG); + nng_log_debug(NULL, "This is a test message, ignore me"); + nng_log_set_facility(NNG_LOG_DAEMON); + nng_log_debug(NULL, "This is a test message (DAEMON), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL0); + nng_log_debug(NULL, "This is a test message (LOCAL0), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL1); + nng_log_debug(NULL, "This is a test message (LOCAL1), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL2); + nng_log_debug(NULL, "This is a test message (LOCAL2), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL3); + nng_log_debug(NULL, "This is a test message (LOCAL3), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL4); + nng_log_debug(NULL, "This is a test message (LOCAL4), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL5); + nng_log_debug(NULL, "This is a test message (LOCAL5), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL6); + nng_log_debug(NULL, "This is a test message (LOCAL6), ignore me"); + nng_log_set_facility(NNG_LOG_LOCAL7); + nng_log_debug(NULL, "This is a test message (LOCAL7), ignore me"); + + nng_log_set_facility(NNG_LOG_USER); + nng_log_debug(NULL, "This is a test message (LOCAL7), ignore me"); + nng_log_err("TEST", "This is only a test (ERR). Ignore me."); + nng_log_warn("TEST", "This is only a test (WARN). Ignore me."); + nng_log_notice("TEST", "This is only a test (NOTICE). Ignore me."); + nng_log_info("TEST", "This is only a test (INFO). Ignore me."); +} + +TEST_LIST = { + { "log stderr", test_log_stderr }, + { "log priority", test_log_priority }, + { "log facility", test_log_facility }, + { "log null logger", test_log_null_logger }, + { "log system logger", test_log_system_logger }, + { NULL, NULL }, +}; From 6d6627c75d371cfd014aabc5a55cb62a4e970656 Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 14 Apr 2024 10:18:09 -0700 Subject: [PATCH 02/22] minor include fix --- src/core/log_test.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/core/log_test.c b/src/core/log_test.c index 6aa1dd53..0bee1d47 100644 --- a/src/core/log_test.c +++ b/src/core/log_test.c @@ -10,8 +10,8 @@ #include #include +#include "nuts.h" #include -#include #ifdef NNG_PLATFORM_POSIX #include From fef453488630dde63bc859c7138efcf01cd6b84e Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 14 Apr 2024 10:21:09 -0700 Subject: [PATCH 03/22] Add clarification about logged content. --- docs/man/nng_log.3.adoc | 3 +++ docs/man/nng_log_set_logger.adoc | 1 + 2 files changed, 4 insertions(+) diff --git a/docs/man/nng_log.3.adoc b/docs/man/nng_log.3.adoc index 852f765b..358264c2 100644 --- a/docs/man/nng_log.3.adoc +++ b/docs/man/nng_log.3.adoc @@ -55,6 +55,9 @@ The severity can be one of the following values: The message itself is handled according to the logging facility set up with xref:nng_mg_set_logger.3.adoc[`nng_log_set_logger`]. Message delivery is best effort, and messages may be suppressed based on the priority set with xref:nng_log_set_level.3.adoc[`nng_log_set_level`]. +Note that in order to get log messages, a suitable logger must be set using `nng_log_set_logger`. +The default logger, `nng_null_logger` simply discards logged content. + == SEE ALSO xref:nng_log_set_facility.3.adoc[nng_log_set_facility(3)], diff --git a/docs/man/nng_log_set_logger.adoc b/docs/man/nng_log_set_logger.adoc index 4f3cafc8..eedbca49 100644 --- a/docs/man/nng_log_set_logger.adoc +++ b/docs/man/nng_log_set_logger.adoc @@ -36,6 +36,7 @@ Only a single logger may be registered at a time. If needed, the logger should make copies of either _msgid_ or _msg_, as those may not be valid once the logger function returns. The `nng_null_logger` function is an implementation of `nng_logger` that simply discards the content. +This is the default logger, so logging is disabled by default. The `nng_stderr_logger` function is an implementation that logs messages to the standard error stream. It will attempt to colorize messages by the severity, if the standard error is a terminal device. From 83b227d9124b3d405afca9630b51de05d937584a Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 14 Apr 2024 14:47:35 -0700 Subject: [PATCH 04/22] 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. Signed-off-by: jaylin --- src/core/log.c | 59 ++++++++++++++++++++++++-------- src/platform/windows/win_clock.c | 1 + src/testing/nuts.h | 5 ++- 3 files changed, 48 insertions(+), 17 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/platform/windows/win_clock.c b/src/platform/windows/win_clock.c index 8653048d..5b8dd9a8 100644 --- a/src/platform/windows/win_clock.c +++ b/src/platform/windows/win_clock.c @@ -33,6 +33,7 @@ nni_clock(void) 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; diff --git a/src/testing/nuts.h b/src/testing/nuts.h index 1a4246ab..c82abff2 100644 --- a/src/testing/nuts.h +++ b/src/testing/nuts.h @@ -209,11 +209,10 @@ extern const char *nuts_garbled_crt; #define NUTS_ENABLE_LOG(level) \ do { \ + nng_log_set_logger(nng_stderr_logger); \ + nng_log_set_level(level); \ } while (0) -#define NUTS_LOGGING() \ - do { \ - } while (0) #ifdef __cplusplus }; #endif From 9dd217e1a2d8d96515ad9e51f4401b1c9b932a8c Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 14 Apr 2024 15:43:32 -0700 Subject: [PATCH 05/22] Log transports as they are initialized. --- src/sp/transport.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/sp/transport.c b/src/sp/transport.c index d0a75b22..1d895c82 100644 --- a/src/sp/transport.c +++ b/src/sp/transport.c @@ -1,5 +1,5 @@ // -// Copyright 2023 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // Copyright 2019 Devolutions // @@ -25,6 +25,8 @@ nni_sp_tran_register(nni_sp_tran *tran) if (!nni_list_node_active(&tran->tran_link)) { tran->tran_init(); nni_list_append(&sp_tran_list, tran); + nng_log_info( + "NNG-TRAN", "Registered transport: %s", tran->tran_scheme); } nni_rwlock_unlock(&sp_tran_lk); } From c9c142c85e59a5e62e841f1bf76e7e9e34e2b5a5 Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 14 Apr 2024 15:45:52 -0700 Subject: [PATCH 06/22] Log rejects by app, bind/listen/connect failures. --- src/core/dialer.c | 5 ++++- src/core/listener.c | 19 ++++++++++++------- src/core/socket.c | 4 +++- 3 files changed, 19 insertions(+), 9 deletions(-) diff --git a/src/core/dialer.c b/src/core/dialer.c index e95ef97d..fde072b2 100644 --- a/src/core/dialer.c +++ b/src/core/dialer.c @@ -389,6 +389,9 @@ dialer_connect_cb(void *arg) case NNG_ECONNREFUSED: case NNG_ETIMEDOUT: default: + nng_log_warn("NNG-CONN-FAIL", "Failed connecting to %s: %s", + d->d_url->u_rawurl, nng_strerror(rv)); + nni_dialer_bump_error(d, rv); if (user_aio == NULL) { nni_dialer_timer_start(d); @@ -411,7 +414,7 @@ dialer_connect_start(nni_dialer *d) int nni_dialer_start(nni_dialer *d, unsigned flags) { - int rv = 0; + int rv = 0; nni_aio *aio = NULL; if (nni_atomic_flag_test_and_set(&d->d_started)) { diff --git a/src/core/listener.c b/src/core/listener.c index 53d5c843..a020079d 100644 --- a/src/core/listener.c +++ b/src/core/listener.c @@ -10,6 +10,7 @@ // #include "core/nng_impl.h" +#include "core/strs.h" #include "sockimpl.h" #include @@ -21,7 +22,7 @@ static void listener_accept_start(nni_listener *); static void listener_accept_cb(void *); static void listener_timer_cb(void *); -static nni_id_map listeners = NNI_ID_MAP_INITIALIZER(1, 0x7fffffff, 0); +static nni_id_map listeners = NNI_ID_MAP_INITIALIZER(1, 0x7fffffff, 0); static nni_mtx listeners_lk = NNI_MTX_INITIALIZER; uint32_t @@ -223,12 +224,12 @@ nni_listener_create(nni_listener **lp, nni_sock *s, const char *url_str) nni_url_free(url); return (NNG_ENOMEM); } - l->l_url = url; - l->l_closed = false; - l->l_data = NULL; - l->l_ref = 1; - l->l_sock = s; - l->l_tran = tran; + l->l_url = url; + l->l_closed = false; + l->l_data = NULL; + l->l_ref = 1; + l->l_sock = s; + l->l_tran = tran; nni_atomic_flag_reset(&l->l_started); // Make a copy of the endpoint operations. This allows us to @@ -363,6 +364,8 @@ listener_accept_cb(void *arg) case NNG_ECONNRESET: // remote condition, no cool down case NNG_ETIMEDOUT: // No need to sleep, we timed out already. case NNG_EPEERAUTH: // peer validation failure + nng_log_warn("NNG-ACCEPT-FAIL", "Failed accepting on %s: %s", + l->l_url->u_rawurl, nng_strerror(rv)); nni_listener_bump_error(l, rv); listener_accept_start(l); break; @@ -400,6 +403,8 @@ nni_listener_start(nni_listener *l, int flags) } if ((rv = l->l_ops.l_bind(l->l_data)) != 0) { + nng_log_warn("NNG-BIND-FAIL", "Failed binding to %s: %s", + l->l_url->u_rawurl, nng_strerror(rv)); nni_listener_bump_error(l, rv); nni_atomic_flag_reset(&l->l_started); return (rv); diff --git a/src/core/socket.c b/src/core/socket.c index 49746321..6bd9887e 100644 --- a/src/core/socket.c +++ b/src/core/socket.c @@ -943,7 +943,7 @@ int nni_sock_add_dialer(nni_sock *s, nni_dialer *d) { nni_sockopt *sopt; - int rv; + int rv; // grab a hold on the dialer for the socket if ((rv = nni_dialer_hold(d)) != 0) { @@ -1527,6 +1527,8 @@ nni_dialer_add_pipe(nni_dialer *d, void *tpipe) nni_stat_inc(&d->st_reject, 1); nni_stat_inc(&s->st_rejects, 1); #endif + nng_log_debug("NNG-PIPEREJECT", + "Pipe closed by pipe callback before added to socket"); nni_pipe_rele(p); return; } From 7e7ff0d92c9ae067c24430c69ea67d46428c11ab Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 14 Apr 2024 15:47:55 -0700 Subject: [PATCH 07/22] Announce NNG version in log. --- src/core/init.c | 17 ++++++++++++----- 1 file changed, 12 insertions(+), 5 deletions(-) diff --git a/src/core/init.c b/src/core/init.c index 188b9a16..1bd06582 100644 --- a/src/core/init.c +++ b/src/core/init.c @@ -9,6 +9,7 @@ // #include "core/nng_impl.h" +#include "nng/nng.h" #include #include @@ -45,6 +46,8 @@ nni_init_helper(void) nni_mqtt_tran_sys_init(); nni_inited = true; + nng_log_notice( + "NNG-INIT", "NNG library version %s initialized", nng_version()); return (0); } @@ -52,7 +55,12 @@ nni_init_helper(void) int nni_init(void) { - return (nni_plat_init(nni_init_helper)); + int rv; + if ((rv = nni_plat_init(nni_init_helper)) != 0) { + nng_log_err("NNG-INIT", + "NNG library initialization failed: %s", nng_strerror(rv)); + } + return (rv); } // accessing the list of parameters @@ -61,7 +69,7 @@ typedef struct nni_init_param { nng_init_parameter param; uint64_t value; #ifdef NNG_TEST_LIB - uint64_t effective; + uint64_t effective; #endif } nni_init_param; @@ -115,7 +123,7 @@ nni_init_set_effective(nng_init_parameter p, uint64_t value) } } if ((item = NNI_ALLOC_STRUCT(item)) != NULL) { - item->param = p; + item->param = p; item->effective = value; nni_list_append(&nni_init_params, item); } @@ -135,11 +143,10 @@ nni_init_get_effective(nng_init_parameter p) return (item->effective); } } - return ((uint64_t)-1); + return ((uint64_t) -1); } #endif - static void nni_init_params_fini(void) { From 5ca74958f6e93aa76cfd0c4751269447920e7f19 Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 14 Apr 2024 16:33:38 -0700 Subject: [PATCH 08/22] fixes #1588 TLS should log errors This isn't complete, but it should go much further in assisting debugging TLS related errors. Signed-off-by: jaylin --- src/supplemental/tls/mbedtls/tls.c | 40 +++- src/supplemental/tls/tls_common.c | 53 ++--- src/supplemental/tls/tls_test.c | 316 +---------------------------- tests/tls.c | 19 +- 4 files changed, 81 insertions(+), 347 deletions(-) diff --git a/src/supplemental/tls/mbedtls/tls.c b/src/supplemental/tls/mbedtls/tls.c index 36083bec..379fde74 100644 --- a/src/supplemental/tls/mbedtls/tls.c +++ b/src/supplemental/tls/mbedtls/tls.c @@ -17,6 +17,7 @@ #include "mbedtls/version.h" // Must be first in order to pick up version #include "mbedtls/error.h" +#include "nng/nng.h" #include "nng/nng.h" #include "nng/supplemental/tls/tls.h" @@ -133,6 +134,22 @@ tls_random(void *arg, unsigned char *buf, size_t sz) #endif } +static void +tls_log_err(const char *msgid, const char *context, int errnum) +{ + char errbuf[256]; + mbedtls_strerror(errnum, errbuf, sizeof(errbuf)); + nng_log_err(msgid, "%s: %s", context, errbuf); +} + +static void +tls_log_warn(const char *msgid, const char *context, int errnum) +{ + char errbuf[256]; + mbedtls_strerror(errnum, errbuf, sizeof(errbuf)); + nng_log_warn(msgid, "%s: %s", context, errbuf); +} + // tls_mk_err converts an mbed error to an NNG error. static struct { int tls; @@ -227,6 +244,8 @@ conn_init(nng_tls_engine_conn *ec, void *tls, nng_tls_engine_config *cfg) mbedtls_ssl_set_bio(&ec->ctx, tls, net_send, net_recv, NULL); if ((rv = mbedtls_ssl_setup(&ec->ctx, &cfg->cfg_ctx)) != 0) { + tls_log_warn( + "NNG-TLS-CONN-FAIL", "Failed to setup TLS connection", rv); return (tls_mk_err(rv)); } @@ -300,6 +319,7 @@ conn_handshake(nng_tls_engine_conn *ec) return (0); default: + tls_log_warn("NNG-TLS-HANDSHAKE", "TLS handshake failed", rv); return (tls_mk_err(rv)); } } @@ -434,8 +454,10 @@ config_init(nng_tls_engine_config *cfg, enum nng_tls_mode mode) rv = mbedtls_ssl_config_defaults(&cfg->cfg_ctx, ssl_mode, MBEDTLS_SSL_TRANSPORT_STREAM, MBEDTLS_SSL_PRESET_DEFAULT); if (rv != 0) { + tls_log_err("NNG-TLS-CONFIG-INIT-FAIL", + "Failed to initialize TLS configuration", rv); config_fini(cfg); - return (rv); + return (tls_mk_err(rv)); } mbedtls_ssl_conf_authmode(&cfg->cfg_ctx, auth_mode); @@ -563,12 +585,16 @@ config_ca_chain(nng_tls_engine_config *cfg, const char *certs, const char *crl) pem = (const uint8_t *) certs; len = strlen(certs) + 1; if ((rv = mbedtls_x509_crt_parse(&cfg->ca_certs, pem, len)) != 0) { + tls_log_err("NNG-TLS-CA-FAIL", + "Failed to parse CA certificate(s)", rv); return (tls_mk_err(rv)); } if (crl != NULL) { pem = (const uint8_t *) crl; len = strlen(crl) + 1; if ((rv = mbedtls_x509_crl_parse(&cfg->crl, pem, len)) != 0) { + tls_log_err("NNG-TLS-CRL-FAIL", + "Failed to parse revocation list", rv); return (tls_mk_err(rv)); } } @@ -595,6 +621,8 @@ config_own_cert(nng_tls_engine_config *cfg, const char *cert, const char *key, pem = (const uint8_t *) cert; len = strlen(cert) + 1; if ((rv = mbedtls_x509_crt_parse(&p->crt, pem, len)) != 0) { + tls_log_err("NNG-TLS-CRT-FAIL", + "Failure parsing our own certificate", rv); rv = tls_mk_err(rv); goto err; } @@ -609,12 +637,15 @@ config_own_cert(nng_tls_engine_config *cfg, const char *cert, const char *key, pass != NULL ? strlen(pass) : 0, tls_random, NULL); #endif if (rv != 0) { + tls_log_err("NNG-TLS-KEY", "Failure parsing private key", rv); rv = tls_mk_err(rv); goto err; } rv = mbedtls_ssl_conf_own_cert(&cfg->cfg_ctx, &p->crt, &p->key); if (rv != 0) { + tls_log_err("NNG-TLS-SELF", + "Failure configuring self certificate", rv); rv = tls_mk_err(rv); goto err; } @@ -638,6 +669,8 @@ config_version(nng_tls_engine_config *cfg, nng_tls_version min_ver, int maj = MBEDTLS_SSL_MAJOR_VERSION_3; if (min_ver > max_ver) { + nng_log_err("TLS-CFG-VER", + "TLS maximum version must be larger than mimumum version"); return (NNG_ENOTSUP); } switch (min_ver) { @@ -655,6 +688,8 @@ config_version(nng_tls_engine_config *cfg, nng_tls_version min_ver, v1 = MBEDTLS_SSL_MINOR_VERSION_3; break; default: + nng_log_err( + "TLS-CFG-VER", "TLS minimum version not supported"); return (NNG_ENOTSUP); } @@ -677,6 +712,8 @@ config_version(nng_tls_engine_config *cfg, nng_tls_version min_ver, // Note that this means that if we ever TLS 1.4 or 2.0, // then this will break. That's sufficiently far out // to justify not worrying about it. + nng_log_err( + "TLS-CFG-VER", "TLS maximum version not supported"); return (NNG_ENOTSUP); } @@ -732,6 +769,7 @@ nng_tls_engine_init_mbed(void) mbedtls_ctr_drbg_init(&cfg->rng_ctx); rv = mbedtls_ctr_drbg_seed(&rng_ctx, tls_get_entropy, NULL, NULL, 0); if (rv != 0) { + tls_log_err("NNG-TLS-RNG", "Failed initializing CTR DRBG", rv); nni_mtx_fini(&rng_lock); return (rv); } diff --git a/src/supplemental/tls/tls_common.c b/src/supplemental/tls/tls_common.c index d801ec21..62296de0 100644 --- a/src/supplemental/tls/tls_common.c +++ b/src/supplemental/tls/tls_common.c @@ -43,7 +43,7 @@ static nni_atomic_ptr tls_engine; struct nng_tls_config { nng_tls_engine_config_ops ops; - const nng_tls_engine * engine; // store this so we can verify + const nng_tls_engine *engine; // store this so we can verify nni_mtx lock; int ref; bool busy; @@ -55,21 +55,21 @@ struct nng_tls_config { typedef struct { nng_stream stream; nng_tls_engine_conn_ops ops; - nng_tls_config * cfg; - const nng_tls_engine * engine; + nng_tls_config *cfg; + const nng_tls_engine *engine; size_t size; - nni_aio * user_aio; // user's aio for connect/accept + nni_aio *user_aio; // user's aio for connect/accept nni_aio conn_aio; // system aio for connect/accept nni_mtx lock; bool closed; bool hs_done; nni_list send_queue; nni_list recv_queue; - nng_stream * tcp; // lower level stream + nng_stream *tcp; // lower level stream nni_aio tcp_send; // lower level send pending nni_aio tcp_recv; // lower level recv pending - uint8_t * tcp_send_buf; - uint8_t * tcp_recv_buf; + uint8_t *tcp_send_buf; + uint8_t *tcp_recv_buf; size_t tcp_recv_len; size_t tcp_recv_off; bool tcp_recv_pend; @@ -101,7 +101,7 @@ static nni_reap_list tls_conn_reap_list = { typedef struct { nng_stream_dialer ops; nng_stream_dialer *d; // underlying TCP dialer - nng_tls_config * cfg; + nng_tls_config *cfg; nni_mtx lk; // protects the config } tls_dialer; @@ -130,7 +130,7 @@ tls_dialer_free(void *arg) static void tls_conn_cb(void *arg) { - tls_conn * conn = arg; + tls_conn *conn = arg; nng_stream *tcp; int rv; @@ -171,7 +171,7 @@ tls_dialer_dial(void *arg, nng_aio *aio) { tls_dialer *d = arg; int rv; - tls_conn * conn; + tls_conn *conn; if (nni_aio_begin(aio) != 0) { return; @@ -212,7 +212,7 @@ tls_dialer_set_config(void *arg, const void *buf, size_t sz, nni_type t) { int rv; nng_tls_config *cfg; - tls_dialer * d = arg; + tls_dialer *d = arg; nng_tls_config *old; if ((rv = nni_copyin_ptr((void **) &cfg, buf, sz, t)) != 0) { @@ -235,7 +235,7 @@ tls_dialer_set_config(void *arg, const void *buf, size_t sz, nni_type t) static int tls_dialer_get_config(void *arg, void *buf, size_t *szp, nni_type t) { - tls_dialer * d = arg; + tls_dialer *d = arg; nng_tls_config *cfg; int rv; nni_mtx_lock(&d->lk); @@ -409,7 +409,7 @@ nni_tls_dialer_alloc(nng_stream_dialer **dp, const nng_url *url) typedef struct { nng_stream_listener ops; nng_stream_listener *l; - nng_tls_config * cfg; + nng_tls_config *cfg; nni_mtx lk; } tls_listener; @@ -445,7 +445,7 @@ tls_listener_accept(void *arg, nng_aio *aio) { tls_listener *l = arg; int rv; - tls_conn * conn; + tls_conn *conn; if (nni_aio_begin(aio) != 0) { return; @@ -469,7 +469,7 @@ tls_listener_set_config(void *arg, const void *buf, size_t sz, nni_type t) { int rv; nng_tls_config *cfg; - tls_listener * l = arg; + tls_listener *l = arg; nng_tls_config *old; if ((rv = nni_copyin_ptr((void **) &cfg, buf, sz, t)) != 0) { @@ -494,7 +494,7 @@ tls_listener_set_config(void *arg, const void *buf, size_t sz, nni_type t) static int tls_listener_get_config(void *arg, void *buf, size_t *szp, nni_type t) { - tls_listener * l = arg; + tls_listener *l = arg; nng_tls_config *cfg; int rv; nni_mtx_lock(&l->lk); @@ -809,7 +809,7 @@ static const nni_option tls_options[] = { static int tls_set(void *arg, const char *name, const void *buf, size_t sz, nni_type t) { - tls_conn * conn = arg; + tls_conn *conn = arg; int rv; nng_stream *tcp; @@ -837,7 +837,7 @@ tls_get(void *arg, const char *name, void *buf, size_t *szp, nni_type t) static int tls_alloc(tls_conn **conn_p, nng_tls_config *cfg, nng_aio *user_aio) { - tls_conn * conn; + tls_conn *conn; const nng_tls_engine *eng; size_t size; @@ -1071,7 +1071,7 @@ static void tls_tcp_send_cb(void *arg) { tls_conn *conn = arg; - nng_aio * aio = &conn->tcp_send; + nng_aio *aio = &conn->tcp_send; int rv; size_t count; @@ -1103,7 +1103,7 @@ static void tls_tcp_recv_cb(void *arg) { tls_conn *conn = arg; - nni_aio * aio = &conn->tcp_recv; + nni_aio *aio = &conn->tcp_recv; int rv; nni_mtx_lock(&conn->lock); @@ -1278,9 +1278,9 @@ nng_tls_config_cert_key_file( nng_tls_config *cfg, const char *path, const char *pass) { int rv; - void * data; + void *data; size_t size; - char * pem; + char *pem; if ((rv = nni_file_get(path, &data, &size)) != 0) { return (rv); @@ -1300,9 +1300,9 @@ int nng_tls_config_ca_file(nng_tls_config *cfg, const char *path) { int rv; - void * data; + void *data; size_t size; - char * pem; + char *pem; if ((rv = nni_file_get(path, &data, &size)) != 0) { return (rv); @@ -1417,7 +1417,7 @@ nng_tls_config_auth_mode(nng_tls_config *cfg, nng_tls_auth_mode mode) int nng_tls_config_alloc(nng_tls_config **cfg_p, nng_tls_mode mode) { - nng_tls_config * cfg; + nng_tls_config *cfg; const nng_tls_engine *eng; size_t size; int rv; @@ -1516,6 +1516,9 @@ int nng_tls_engine_register(const nng_tls_engine *engine) { if (engine->version != NNG_TLS_ENGINE_VERSION) { + nng_log_err("NNG-TLS-ENGINE-VER", + "TLS Engine version mismatch: %d != %d", engine->version, + NNG_TLS_ENGINE_VERSION); return (NNG_ENOTSUP); } nni_atomic_set_ptr(&tls_engine, (void *) engine); diff --git a/src/supplemental/tls/tls_test.c b/src/supplemental/tls/tls_test.c index 0aa18708..7b317bb4 100644 --- a/src/supplemental/tls/tls_test.c +++ b/src/supplemental/tls/tls_test.c @@ -8,7 +8,6 @@ // #include "nng/nng.h" -#include "nng/supplemental/tls/tls.h" #include void @@ -87,7 +86,11 @@ test_tls_large_message(void) void *t2; int port; +<<<<<<< HEAD NUTS_ENABLE_LOG(NNG_LOG_DEBUG); +======= + NUTS_ENABLE_LOG(NNG_LOG_INFO); +>>>>>>> b1aaa6069 (fixes #1588 TLS should log errors) // allocate messages NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); @@ -171,321 +174,10 @@ test_tls_garbled_cert(void) nng_tls_config_free(c1); } -void -test_tls_psk(void) -{ - nng_stream_listener *l; - nng_stream_dialer *d; - nng_aio *aio1, *aio2; - nng_stream *s1; - nng_stream *s2; - nng_tls_config *c1; - nng_tls_config *c2; - char addr[32]; - uint8_t key[32]; - uint8_t *buf1; - uint8_t *buf2; - size_t size = 10000; - void *t1; - void *t2; - int port; - - NUTS_ENABLE_LOG(NNG_LOG_DEBUG); - // allocate messages - NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); - NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); - - for (size_t i = 0; i < sizeof(key); i++) { - key[i] = rand() & 0xff; - } - for (size_t i = 0; i < size; i++) { - buf1[i] = rand() & 0xff; - } - - NUTS_PASS(nng_aio_alloc(&aio1, NULL, NULL)); - NUTS_PASS(nng_aio_alloc(&aio2, NULL, NULL)); - nng_aio_set_timeout(aio1, 5000); - nng_aio_set_timeout(aio2, 5000); - - // Allocate the listener first. We use a wild-card port. - NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); - NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); - NUTS_PASS(nng_tls_config_psk(c1, "identity", key, sizeof(key))); - NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); - NUTS_PASS(nng_stream_listener_listen(l)); - NUTS_PASS( - nng_stream_listener_get_int(l, NNG_OPT_TCP_BOUND_PORT, &port)); - NUTS_TRUE(port > 0); - NUTS_TRUE(port < 65536); - - snprintf(addr, sizeof(addr), "tls+tcp://127.0.0.1:%d", port); - NUTS_PASS(nng_stream_dialer_alloc(&d, addr)); - NUTS_PASS(nng_tls_config_alloc(&c2, NNG_TLS_MODE_CLIENT)); - NUTS_PASS(nng_tls_config_psk(c2, "identity", key, sizeof(key))); - - NUTS_PASS(nng_stream_dialer_set_ptr(d, NNG_OPT_TLS_CONFIG, c2)); - - nng_stream_listener_accept(l, aio1); - nng_stream_dialer_dial(d, aio2); - - nng_aio_wait(aio1); - nng_aio_wait(aio2); - - NUTS_PASS(nng_aio_result(aio1)); - NUTS_PASS(nng_aio_result(aio2)); - - NUTS_TRUE((s1 = nng_aio_get_output(aio1, 0)) != NULL); - NUTS_TRUE((s2 = nng_aio_get_output(aio2, 0)) != NULL); - - t1 = nuts_stream_send_start(s1, buf1, size); - t2 = nuts_stream_recv_start(s2, buf2, size); - - NUTS_PASS(nuts_stream_wait(t1)); - NUTS_PASS(nuts_stream_wait(t2)); - NUTS_TRUE(memcmp(buf1, buf2, size) == 0); - - nng_free(buf1, size); - nng_free(buf2, size); - nng_stream_free(s1); - nng_stream_free(s2); - nng_stream_dialer_free(d); - nng_stream_listener_free(l); - nng_tls_config_free(c1); - nng_tls_config_free(c2); - nng_aio_free(aio1); - nng_aio_free(aio2); -} - -void -test_tls_psk_server_identities(void) -{ - nng_stream_listener *l; - nng_stream_dialer *d; - nng_aio *aio1, *aio2; - nng_stream *s1; - nng_stream *s2; - nng_tls_config *c1; - nng_tls_config *c2; - char addr[32]; - uint8_t *buf1; - uint8_t *buf2; - size_t size = 10000; - void *t1; - void *t2; - int port; - char *identity = "test_identity"; - uint8_t key[32]; - - NUTS_ENABLE_LOG(NNG_LOG_INFO); - // allocate messages - NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); - NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); - - for (size_t i = 0; i < sizeof(key); i++) { - key[i] = rand() & 0xff; - } - for (size_t i = 0; i < size; i++) { - buf1[i] = rand() & 0xff; - } - - NUTS_PASS(nng_aio_alloc(&aio1, NULL, NULL)); - NUTS_PASS(nng_aio_alloc(&aio2, NULL, NULL)); - nng_aio_set_timeout(aio1, 5000); - nng_aio_set_timeout(aio2, 5000); - - // Allocate the listener first. We use a wild-card port. - NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); - NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); - // Replace the identity .. first write one value, then we change it - NUTS_PASS( - nng_tls_config_psk(c1, "identity2", key + 4, sizeof(key) - 4)); - NUTS_PASS(nng_tls_config_psk(c1, identity, key + 4, sizeof(key) - 4)); - NUTS_PASS(nng_tls_config_psk(c1, identity, key, sizeof(key))); - NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); - NUTS_PASS(nng_stream_listener_listen(l)); - NUTS_PASS( - nng_stream_listener_get_int(l, NNG_OPT_TCP_BOUND_PORT, &port)); - NUTS_TRUE(port > 0); - NUTS_TRUE(port < 65536); - - snprintf(addr, sizeof(addr), "tls+tcp://127.0.0.1:%d", port); - NUTS_PASS(nng_stream_dialer_alloc(&d, addr)); - NUTS_PASS(nng_tls_config_alloc(&c2, NNG_TLS_MODE_CLIENT)); - NUTS_PASS(nng_tls_config_psk(c2, identity, key, sizeof(key))); - - NUTS_PASS(nng_stream_dialer_set_ptr(d, NNG_OPT_TLS_CONFIG, c2)); - - nng_stream_listener_accept(l, aio1); - nng_stream_dialer_dial(d, aio2); - - nng_aio_wait(aio1); - nng_aio_wait(aio2); - - NUTS_PASS(nng_aio_result(aio1)); - NUTS_PASS(nng_aio_result(aio2)); - - NUTS_TRUE((s1 = nng_aio_get_output(aio1, 0)) != NULL); - NUTS_TRUE((s2 = nng_aio_get_output(aio2, 0)) != NULL); - - t1 = nuts_stream_send_start(s1, buf1, size); - t2 = nuts_stream_recv_start(s2, buf2, size); - - NUTS_PASS(nuts_stream_wait(t1)); - NUTS_PASS(nuts_stream_wait(t2)); - NUTS_TRUE(memcmp(buf1, buf2, size) == 0); - - nng_free(buf1, size); - nng_free(buf2, size); - nng_stream_free(s1); - nng_stream_free(s2); - nng_stream_dialer_free(d); - nng_stream_listener_free(l); - nng_tls_config_free(c1); - nng_tls_config_free(c2); - nng_aio_free(aio1); - nng_aio_free(aio2); -} - -void -test_tls_psk_bad_identity(void) -{ - nng_stream_listener *l; - nng_stream_dialer *d; - nng_aio *aio1, *aio2; - nng_stream *s1; - nng_stream *s2; - nng_tls_config *c1; - nng_tls_config *c2; - char addr[32]; - uint8_t *buf1; - uint8_t *buf2; - size_t size = 10000; - void *t1; - void *t2; - int port; - uint8_t key[32]; - - NUTS_ENABLE_LOG(NNG_LOG_INFO); - // allocate messages - NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); - NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); - - for (size_t i = 0; i < sizeof(key); i++) { - key[i] = rand() & 0xff; - } - for (size_t i = 0; i < size; i++) { - buf1[i] = rand() & 0xff; - } - - NUTS_PASS(nng_aio_alloc(&aio1, NULL, NULL)); - NUTS_PASS(nng_aio_alloc(&aio2, NULL, NULL)); - nng_aio_set_timeout(aio1, 5000); - nng_aio_set_timeout(aio2, 5000); - - // Allocate the listener first. We use a wild-card port. - NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); - NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); - // Replace the identity .. first write one value, then we change it - NUTS_PASS(nng_tls_config_psk(c1, "identity1", key, sizeof(key))); - NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); - NUTS_PASS(nng_stream_listener_listen(l)); - NUTS_PASS( - nng_stream_listener_get_int(l, NNG_OPT_TCP_BOUND_PORT, &port)); - NUTS_TRUE(port > 0); - NUTS_TRUE(port < 65536); - - snprintf(addr, sizeof(addr), "tls+tcp://127.0.0.1:%d", port); - NUTS_PASS(nng_stream_dialer_alloc(&d, addr)); - NUTS_PASS(nng_tls_config_alloc(&c2, NNG_TLS_MODE_CLIENT)); - NUTS_PASS(nng_tls_config_psk(c2, "identity2", key, sizeof(key))); - NUTS_PASS(nng_tls_config_server_name(c2, "localhost")); - - NUTS_PASS(nng_stream_dialer_set_ptr(d, NNG_OPT_TLS_CONFIG, c2)); - - nng_stream_listener_accept(l, aio1); - nng_stream_dialer_dial(d, aio2); - - nng_aio_wait(aio1); - nng_aio_wait(aio2); - - NUTS_PASS(nng_aio_result(aio1)); - NUTS_PASS(nng_aio_result(aio2)); - - NUTS_TRUE((s1 = nng_aio_get_output(aio1, 0)) != NULL); - NUTS_TRUE((s2 = nng_aio_get_output(aio2, 0)) != NULL); - - t1 = nuts_stream_send_start(s1, buf1, size); - t2 = nuts_stream_recv_start(s2, buf2, size); - - NUTS_FAIL(nuts_stream_wait(t1), NNG_ECRYPTO); - NUTS_FAIL(nuts_stream_wait(t2), NNG_ECRYPTO); - - nng_free(buf1, size); - nng_free(buf2, size); - nng_stream_free(s1); - nng_stream_free(s2); - nng_stream_dialer_free(d); - nng_stream_listener_free(l); - nng_tls_config_free(c1); - nng_tls_config_free(c2); - nng_aio_free(aio1); - nng_aio_free(aio2); -} - -void -test_tls_psk_key_too_big(void) -{ - nng_tls_config *c1; - uint8_t key[5000]; - - NUTS_ENABLE_LOG(NNG_LOG_INFO); - - // Allocate the listener first. We use a wild-card port. - NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_CLIENT)); - NUTS_FAIL( - nng_tls_config_psk(c1, "identity", key, sizeof(key)), NNG_ECRYPTO); - nng_tls_config_free(c1); -} - -void -test_tls_psk_config_busy(void) -{ - nng_tls_config *c1; - uint8_t key[32]; - nng_stream_listener *l; - nng_aio *aio; - - nng_aio_alloc(&aio, NULL, NULL); - - NUTS_ENABLE_LOG(NNG_LOG_INFO); - - NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); - NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); - NUTS_PASS(nng_tls_config_psk(c1, "identity", key, sizeof(key))); - NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); - nng_stream_listener_accept(l, aio); - nng_msleep(100); - NUTS_FAIL( - nng_tls_config_psk(c1, "identity2", key, sizeof(key)), NNG_EBUSY); - - nng_stream_listener_free(l); - nng_aio_free(aio); - nng_tls_config_free(c1); -} - TEST_LIST = { { "tls config version", test_tls_config_version }, { "tls conn refused", test_tls_conn_refused }, { "tls large message", test_tls_large_message }, -#ifndef NNG_TLS_ENGINE_WOLFSSL // wolfSSL doesn't validate certas until use { "tls garbled cert", test_tls_garbled_cert }, -#endif -#ifdef NNG_SUPP_TLS_PSK - { "tls psk", test_tls_psk }, - { "tls psk server identities", test_tls_psk_server_identities }, - { "tls psk bad identity", test_tls_psk_bad_identity }, - { "tls psk key too big", test_tls_psk_key_too_big }, - { "tls psk key config busy", test_tls_psk_config_busy }, -#endif { NULL, NULL }, }; diff --git a/tests/tls.c b/tests/tls.c index 545d2da2..c3a4a46b 100644 --- a/tests/tls.c +++ b/tests/tls.c @@ -275,6 +275,9 @@ init_listener_tls_file(nng_listener l) TestMain("TLS Transport", { static trantest tt; + nng_log_set_logger(nng_stderr_logger); + nng_log_set_level(NNG_LOG_INFO); + if (strcmp(nng_tls_engine_name(), "none") == 0) { Skip("TLS not enabled"); } @@ -332,7 +335,7 @@ TestMain("TLS Transport", { nng_socket s2; nng_listener l; nng_dialer d; - char * addr; + char *addr; So(nng_tls_register() == 0); So(nng_pair_open(&s1) == 0); @@ -454,7 +457,7 @@ TestMain("TLS Transport", { nng_socket s2; // client nng_listener l; char addr[NNG_MAXADDRLEN]; - nng_msg * msg; + nng_msg *msg; nng_pipe p; bool b; nng_dialer d; @@ -500,7 +503,7 @@ TestMain("TLS Transport", { nng_listener l; nng_dialer d; char addr[NNG_MAXADDRLEN]; - nng_msg * msg; + nng_msg *msg; nng_pipe p; bool b; @@ -576,8 +579,8 @@ TestMain("TLS Transport", { So(nng_listener_set_int(l, NNG_OPT_TCP_NODELAY, x) == NNG_EBADTYPE); // This assumes sizeof (bool) != sizeof (int) - So(nng_listener_set( - l, NNG_OPT_TCP_NODELAY, &x, sizeof(x)) == NNG_EINVAL); + So(nng_listener_set(l, NNG_OPT_TCP_NODELAY, &x, sizeof(x)) == + NNG_EINVAL); nng_dialer_close(d); nng_listener_close(l); @@ -607,8 +610,7 @@ TestMain("TLS Transport", { So(nng_dialer_create(&d, s, "tcp://127.0.0.1:4999") == 0); So(nng_dialer_get_bool(d, NNG_OPT_TCP_KEEPALIVE, &v) == 0); So(v == false); - So(nng_dialer_set_bool(d, NNG_OPT_TCP_KEEPALIVE, true) == - 0); + So(nng_dialer_set_bool(d, NNG_OPT_TCP_KEEPALIVE, true) == 0); So(nng_dialer_get_bool(d, NNG_OPT_TCP_KEEPALIVE, &v) == 0); So(v == true); So(nng_dialer_get_int(d, NNG_OPT_TCP_KEEPALIVE, &x) == @@ -618,8 +620,7 @@ TestMain("TLS Transport", { NNG_EBADTYPE); So(nng_listener_create(&l, s, "tcp://127.0.0.1:4999") == 0); - So(nng_listener_get_bool(l, NNG_OPT_TCP_KEEPALIVE, &v) == - 0); + So(nng_listener_get_bool(l, NNG_OPT_TCP_KEEPALIVE, &v) == 0); So(v == false); x = 1; So(nng_listener_set_int(l, NNG_OPT_TCP_KEEPALIVE, x) == From 08a14438c28057844d5f894251d9577b9ded5f3c Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 21 Apr 2024 12:23:07 -0700 Subject: [PATCH 09/22] Logging improvements (#1816) * Add nng_str_sockaddr to get string representation of socket address. * Added nng_log_get_level() is meant to allow users to obtain the current level and avoid some possibly expensive operations just to collect debugging information when debugging is not in effect. We use a custom logger for NUTS, and this fits within the NUTS test framework well, so that if -v is supplied we get more content. All tests now get this by default. Signed-off-by: jaylin --- docs/man/CMakeLists.txt | 6 +- docs/man/nng_log_get_level.3.adoc | 42 +++++ ...et_level.adoc => nng_log_set_level.3.adoc} | 1 + ..._logger.adoc => nng_log_set_logger.3.adoc} | 0 docs/man/nng_str_sockaddr.3.adoc | 52 ++++++ include/nng/nng.h | 40 ++-- src/core/CMakeLists.txt | 2 + src/core/dialer.c | 11 +- src/core/listener.c | 26 ++- src/core/log.c | 7 +- src/core/pipe.c | 14 +- src/core/pipe.h | 5 +- src/core/sockaddr.c | 165 ++++++++++++++++ src/core/sockaddr_test.c | 176 ++++++++++++++++++ src/core/socket.c | 24 ++- src/sp/transport/ipc/ipc.c | 13 ++ src/sp/transport/ipc/ipc_test.c | 32 ++-- src/sp/transport/tcp/tcp.c | 15 ++ src/sp/transport/tcp/tcp_test.c | 27 ++- src/sp/transport/tls/tls.c | 14 ++ src/sp/transport/ws/ws_test.c | 4 +- src/testing/acutest.h | 35 +++- src/testing/nuts.h | 9 + src/testing/util.c | 48 ++++- 24 files changed, 701 insertions(+), 67 deletions(-) create mode 100644 docs/man/nng_log_get_level.3.adoc rename docs/man/{nng_log_set_level.adoc => nng_log_set_level.3.adoc} (95%) rename docs/man/{nng_log_set_logger.adoc => nng_log_set_logger.3.adoc} (100%) create mode 100644 docs/man/nng_str_sockaddr.3.adoc create mode 100644 src/core/sockaddr.c create mode 100644 src/core/sockaddr_test.c diff --git a/docs/man/CMakeLists.txt b/docs/man/CMakeLists.txt index 7f47f006..6db3318f 100644 --- a/docs/man/CMakeLists.txt +++ b/docs/man/CMakeLists.txt @@ -1,5 +1,5 @@ # -# Copyright 2020 Staysail Systems, Inc. +# Copyright 2024 Staysail Systems, Inc. # Copyright 2018 Capitar IT Group BV # Copyright 2019 Devolutions # @@ -116,8 +116,9 @@ if (NNG_ENABLE_DOC) nng_listener_setopt nng_listener_start nng_log + nng_log_get_level nng_log_set_facility - nng_log_set_loevel + nng_log_set_level nng_log_set_logger nng_msg_alloc nng_msg_append @@ -181,6 +182,7 @@ if (NNG_ENABLE_DOC) nng_stat_type nng_stat_unit nng_stat_value + nng_str_sockaddr nng_strdup nng_strerror nng_strfree diff --git a/docs/man/nng_log_get_level.3.adoc b/docs/man/nng_log_get_level.3.adoc new file mode 100644 index 00000000..7ff90906 --- /dev/null +++ b/docs/man/nng_log_get_level.3.adoc @@ -0,0 +1,42 @@ += nng_log_get_level(3) +// +// Copyright 2024 Staysail Systems, Inc. +// +// This document is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +== NAME + +nng_log_get_level - get minimum level for logging messagse + +== SYNOPSIS + +[source, c] +---- +#include + +typedef enum nng_log_level { + NNG_LOG_NONE = 0, // used for filters only, NNG suppresses these + NNG_LOG_ERR = 3, + NNG_LOG_WARN = 4, + NNG_LOG_NOTICE = 5, + NNG_LOG_INFO = 6, + NNG_LOG_DEBUG = 7 +} nng_log_level; + +nng_log_level nng_log_set_level(void); +---- + +== DESCRIPTION + +The `nng_log_get_level` function is used to get the minimum severity to _level_ for processing log messages. +The intended use case is to avoid expensive operations used solely to provide debugging information in logs, +if the logged content would merely be discarded. + +== SEE ALSO + +xref:nng_log_set_facility.3.adoc[nng_log_set_facility(3)], +xref:nng_log_set_level.3.adoc[nng_log_set_level(3)] diff --git a/docs/man/nng_log_set_level.adoc b/docs/man/nng_log_set_level.3.adoc similarity index 95% rename from docs/man/nng_log_set_level.adoc rename to docs/man/nng_log_set_level.3.adoc index 012f93f8..5501e9ce 100644 --- a/docs/man/nng_log_set_level.adoc +++ b/docs/man/nng_log_set_level.3.adoc @@ -39,4 +39,5 @@ Use `NNG_LOG_DEBUG` to receive all log messages. == SEE ALSO +xref:nng_log_get_level.3.adoc[nng_log_set_level(3)] xref:nng_log_set_facility.3.adoc[nng_log_set_facility(3)] diff --git a/docs/man/nng_log_set_logger.adoc b/docs/man/nng_log_set_logger.3.adoc similarity index 100% rename from docs/man/nng_log_set_logger.adoc rename to docs/man/nng_log_set_logger.3.adoc diff --git a/docs/man/nng_str_sockaddr.3.adoc b/docs/man/nng_str_sockaddr.3.adoc new file mode 100644 index 00000000..03999d1a --- /dev/null +++ b/docs/man/nng_str_sockaddr.3.adoc @@ -0,0 +1,52 @@ += nng_str_sockaddr(3) +// +// Copyright 2024 Staysail Systems, Inc. +// +// This document is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +== NAME + + +nng_str_sockaddr - get string representation of socket address + +== SYNOPSIS + +[source, c] +---- +#include + +#define NNG_MAXADDRSTRLEN (NNG_MAXADDRLEN+16) +const char *nng_str_sockaddr(const nng_sockaddr *sa, char *buf, size_t bufsz) +---- + +== DESCRIPTION + +The `nng_str_sockaddr()` is used to provide a displayable representation +for the socket address _sa_. +The content will be stored the location provided by _buf_, and will be +formatted to fit within _bufsz_ bytes, truncating if necessary. + +As long as _bufsz_ is greater than zero, the result will be properly +zero-terminated in the usual fashion. + +The `NNG_MAXADDRSTRLEN` can be used to provide a buffer large enough to hold most socket addresses. +It is possible for applications to use very much larger socket addresses (using very long paths +for IPC or inproc), but such addresses are not generally compatible with other implementations, +and will be truncated here. + +== RETURN VALUES + +This function returns the _buf_ argument. + +== ERRORS + +None. + +== SEE ALSO + +[.text-left] +xref:nng_sockaddr.5.adoc[nng_sockaddr(5)] diff --git a/include/nng/nng.h b/include/nng/nng.h index b11b7317..23ccd440 100644 --- a/include/nng/nng.h +++ b/include/nng/nng.h @@ -250,6 +250,17 @@ NNG_DECL int nng_socket_get_ptr(nng_socket, const char *, void **); NNG_DECL int nng_socket_get_ms(nng_socket, const char *, nng_duration *); NNG_DECL int nng_socket_get_addr(nng_socket, const char *, nng_sockaddr *); +// Utility function for getting a printable form of the socket address +// for display in logs, etc. It is not intended to be parsed, and the +// display format may change without notice. Generally you should alow +// at least NNG_MAXADDRSTRLEN if you want to avoid typical truncations. +// It is still possible for very long IPC paths to be truncated, but that +// is an edge case and applications that pass such long paths should +// expect some truncation (but they may pass larger values). +#define NNG_MAXADDRSTRLEN (NNG_MAXADDRLEN + 16) // extra bytes for scheme +NNG_DECL const char *nng_str_sockaddr( + const nng_sockaddr *sa, char *buf, size_t bufsz); + // Arguably the pipe callback functions could be handled as an option, // but with the need to specify an argument, we find it best to unify // this as a separate function to pass in the argument and the callback. @@ -1634,11 +1645,11 @@ typedef void (*nng_logger)(nng_log_level level, nng_log_facility facility, const char *msgid, const char *msg); // Discard logger, simply throws logs away. -extern void nng_null_logger( +NNG_DECL void nng_null_logger( nng_log_level, nng_log_facility, const char *, const char *); // Very simple, prints formatted messages to stderr. -extern void nng_stderr_logger( +NNG_DECL void nng_stderr_logger( nng_log_level, nng_log_facility, const char *, const char *); // Performs an appropriate logging function for the system. On @@ -1646,32 +1657,37 @@ extern void nng_stderr_logger( // logging may be influenced by other APIs not provided by NNG, such as // openlog() for POSIX systems. This may be nng_stderr_logger on // other systems. -extern void nng_system_logger( +NNG_DECL void nng_system_logger( nng_log_level, nng_log_facility, const char *, const char *); // Set the default facility to use when logging. NNG uses NNG_LOG_USER by // default. -extern void nng_log_set_facility(nng_log_facility facility); +NNG_DECL void nng_log_set_facility(nng_log_facility facility); // Set the default logging level. Use NNG_LOG_DEBUG to get everything. // Use NNG_LOG_NONE to prevent logging altogether. Logs that are less // severe (numeric level is higher) will be discarded. -extern void nng_log_set_level(nng_log_level level); +NNG_DECL void nng_log_set_level(nng_log_level level); + +// Get the current logging level. The intention here os to allow +// bypassing expensive formatting operations that will be discarded +// anyway. +NNG_DECL nng_log_level nng_log_get_level(void); // Register a logger. -extern void nng_log_set_logger(nng_logger logger); +NNG_DECL void nng_log_set_logger(nng_logger logger); // Log a message. The msg is formatted using following arguments as per // sprintf. The msgid may be NULL. -extern void nng_log_err(const char *msgid, const char *msg, ...); -extern void nng_log_warn(const char *msgid, const char *msg, ...); -extern void nng_log_notice(const char *msgid, const char *msg, ...); -extern void nng_log_info(const char *msgid, const char *msg, ...); -extern void nng_log_debug(const char *msgid, const char *msg, ...); +NNG_DECL void nng_log_err(const char *msgid, const char *msg, ...); +NNG_DECL void nng_log_warn(const char *msgid, const char *msg, ...); +NNG_DECL void nng_log_notice(const char *msgid, const char *msg, ...); +NNG_DECL void nng_log_info(const char *msgid, const char *msg, ...); +NNG_DECL void nng_log_debug(const char *msgid, const char *msg, ...); // Log an authentication related message. These will use the NNG_LOG_AUTH // facility. -extern void nng_log_auth( +NNG_DECL void nng_log_auth( nng_log_level level, const char *msgid, const char *msg, ...); #ifdef __cplusplus diff --git a/src/core/CMakeLists.txt b/src/core/CMakeLists.txt index 48b25265..90ef4023 100644 --- a/src/core/CMakeLists.txt +++ b/src/core/CMakeLists.txt @@ -57,6 +57,7 @@ nng_sources( protocol.h reap.c reap.h + sockaddr.c socket.c socket.h sockimpl.h @@ -86,5 +87,6 @@ nng_test(log_test) nng_test(message_test) nng_test(reconnect_test) nng_test(sock_test) +nng_test(sockaddr_test) nng_test(stats_test) nng_test(url_test) diff --git a/src/core/dialer.c b/src/core/dialer.c index fde072b2..1295fbfc 100644 --- a/src/core/dialer.c +++ b/src/core/dialer.c @@ -1,5 +1,5 @@ // -// Copyright 2023 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // Copyright 2018 Devolutions // @@ -389,8 +389,10 @@ dialer_connect_cb(void *arg) case NNG_ECONNREFUSED: case NNG_ETIMEDOUT: default: - nng_log_warn("NNG-CONN-FAIL", "Failed connecting to %s: %s", - d->d_url->u_rawurl, nng_strerror(rv)); + nng_log_warn("NNG-CONN-FAIL", + "Failed connecting socket<%u> to %s: %s", + nni_sock_id(d->d_sock), d->d_url->u_rawurl, + nng_strerror(rv)); nni_dialer_bump_error(d, rv); if (user_aio == NULL) { @@ -442,6 +444,9 @@ nni_dialer_start(nni_dialer *d, unsigned flags) nni_aio_free(aio); } + nng_log_info("NNG-DIAL", "Starting dialer for socket<%u> on %s", + nni_sock_id(d->d_sock), d->d_url->u_rawurl); + return (rv); } diff --git a/src/core/listener.c b/src/core/listener.c index a020079d..65fe5a9f 100644 --- a/src/core/listener.c +++ b/src/core/listener.c @@ -1,5 +1,5 @@ // -// Copyright 2023 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // Copyright 2018 Devolutions // @@ -11,6 +11,7 @@ #include "core/nng_impl.h" #include "core/strs.h" +#include "nng/nng.h" #include "sockimpl.h" #include @@ -364,8 +365,10 @@ listener_accept_cb(void *arg) case NNG_ECONNRESET: // remote condition, no cool down case NNG_ETIMEDOUT: // No need to sleep, we timed out already. case NNG_EPEERAUTH: // peer validation failure - nng_log_warn("NNG-ACCEPT-FAIL", "Failed accepting on %s: %s", - l->l_url->u_rawurl, nng_strerror(rv)); + nng_log_warn("NNG-ACCEPT-FAIL", + "Failed accepting for socket<%u> on %s: %s", + nni_sock_id(l->l_sock), l->l_url->u_rawurl, + nng_strerror(rv)); nni_listener_bump_error(l, rv); listener_accept_start(l); break; @@ -395,7 +398,9 @@ listener_accept_start(nni_listener *l) int nni_listener_start(nni_listener *l, int flags) { - int rv; + int rv; + char *url; + size_t sz; NNI_ARG_UNUSED(flags); if (nni_atomic_flag_test_and_set(&l->l_started)) { @@ -403,12 +408,21 @@ nni_listener_start(nni_listener *l, int flags) } if ((rv = l->l_ops.l_bind(l->l_data)) != 0) { - nng_log_warn("NNG-BIND-FAIL", "Failed binding to %s: %s", - l->l_url->u_rawurl, nng_strerror(rv)); + nng_log_warn("NNG-BIND-FAIL", + "Failed binding socket<%u> to %s: %s", + nni_sock_id(l->l_sock), l->l_url->u_rawurl, + nng_strerror(rv)); nni_listener_bump_error(l, rv); nni_atomic_flag_reset(&l->l_started); return (rv); } + // collect the URL which may have changed (e.g. binding to port 0) + sz = sizeof(url); + (void) (nni_listener_getopt( + l, NNG_OPT_URL, &url, &sz, NNI_TYPE_STRING)); + nng_log_info("NNG-LISTEN", "Starting listener for socket<%u> on %s", + nni_sock_id(l->l_sock), url); + nni_strfree(url); listener_accept_start(l); diff --git a/src/core/log.c b/src/core/log.c index cef3169c..e415e159 100644 --- a/src/core/log.c +++ b/src/core/log.c @@ -37,6 +37,12 @@ nng_log_set_level(nng_log_level level) log_level = level; } +nng_log_level +nng_log_get_level(void) +{ + return (log_level); +} + void nng_log_set_logger(nng_logger logger) { @@ -54,7 +60,6 @@ nng_null_logger(nng_log_level level, nng_log_facility facility, NNI_ARG_UNUSED(facility); NNI_ARG_UNUSED(msgid); NNI_ARG_UNUSED(msg); - return; } void diff --git a/src/core/pipe.c b/src/core/pipe.c index 2bb98972..1e2842dc 100644 --- a/src/core/pipe.c +++ b/src/core/pipe.c @@ -1,5 +1,5 @@ // -// Copyright 2023 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // Copyright 2018 Devolutions // @@ -10,6 +10,7 @@ // #include "core/nng_impl.h" +#include "nng/nng.h" #include "sockimpl.h" #include @@ -409,3 +410,14 @@ nni_pipe_bump_error(nni_pipe *p, int err) nni_listener_bump_error(p->p_listener, err); } } + +char * +nni_pipe_peer_addr(nni_pipe *p, char buf[NNG_MAXADDRSTRLEN]) +{ + nng_sockaddr sa; + size_t sz = sizeof(sa); + sa.s_family = AF_UNSPEC; + nni_pipe_getopt(p, NNG_OPT_REMADDR, &sa, &sz, NNI_TYPE_SOCKADDR); + nng_str_sockaddr(&sa, buf, NNG_MAXADDRSTRLEN); + return (buf); +} diff --git a/src/core/pipe.h b/src/core/pipe.h index 458a42d9..a1bc361e 100644 --- a/src/core/pipe.h +++ b/src/core/pipe.h @@ -1,5 +1,5 @@ // -// Copyright 2021 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // // This software is supplied under the terms of the MIT License, a @@ -17,6 +17,7 @@ #include "core/defs.h" #include "core/thread.h" +#include "nng/nng.h" #include "sp/transport.h" // AIO @@ -61,4 +62,6 @@ extern void nni_pipe_bump_rx(nni_pipe *, size_t); extern void nni_pipe_bump_tx(nni_pipe *, size_t); extern void nni_pipe_bump_error(nni_pipe *, int); +extern char *nni_pipe_peer_addr(nni_pipe *p, char buf[NNG_MAXADDRSTRLEN]); + #endif // CORE_PIPE_H diff --git a/src/core/sockaddr.c b/src/core/sockaddr.c new file mode 100644 index 00000000..50fd4214 --- /dev/null +++ b/src/core/sockaddr.c @@ -0,0 +1,165 @@ +// +// Copyright 2024 Staysail Systems, Inc. +// +// This software is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +#include "core/nng_impl.h" +#include "nng/nng.h" + +#include +#include + +static const char * +str_sa_inproc(const nng_sockaddr_inproc *sa, char *buf, size_t bufsz) +{ + snprintf(buf, bufsz, "inproc[%s]", sa->sa_name); + return buf; +} + +static const char * +str_sa_inet(const nng_sockaddr_in *sa, char *buf, size_t bufsz) +{ + uint8_t *a_bytes = (uint8_t *) &sa->sa_addr; + uint8_t *p_bytes = (uint8_t *) &sa->sa_port; + + snprintf(buf, bufsz, "%u.%u.%u.%u:%u", a_bytes[0], a_bytes[1], + a_bytes[2], a_bytes[3], + (((uint16_t) p_bytes[0]) << 8) + p_bytes[1]); + return (buf); +} + +// emit an IPv6 address in "short form" +static char * +nni_inet_ntop(const uint8_t addr[16], char buf[46]) +{ + + const uint8_t v4map[12] = { 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0xff, 0xff }; + + if (memcmp(addr, v4map, 12) == 0) { + snprintf(buf, 46, "::ffff:%u.%u.%u.%u", addr[12], addr[13], + addr[14], addr[15]); + return (buf); + } + + uint8_t off = 0; // offset of first set of elided zeros + uint8_t cnt = 0; // how many elided zeros so far + uint8_t maxoff = 0; // offset of largest compressed region + uint8_t maxcnt = 0; // how many elided zeros at maxoff + + // look for the largest compressible region + for (uint8_t i = 0; i < 16; i += 2) { + // is this word zero? + if ((addr[i] == 0) && (addr[i + 1] == 0)) { + cnt += 2; + // if this was the first zero word in region, record it + if (cnt == 2) { + off = i; + } + // possibly update the maximums + if (cnt > maxcnt) { + maxcnt = cnt; + maxoff = off; + } + } else { + cnt = 0; + } + } + if (maxcnt < 2) { + maxoff = 0xff; // too big for anything + } + + int idx = 0; + bool sep = false; + buf[0] = 0; + for (uint8_t i = 0; i < 16; i += 2) { + // We have 46 bytes allocated, which is a "theoretical" + // maximum only. In practice the worst case is really + // 8 groups of four digits with 7 colons, so 39 bytes plus + // the null is 40 bytes. We only use the v4 mapped syntax + // when presented with ::ffff: - so 23 bytes for that syntax. + if (i == maxoff) { + NNI_ASSERT(idx <= 43); + strcat(buf + idx, "::"); + idx += 2; + sep = false; + } else if (i < maxoff || i >= maxoff + maxcnt) { + // this takes at most six bytes -- four hax digits a + // colon, and a null + NNI_ASSERT(idx <= 40); + snprintf(buf + idx, 6, sep ? ":%x" : "%x", + (((uint16_t) addr[i]) << 8) + addr[i + 1]); + idx += strlen(buf + idx); + sep = true; + } + } + return (buf); +} + +static const char * +str_sa_inet6(const nng_sockaddr_in6 *sa, char *buf, size_t bufsz) +{ + const uint8_t *p_bytes = (uint8_t *) &sa->sa_port; + char istr[46]; + + if (sa->sa_scope) { + snprintf(buf, bufsz, "[%s%%%u]:%u", + nni_inet_ntop(sa->sa_addr, istr), sa->sa_scope, + (((uint16_t) (p_bytes[0])) << 8) + p_bytes[1]); + } else { + snprintf(buf, bufsz, "[%s]:%u", + nni_inet_ntop(sa->sa_addr, istr), + (((uint16_t) (p_bytes[0])) << 8) + p_bytes[1]); + } + return (buf); +} + +static const char * +str_sa_ipc(const nng_sockaddr_ipc *sa, char *buf, size_t bufsz) +{ + // does not deal well with embedded "{}" chars + snprintf(buf, bufsz, "%s", sa->sa_path); + return (buf); +} + +static const char * +str_sa_abstract(const nng_sockaddr_abstract *sa, char *buf, size_t bufsz) +{ + // does not deal well with embedded "{}" chars + snprintf(buf, bufsz, "abstract[%s]", sa->sa_name); + return (buf); +} + +static const char * +str_sa_zt(const nng_sockaddr_zt *sa, char *buf, size_t bufsz) +{ + snprintf(buf, bufsz, "ZT[%llx:%llx:%u]", + (unsigned long long) sa->sa_nodeid, + (unsigned long long) sa->sa_nwid, sa->sa_port); + return (buf); +} + +const char * +nng_str_sockaddr(const nng_sockaddr *sa, char *buf, size_t bufsz) +{ + switch (sa->s_family) { + case NNG_AF_INPROC: + return (str_sa_inproc(&sa->s_inproc, buf, bufsz)); + case NNG_AF_INET: + return (str_sa_inet(&sa->s_in, buf, bufsz)); + case NNG_AF_INET6: + return (str_sa_inet6(&sa->s_in6, buf, bufsz)); + case NNG_AF_IPC: + return (str_sa_ipc(&sa->s_ipc, buf, bufsz)); + case NNG_AF_ABSTRACT: + return (str_sa_abstract(&sa->s_abstract, buf, bufsz)); + case NNG_AF_ZT: + return (str_sa_zt(&sa->s_zt, buf, bufsz)); + case NNG_AF_UNSPEC: + default: + return ("unknown"); + } +} diff --git a/src/core/sockaddr_test.c b/src/core/sockaddr_test.c new file mode 100644 index 00000000..0e05fc79 --- /dev/null +++ b/src/core/sockaddr_test.c @@ -0,0 +1,176 @@ +// +// Copyright 2024 Staysail Systems, Inc. +// +// This software is supplied under the terms of the MIT License, a +// copy of which should be located in the distribution where this +// file was obtained (LICENSE.txt). A copy of the license may also be +// found online at https://opensource.org/licenses/MIT. +// + +#include +#include + +#include "nuts.h" +#include + +#ifndef _WIN32 +#include // for endianness functions +#endif + +void +test_sa_ipc(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_ipc.sa_family = NNG_AF_IPC; + snprintf(sa.s_ipc.sa_path, sizeof(sa.s_ipc.sa_path), "/tmp/something"); + NUTS_ASSERT(strcmp(nng_str_sockaddr(&sa, addr, sizeof(addr)), + "/tmp/something") == 0); +} + +void +test_sa_abstract(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_abstract.sa_family = NNG_AF_ABSTRACT; + snprintf((char *) sa.s_abstract.sa_name, sizeof(sa.s_abstract.sa_name), + "something"); + NUTS_ASSERT(strcmp(nng_str_sockaddr(&sa, addr, sizeof(addr)), + "abstract[something]") == 0); +} + +void +test_sa_inproc(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_inproc.sa_family = NNG_AF_INPROC; + snprintf((char *) sa.s_inproc.sa_name, sizeof(sa.s_inproc.sa_name), + "something"); + nng_str_sockaddr(&sa, addr, sizeof(addr)); + nng_log_debug(NULL, "address is %s", addr); + NUTS_ASSERT(strcmp(addr, "inproc[something]") == 0); +} + +void +test_sa_inet(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_in.sa_family = NNG_AF_INET; + sa.s_in.sa_addr = htonl(0x7F000001); + sa.s_in.sa_port = htons(80); + NUTS_ASSERT(strcmp(nng_str_sockaddr(&sa, addr, sizeof(addr)), + "127.0.0.1:80") == 0); +} + +void +test_sa_inet6(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_in.sa_family = NNG_AF_INET6; + memset(sa.s_in6.sa_addr, 0, sizeof(sa.s_in6.sa_addr)); + sa.s_in6.sa_addr[15] = 1; // loopback + sa.s_in6.sa_scope = 0; + sa.s_in6.sa_port = htons(80); + nng_str_sockaddr(&sa, addr, sizeof(addr)); + nng_log_debug(NULL, "address is %s", addr); + NUTS_ASSERT(strcmp(addr, "[::1]:80") == 0); +} + +void +test_sa_inet6_v4_mapped(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_in.sa_family = NNG_AF_INET6; + memset(sa.s_in6.sa_addr, 0, sizeof(sa.s_in6.sa_addr)); + sa.s_in6.sa_addr[10] = 0xff; + sa.s_in6.sa_addr[11] = 0xff; + sa.s_in6.sa_addr[12] = 192; + sa.s_in6.sa_addr[13] = 168; + sa.s_in6.sa_addr[14] = 1; + sa.s_in6.sa_addr[15] = 100; + sa.s_in6.sa_scope = 0; + sa.s_in6.sa_port = htons(80); + nng_str_sockaddr(&sa, addr, sizeof(addr)); + nng_log_debug(NULL, "address is %s", addr); + NUTS_ASSERT(strcmp(addr, "[::ffff:192.168.1.100]:80") == 0); +} + +void +test_sa_inet6_ll(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_in.sa_family = NNG_AF_INET6; + memset(sa.s_in6.sa_addr, 0, sizeof(sa.s_in6.sa_addr)); + sa.s_in6.sa_addr[0] = 0xfe; + sa.s_in6.sa_addr[1] = 0x80; + sa.s_in6.sa_addr[15] = 4; + sa.s_in6.sa_scope = 0; + sa.s_in6.sa_port = htons(80); + sa.s_in6.sa_scope = 2; // link local addresses have a non-zero scope + nng_str_sockaddr(&sa, addr, sizeof(addr)); + nng_log_debug(NULL, "address is %s", addr); + NUTS_ASSERT(strcmp(addr, "[fe80::4%2]:80") == 0); +} + +void +test_sa_inet6_zero(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_in6.sa_family = NNG_AF_INET6; + memset(sa.s_in6.sa_addr, 0, sizeof(sa.s_in6.sa_addr)); + sa.s_in6.sa_port = htons(80); + sa.s_in6.sa_scope = 0; + nng_str_sockaddr(&sa, addr, sizeof(addr)); + nng_log_debug(NULL, "address is %s", addr); + NUTS_ASSERT(strcmp(addr, "[::]:80") == 0); +} + +void +test_sa_inet6_net(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_in6.sa_family = NNG_AF_INET6; + memset(sa.s_in6.sa_addr, 0, sizeof(sa.s_in6.sa_addr)); + sa.s_in6.sa_port = htons(80); + sa.s_in6.sa_addr[0] = 0xfc; + sa.s_in6.sa_scope = 0; + nng_str_sockaddr(&sa, addr, sizeof(addr)); + nng_log_debug(NULL, "address is %s", addr); + NUTS_ASSERT(strcmp(addr, "[fc00::]:80") == 0); +} + +void +test_sa_zt(void) +{ + nng_sockaddr sa; + char addr[NNG_MAXADDRSTRLEN]; + sa.s_zt.sa_family = NNG_AF_ZT; + sa.s_zt.sa_nodeid = 0xa; + sa.s_zt.sa_nwid = 0xb; + sa.s_zt.sa_port = 1 << 20; + nng_str_sockaddr(&sa, addr, sizeof(addr)); + nng_log_debug(NULL, "address is %s", addr); + NUTS_ASSERT(strcmp(addr, "ZT[a:b:1048576]") == 0); +} + +TEST_LIST = { + { "nng_sockaddr_ipc", test_sa_ipc }, + { "nng_sockaddr_abstract", test_sa_abstract }, + { "nng_sockaddr_inproc", test_sa_inproc }, + { "nng_sockaddr_in", test_sa_inet }, + { "nng_sockaddr_in6", test_sa_inet6 }, + { "nng_sockaddr_in6 v4 mapped", test_sa_inet6_v4_mapped }, + { "nng_sockaddr_in6 link local", test_sa_inet6_ll }, + { "nng_sockaddr_in6 zero", test_sa_inet6_zero }, + { "nng_sockaddr_in6 subnet", test_sa_inet6_net }, + { "nng_sockaddr_zt", test_sa_zt }, + { NULL, NULL }, +}; diff --git a/src/core/socket.c b/src/core/socket.c index 6bd9887e..1e374121 100644 --- a/src/core/socket.c +++ b/src/core/socket.c @@ -1,5 +1,5 @@ // -// Copyright 2023 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // // This software is supplied under the terms of the MIT License, a @@ -9,9 +9,9 @@ // #include "core/nng_impl.h" +#include "core/pipe.h" #include "list.h" #include "nng/nng.h" -#include "nng/supplemental/tls/tls.h" #include "sockimpl.h" #include @@ -1527,8 +1527,12 @@ nni_dialer_add_pipe(nni_dialer *d, void *tpipe) nni_stat_inc(&d->st_reject, 1); nni_stat_inc(&s->st_rejects, 1); #endif - nng_log_debug("NNG-PIPEREJECT", - "Pipe closed by pipe callback before added to socket"); + if (nng_log_get_level() >= NNG_LOG_DEBUG) { + char addr[NNG_MAXADDRSTRLEN]; + nng_log_debug("NNG-PIPEREJECT", + "Pipe on socket<%u> from %s rejected by callback", + nni_pipe_sock_id(p), nni_pipe_peer_addr(p, addr)); + } nni_pipe_rele(p); return; } @@ -1548,6 +1552,12 @@ nni_dialer_add_pipe(nni_dialer *d, void *tpipe) nni_stat_register(&p->st_root); #endif nni_pipe_run_cb(p, NNG_PIPE_EV_ADD_POST); + if (nng_log_get_level() >= NNG_LOG_DEBUG) { + char addr[NNG_MAXADDRSTRLEN]; + nng_log_debug("NNG-CONNECT", + "Connected pipe<%u> on socket<%u> to %s", nni_pipe_id(p), + nni_sock_id(s), nni_pipe_peer_addr(p, addr)); + } nni_pipe_rele(p); } @@ -1658,6 +1668,12 @@ nni_listener_add_pipe(nni_listener *l, void *tpipe) nni_stat_register(&p->st_root); #endif nni_pipe_run_cb(p, NNG_PIPE_EV_ADD_POST); + if (nng_log_get_level() >= NNG_LOG_DEBUG) { + char addr[NNG_MAXADDRSTRLEN]; + nng_log_debug("NNG-ACCEPT", + "Accepted pipe<%u> on socket<%u> from %s", nni_pipe_id(p), + nni_sock_id(s), nni_pipe_peer_addr(p, addr)); + } nni_pipe_rele(p); } diff --git a/src/sp/transport/ipc/ipc.c b/src/sp/transport/ipc/ipc.c index 85ccd658..50490e64 100644 --- a/src/sp/transport/ipc/ipc.c +++ b/src/sp/transport/ipc/ipc.c @@ -382,6 +382,19 @@ ipc_pipe_recv_cb(void *arg) // Make sure the message payload is not too big. If it is // the caller will shut down the pipe. if ((len > p->rcv_max) && (p->rcv_max > 0)) { + uint64_t pid; + char peer[64] = ""; + if (nng_stream_get_uint64( + p->conn, NNG_OPT_PEER_PID, &pid) == 0) { + snprintf(peer, sizeof(peer), " from PID %lu", + (unsigned long) pid); + } + nng_log_warn("NNG-RCVMAX", + "Oversize message of %lu bytes (> %lu) " + "on socket<%u> pipe<%u> from IPC%s", + (unsigned long) len, (unsigned long) p->rcv_max, + nni_pipe_sock_id(p->pipe), nni_pipe_id(p->pipe), + peer); rv = NNG_EMSGSIZE; goto error; } diff --git a/src/sp/transport/ipc/ipc_test.c b/src/sp/transport/ipc/ipc_test.c index b39aa937..3936a750 100644 --- a/src/sp/transport/ipc/ipc_test.c +++ b/src/sp/transport/ipc/ipc_test.c @@ -42,7 +42,7 @@ test_ipc_dialer_perms(void) { nng_socket s; nng_dialer d; - char * addr; + char *addr; NUTS_ADDR(addr, "ipc"); NUTS_OPEN(s); @@ -59,7 +59,7 @@ test_ipc_dialer_properties(void) nng_dialer d; nng_sockaddr sa; size_t z; - char *addr; + char *addr; NUTS_ADDR(addr, "ipc"); NUTS_OPEN(s); @@ -84,10 +84,10 @@ test_ipc_listener_perms(void) { nng_socket s; nng_listener l; - char *addr; + char *addr; #ifndef _WIN32 - char * path; + char *path; struct stat st; #endif @@ -125,7 +125,7 @@ test_ipc_listener_properties(void) nng_listener l; nng_sockaddr sa; size_t z; - char *addr; + char *addr; NUTS_ADDR(addr, "ipc"); NUTS_OPEN(s); @@ -154,8 +154,9 @@ test_ipc_recv_max(void) nng_socket s1; nng_listener l; size_t sz; - char *addr; + char *addr; + NUTS_ENABLE_LOG(NNG_LOG_INFO); NUTS_ADDR(addr, "ipc"); NUTS_OPEN(s0); NUTS_PASS(nng_socket_set_ms(s0, NNG_OPT_RECVTIMEO, 100)); @@ -184,12 +185,12 @@ test_abstract_sockets(void) #ifdef NNG_HAVE_ABSTRACT_SOCKETS nng_socket s1; nng_socket s2; - char *addr; + char *addr; nng_pipe p1; nng_pipe p2; nng_sockaddr sa1; nng_sockaddr sa2; - char * prefix = "abstract://"; + char *prefix = "abstract://"; NUTS_ADDR(addr, "abstract"); NUTS_OPEN(s1); @@ -341,7 +342,7 @@ test_unix_alias(void) char rng[20]; nng_sockaddr sa1; nng_sockaddr sa2; - nng_msg * msg; + nng_msg *msg; nng_pipe p; // Presumes /tmp. @@ -385,11 +386,11 @@ test_ipc_pipe_peer(void) #ifdef NNG_PLATFORM_POSIX // this test verifies that closing a socket peer // during negotiation is ok. - nng_socket s0, s1; - nng_msg *msg; - nng_pipe p; - uint64_t id; - char *addr; + nng_socket s0, s1; + nng_msg *msg; + nng_pipe p; + uint64_t id; + char *addr; NUTS_ADDR(addr, "ipc"); NUTS_OPEN(s0); @@ -432,7 +433,6 @@ test_ipc_pipe_peer(void) #endif // NNG_PLATFORM_POSIX } - TEST_LIST = { { "ipc path too long", test_path_too_long }, { "ipc dialer perms", test_ipc_dialer_perms }, @@ -447,4 +447,4 @@ TEST_LIST = { { "ipc unix alias", test_unix_alias }, { "ipc peer id", test_ipc_pipe_peer }, { NULL, NULL }, -}; \ No newline at end of file +}; diff --git a/src/sp/transport/tcp/tcp.c b/src/sp/transport/tcp/tcp.c index 5095c8c9..cf437ed3 100644 --- a/src/sp/transport/tcp/tcp.c +++ b/src/sp/transport/tcp/tcp.c @@ -13,6 +13,7 @@ #include #include "core/nng_impl.h" +#include "nng/nng.h" // TCP transport. Platform specific TCP operations must be // supplied as well. @@ -387,6 +388,20 @@ tcptran_pipe_recv_cb(void *arg) // Make sure the message payload is not too big. If it is // the caller will shut down the pipe. if ((len > p->rcvmax) && (p->rcvmax > 0)) { + nng_sockaddr_storage ss; + nng_sockaddr *sa = (nng_sockaddr *) &ss; + char peername[64] = "unknown"; + if ((rv = nng_stream_get_addr( + p->conn, NNG_OPT_REMADDR, sa)) == 0) { + (void) nng_str_sockaddr( + sa, peername, sizeof(peername)); + } + nng_log_warn("NNG-RCVMAX", + "Oversize message of %lu bytes (> %lu) " + "on socket<%u> pipe<%u> from TCP %s", + (unsigned long) len, (unsigned long) p->rcvmax, + nni_pipe_sock_id(p->npipe), nni_pipe_id(p->npipe), + peername); rv = NNG_EMSGSIZE; goto recv_error; } diff --git a/src/sp/transport/tcp/tcp_test.c b/src/sp/transport/tcp/tcp_test.c index 16c70d7d..005fd2b0 100644 --- a/src/sp/transport/tcp/tcp_test.c +++ b/src/sp/transport/tcp/tcp_test.c @@ -1,5 +1,5 @@ // -// Copyright 2020 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // Copyright 2018 Devolutions // Copyright 2018 Cody Piersall @@ -10,7 +10,6 @@ // found online at https://opensource.org/licenses/MIT. // - #include // TCP tests. @@ -75,7 +74,7 @@ test_tcp_port_zero_bind(void) nng_socket s2; nng_sockaddr sa; nng_listener l; - char * addr; + char *addr; NUTS_OPEN(s1); NUTS_OPEN(s2); @@ -96,7 +95,7 @@ void test_tcp_bad_local_interface(void) { nng_socket s1; - int rv; + int rv; NUTS_OPEN(s1); rv = nng_dial(s1, "tcp://bogus1;127.0.0.1:80", NULL, 0), @@ -122,12 +121,9 @@ test_tcp_malformed_address(void) nng_socket s1; NUTS_OPEN(s1); - NUTS_FAIL( - nng_dial(s1, "tcp://127.0.0.1", NULL, 0), NNG_EADDRINVAL); - NUTS_FAIL( - nng_dial(s1, "tcp://127.0.0.1.32", NULL, 0), NNG_EADDRINVAL); - NUTS_FAIL( - nng_dial(s1, "tcp://127.0.x.1.32", NULL, 0), NNG_EADDRINVAL); + NUTS_FAIL(nng_dial(s1, "tcp://127.0.0.1", NULL, 0), NNG_EADDRINVAL); + NUTS_FAIL(nng_dial(s1, "tcp://127.0.0.1.32", NULL, 0), NNG_EADDRINVAL); + NUTS_FAIL(nng_dial(s1, "tcp://127.0.x.1.32", NULL, 0), NNG_EADDRINVAL); NUTS_FAIL( nng_listen(s1, "tcp://127.0.0.1.32", NULL, 0), NNG_EADDRINVAL); NUTS_FAIL( @@ -143,7 +139,7 @@ test_tcp_no_delay_option(void) nng_listener l; bool v; int x; - char *addr; + char *addr; NUTS_ADDR(addr, "tcp"); @@ -161,8 +157,7 @@ test_tcp_no_delay_option(void) NUTS_FAIL( nng_dialer_get_int(d, NNG_OPT_TCP_NODELAY, &x), NNG_EBADTYPE); x = 0; - NUTS_FAIL( - nng_dialer_set_int(d, NNG_OPT_TCP_NODELAY, x), NNG_EBADTYPE); + NUTS_FAIL(nng_dialer_set_int(d, NNG_OPT_TCP_NODELAY, x), NNG_EBADTYPE); // This assumes sizeof (bool) != sizeof (int) if (sizeof(bool) != sizeof(int)) { NUTS_FAIL( @@ -205,7 +200,7 @@ test_tcp_keep_alive_option(void) nng_listener l; bool v; int x; - char *addr; + char *addr; NUTS_ADDR(addr, "tcp"); NUTS_OPEN(s); @@ -258,7 +253,7 @@ test_tcp_recv_max(void) nng_socket s1; nng_listener l; size_t sz; - char *addr; + char *addr; NUTS_ADDR(addr, "tcp"); @@ -296,4 +291,4 @@ NUTS_TESTS = { { "tcp keep alive option", test_tcp_keep_alive_option }, { "tcp recv max", test_tcp_recv_max }, { NULL, NULL }, -}; \ No newline at end of file +}; diff --git a/src/sp/transport/tls/tls.c b/src/sp/transport/tls/tls.c index 89e9afa6..b27c2e79 100644 --- a/src/sp/transport/tls/tls.c +++ b/src/sp/transport/tls/tls.c @@ -380,6 +380,20 @@ tlstran_pipe_recv_cb(void *arg) // Make sure the message payload is not too big. If it is // the caller will shut down the pipe. if ((len > p->rcvmax) && (p->rcvmax > 0)) { + nng_sockaddr_storage ss; + nng_sockaddr *sa = (nng_sockaddr *) &ss; + char peername[64] = "unknown"; + if ((rv = nng_stream_get_addr( + p->tls, NNG_OPT_REMADDR, sa)) == 0) { + (void) nng_str_sockaddr( + sa, peername, sizeof(peername)); + } + nng_log_warn("NNG-RCVMAX", + "Oversize message of %lu bytes (> %lu) " + "on socket<%u> pipe<%u> from TLS %s", + (unsigned long) len, (unsigned long) p->rcvmax, + nni_pipe_sock_id(p->npipe), nni_pipe_id(p->npipe), + peername); rv = NNG_EMSGSIZE; goto recv_error; } diff --git a/src/sp/transport/ws/ws_test.c b/src/sp/transport/ws/ws_test.c index b5e72b79..9115338f 100644 --- a/src/sp/transport/ws/ws_test.c +++ b/src/sp/transport/ws/ws_test.c @@ -144,7 +144,7 @@ test_ws_recv_max(void) nng_socket s1; nng_listener l; size_t sz; - char * addr; + char *addr; memset(msg, 0, sizeof(msg)); // required to silence valgrind @@ -177,4 +177,4 @@ TEST_LIST = { { "ws empty host", test_empty_host }, { "ws recv max", test_ws_recv_max }, { NULL, NULL }, -}; \ No newline at end of file +}; diff --git a/src/testing/acutest.h b/src/testing/acutest.h index 8b49afc8..a162bde1 100644 --- a/src/testing/acutest.h +++ b/src/testing/acutest.h @@ -3,7 +3,7 @@ * * * Copyright 2013-2020 Martin Mitas - * Copyright 2019 Garrett D'Amore + * Copyright 2024 Garrett D'Amore * * Permission is hereby granted, free of charge, to any person obtaining a * copy of this software and associated documentation files (the "Software"), @@ -361,6 +361,7 @@ extern const struct test_ test_list_[]; int test_check_(int cond, const char* file, int line, const char* fmt, ...); void test_case_(const char* fmt, ...); void test_message_(const char* fmt, ...); +void test_message_color_(int, const char* fmt, ...); void test_dump_(const char* title, const void* addr, size_t size); void test_abort_(void) TEST_ATTRIBUTE_(noreturn); @@ -779,6 +780,38 @@ test_message_(const char* fmt, ...) } } +/* Print a message in color, unconditionally (based on verbosity). */ +void TEST_ATTRIBUTE_(format (printf, 2, 3)) +test_message_color_(int color, const char* fmt, ...) +{ + char buffer[TEST_MSG_MAXSIZE]; + char* line_beg; + char* line_end; + va_list args; + + if(test_verbose_level_ < 3) + return; + + va_start(args, fmt); + vsnprintf(buffer, TEST_MSG_MAXSIZE, fmt, args); + va_end(args); + buffer[TEST_MSG_MAXSIZE-1] = '\0'; + + line_beg = buffer; + while(1) { + line_end = strchr(line_beg, '\n'); + if(line_end == NULL) + break; + test_line_indent_(test_case_name_[0] ? 3 : 2); + test_print_in_color_(color, "%.*s\n", (int)(line_end - line_beg), line_beg); + line_beg = line_end + 1; + } + if(line_beg[0] != '\0') { + test_line_indent_(test_case_name_[0] ? 3 : 2); + test_print_in_color_(color, "%s\n", line_beg); + } +} + void test_dump_(const char* title, const void* addr, size_t size) { diff --git a/src/testing/nuts.h b/src/testing/nuts.h index c82abff2..e13a44da 100644 --- a/src/testing/nuts.h +++ b/src/testing/nuts.h @@ -18,12 +18,16 @@ #define NNG_TESTING_NUTS_H #include +extern void nuts_logger( + nng_log_level, nng_log_facility, const char *, const char *); // Call nng_fini during test finalization -- this avoids leak warnings. extern void nng_fini(void); #define TEST_FINI nng_fini() #define TEST_INIT \ do { \ + nng_log_set_logger(nuts_logger); \ + nng_log_set_level(NNG_LOG_DEBUG); \ } while (0) #include "acutest.h" @@ -213,6 +217,11 @@ extern const char *nuts_garbled_crt; nng_log_set_level(level); \ } while (0) +#define NUTS_LOGGING() \ + do { \ + nng_log_set_logger(nuts_logger); \ + nng_log_set_level(NNG_LOG_DEBUG); \ + } while (0) #ifdef __cplusplus }; #endif diff --git a/src/testing/util.c b/src/testing/util.c index eeb70b4f..f93b6d55 100644 --- a/src/testing/util.c +++ b/src/testing/util.c @@ -1,5 +1,5 @@ // -// Copyright 2020 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // // This software is supplied under the terms of the MIT License, a @@ -8,6 +8,7 @@ // found online at https://opensource.org/licenses/MIT. // +#include "nng/nng.h" #define TEST_NO_MAIN #ifdef _WIN32 @@ -72,7 +73,7 @@ nuts_clock(void) } tv.tv_sec -= epoch; return ( - ((uint64_t)(tv.tv_sec) * 1000) + (uint64_t)(tv.tv_usec / 1000)); + ((uint64_t) (tv.tv_sec) * 1000) + (uint64_t) (tv.tv_usec / 1000)); #endif #ifdef _WIN32 @@ -162,3 +163,46 @@ nuts_sleep(int msec) poll(NULL, 0, msec); #endif } + +#define NUTS_COLOR_DEFAULT_ 0 +#define NUTS_COLOR_GREEN_ 1 +#define NUTS_COLOR_RED_ 2 +#define NUTS_COLOR_DEFAULT_INTENSIVE_ 3 +#define NUTS_COLOR_GREEN_INTENSIVE_ 4 +#define NUTS_COLOR_RED_INTENSIVE_ 5 + +void +nuts_logger(nng_log_level level, nng_log_facility fac, const char *msgid, + const char *msg) +{ + (void) fac; + char *lstr; + int color; + switch (level) { + case NNG_LOG_DEBUG: + lstr = "DEBUG"; + color = NUTS_COLOR_DEFAULT_; + break; + case NNG_LOG_INFO: + lstr = "INFO"; + color = NUTS_COLOR_DEFAULT_; + break; + case NNG_LOG_NOTICE: + lstr = "NOTICE"; + color = NUTS_COLOR_DEFAULT_INTENSIVE_; + break; + case NNG_LOG_WARN: + lstr = "WARNING"; + color = NUTS_COLOR_RED_; + break; + case NNG_LOG_ERR: + lstr = "ERROR"; + color = NUTS_COLOR_RED_INTENSIVE_; + break; + default: + lstr = "LEVEL UNKNOWN"; + color = NUTS_COLOR_DEFAULT_; + break; + } + test_message_color_(color, "%s: %s: %s", lstr, msgid, msg); +} From 212269e7535310c235a4bf9e0bc9712461a9ad9c Mon Sep 17 00:00:00 2001 From: jaylin Date: Wed, 21 Aug 2024 13:31:41 +0800 Subject: [PATCH 10/22] * FIX sync error Signed-off-by: jaylin --- src/supplemental/tls/tls_test.c | 4 ---- 1 file changed, 4 deletions(-) diff --git a/src/supplemental/tls/tls_test.c b/src/supplemental/tls/tls_test.c index 7b317bb4..4a3f6e2d 100644 --- a/src/supplemental/tls/tls_test.c +++ b/src/supplemental/tls/tls_test.c @@ -86,11 +86,7 @@ test_tls_large_message(void) void *t2; int port; -<<<<<<< HEAD - NUTS_ENABLE_LOG(NNG_LOG_DEBUG); -======= NUTS_ENABLE_LOG(NNG_LOG_INFO); ->>>>>>> b1aaa6069 (fixes #1588 TLS should log errors) // allocate messages NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); From bab9a49c25f7e587e5755d3f21dcad4e4c8580aa Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 11 Aug 2024 22:12:30 -0700 Subject: [PATCH 11/22] idhash: add nng_id_visit API This allows an efficient way to iterate over the entries stored in an ID hash. The iteration is fast, and requires no additional storage. The order of iteration is not guaranteed. Signed-off-by: jaylin --- docs/man/nng_id_map.3supp.adoc | 8 +++++ include/nng/supplemental/util/idhash.h | 1 + src/core/idhash.c | 24 ++++++++++++- src/core/idhash.h | 8 ++--- src/supplemental/util/idhash.c | 6 ++++ src/supplemental/util/idhash_test.c | 48 ++++++++++++++++++++++++++ 6 files changed, 89 insertions(+), 6 deletions(-) diff --git a/docs/man/nng_id_map.3supp.adoc b/docs/man/nng_id_map.3supp.adoc index 343c0667..5bebf1c4 100644 --- a/docs/man/nng_id_map.3supp.adoc +++ b/docs/man/nng_id_map.3supp.adoc @@ -29,6 +29,7 @@ void *nng_id_get(nng_id_map *map, uint64_t id); int nng_id_set(nng_id_map *map, uint64_t, void *value); int nng_id_alloc(nng_id_map *map, uint64_t *id_p, void *value); int nng_id_remove(nng_id_map *map, uint64_t id); +bool nng_id_visit(nng_id_map *map, uint64_t *id_p, void **value_p, uint32_t *cursor); ---- @@ -74,6 +75,13 @@ the supplied _value_. The `nng_id_remove()` function removes the identifier and its associated value from the table. +The `nng_id_visit()` function is used to iterate over all items in the table. +The caller starts the iteration by setting the _cursor_ to 0 before calling it. +For each call, the associated key and value of the next item will be returned in __id_p__, and __value_p__ and the _cursor_ will be updated. +When all items have been iterated, the function returns `false`. +The order of items returned is not guaranteed to be sequential. +The caller must not attempt to derive any value of the _cursor_ as it refers to internal table indices. + NOTE: These functions are limited to storing at most 2^32^ identifiers, even though the identifers may themselves be larger than 2^32^. diff --git a/include/nng/supplemental/util/idhash.h b/include/nng/supplemental/util/idhash.h index 8f691d08..f231a554 100644 --- a/include/nng/supplemental/util/idhash.h +++ b/include/nng/supplemental/util/idhash.h @@ -27,6 +27,7 @@ NNG_DECL void *nng_id_get(nng_id_map *, uint64_t); NNG_DECL int nng_id_set(nng_id_map *, uint64_t, void *); NNG_DECL int nng_id_alloc(nng_id_map *, uint64_t *, void *); NNG_DECL int nng_id_remove(nng_id_map *, uint64_t); +NNG_DECL bool nng_id_visit(nng_id_map *, uint64_t *, void **, uint32_t *); #ifdef __cplusplus } diff --git a/src/core/idhash.c b/src/core/idhash.c index 07862d91..94fa2ee5 100644 --- a/src/core/idhash.c +++ b/src/core/idhash.c @@ -1,5 +1,5 @@ // -// Copyright 2023 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // // This software is supplied under the terms of the MIT License, a @@ -469,6 +469,28 @@ nni_id_alloc32(nni_id_map *m, uint32_t *idp, void *val) return (rv); } +bool +nni_id_visit(nni_id_map *m, uint64_t *keyp, void **valp, uint32_t *cursor) +{ + // cursor is just a cursor into the table + uint32_t index = *cursor; + while (index < m->id_cap) { + if (m->id_entries[index].val != NULL) { + if (valp != NULL) { + *valp = m->id_entries[index].val; + } + if (keyp != NULL) { + *keyp = m->id_entries[index].key; + } + *cursor = index + 1; + return true; + } + index++; + } + *cursor = index; + return (false); +} + // Added by NanoSDK void nni_id_msgfree_cb(nni_msg* msg) diff --git a/src/core/idhash.h b/src/core/idhash.h index 247625b0..2e411160 100644 --- a/src/core/idhash.h +++ b/src/core/idhash.h @@ -1,5 +1,5 @@ // -// Copyright 2023 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // // This software is supplied under the terms of the MIT License, a @@ -54,9 +54,7 @@ extern int nni_id_alloc(nni_id_map *, uint64_t *, void *); extern int nni_id_alloc32(nni_id_map *, uint32_t *, void *); extern int nni_id_remove(nni_id_map *, uint64_t); extern void nni_id_map_sys_fini(void); -// NanoSDK usage -extern void nni_id_map_foreach(nni_id_map *, nni_idhash_cb); - +extern bool nni_id_visit(nni_id_map *, uint64_t *, void **, uint32_t *); #define NNI_ID_MAP_INITIALIZER(min, max, flags) \ { \ @@ -67,5 +65,5 @@ extern void nni_id_map_foreach(nni_id_map *, nni_idhash_cb); // NanoSDK extern void *nni_id_get_min(nni_id_map *m, uint16_t *pid); extern void nni_id_msgfree_cb(nni_msg *msg); - +extern void nni_id_map_foreach(nni_id_map *, nni_idhash_cb); #endif // CORE_IDHASH_H diff --git a/src/supplemental/util/idhash.c b/src/supplemental/util/idhash.c index cf48df3e..4ededa31 100644 --- a/src/supplemental/util/idhash.c +++ b/src/supplemental/util/idhash.c @@ -60,3 +60,9 @@ nng_id_alloc(nng_id_map *map, uint64_t *id, void *val) { return (nni_id_alloc(&map->m, id, val)); } + +bool +nng_id_visit(nng_id_map *map, uint64_t *id, void **valp, uint32_t *cursor) +{ + return (nni_id_visit(&map->m, id, valp, cursor)); +} diff --git a/src/supplemental/util/idhash_test.c b/src/supplemental/util/idhash_test.c index 5bbdc4fb..e0d472a0 100644 --- a/src/supplemental/util/idhash_test.c +++ b/src/supplemental/util/idhash_test.c @@ -182,6 +182,52 @@ test_id_set_out_of_range(void) nng_id_map_free(m); } +void +test_id_visit(void) +{ + nng_id_map *m; + int x, y; + uint64_t id1; + uint64_t id2; + int *v1; + int *v2; + uint32_t cursor = 0; + + NUTS_PASS(nng_id_map_alloc(&m, 10, 13, 0)); + + // We can insert outside the range forcibly. + NUTS_PASS(nng_id_set(m, 1, &x)); + NUTS_PASS(nng_id_set(m, 100, &y)); + NUTS_TRUE(nng_id_visit(m, &id1, (void **) &v1, &cursor)); + NUTS_ASSERT(id1 == 1 || id1 == 100); + NUTS_ASSERT(v1 == &x || v1 == &y); + NUTS_TRUE(nng_id_visit(m, &id2, (void **) &v2, &cursor)); + NUTS_ASSERT(id2 == 1 || id2 == 100); + NUTS_ASSERT(v2 == &x || v2 == &y); + NUTS_ASSERT(id1 != id2); + NUTS_ASSERT(v1 != v2); + NUTS_TRUE(!nng_id_visit(m, &id2, (void **) &v2, &cursor)); + nng_id_map_free(m); +} + +void +test_id_visit_out_of_range(void) +{ + nng_id_map *m; + int x, y; + uint64_t id1; + int *v1; + uint32_t cursor = 1000; + + NUTS_PASS(nng_id_map_alloc(&m, 10, 13, 0)); + + // We can insert outside the range forcibly. + NUTS_PASS(nng_id_set(m, 1, &x)); + NUTS_PASS(nng_id_set(m, 100, &y)); + NUTS_TRUE(!nng_id_visit(m, &id1, (void **) &v1, &cursor)); + nng_id_map_free(m); +} + #define STRESS_LOAD 50000 #define NUM_VALUES 1000 @@ -303,6 +349,8 @@ NUTS_TESTS = { { "id resize", test_id_resize }, { "id dynamic", test_id_dynamic }, { "id set out of range", test_id_set_out_of_range }, + { "id visit", test_id_visit }, + { "id visit out of range", test_id_visit_out_of_range }, { "id stress", test_id_stress }, { "id alloc long long", test_id_alloc_long_long }, { NULL, NULL }, From a8d4862b9c1aeba4211f4154239512ff3515008f Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Sun, 21 Jul 2024 15:55:09 -0700 Subject: [PATCH 12/22] fixes #1837 IPC - Use After Free This fixes a problem only found on Windows, that affected both IPC and TCP. --- src/platform/windows/win_ipcconn.c | 25 +++++++++++++++++++- src/platform/windows/win_tcp.h | 8 ++++--- src/platform/windows/win_tcpconn.c | 37 ++++++++++++++++++++++++------ 3 files changed, 59 insertions(+), 11 deletions(-) diff --git a/src/platform/windows/win_ipcconn.c b/src/platform/windows/win_ipcconn.c index b2136a89..ef6ceb66 100644 --- a/src/platform/windows/win_ipcconn.c +++ b/src/platform/windows/win_ipcconn.c @@ -30,6 +30,8 @@ typedef struct ipc_conn { int send_rv; int conn_rv; bool closed; + bool sending; + bool recving; nni_mtx mtx; nni_cv cv; nni_reap_node reap; @@ -76,9 +78,11 @@ ipc_recv_start(ipc_conn *c) len = 0x1000000; } + c->recving = true; if ((!ReadFile(c->f, buf, len, NULL, &c->recv_io.olpd)) && ((rv = GetLastError()) != ERROR_IO_PENDING)) { // Synchronous failure. + c->recving = false; nni_aio_list_remove(aio); nni_aio_finish_error(aio, nni_win_error(rv)); } else { @@ -104,6 +108,7 @@ ipc_recv_cb(nni_win_io *io, int rv, size_t num) // A zero byte receive is a remote close from the peer. rv = NNG_ECONNSHUT; } + c->recving = false; nni_aio_list_remove(aio); ipc_recv_start(c); nni_mtx_unlock(&c->mtx); @@ -196,9 +201,11 @@ ipc_send_start(ipc_conn *c) len = 0x1000000; } + c->sending = true; if ((!WriteFile(c->f, buf, len, NULL, &c->send_io.olpd)) && ((rv = GetLastError()) != ERROR_IO_PENDING)) { // Synchronous failure. + c->sending = false; nni_aio_list_remove(aio); nni_aio_finish_error(aio, nni_win_error(rv)); } else { @@ -217,6 +224,7 @@ ipc_send_cb(nni_win_io *io, int rv, size_t num) aio = nni_list_first(&c->send_aios); NNI_ASSERT(aio != NULL); nni_aio_list_remove(aio); + c->sending = false; if (c->send_rv != 0) { rv = c->send_rv; c->send_rv = 0; @@ -275,17 +283,32 @@ static void ipc_close(void *arg) { ipc_conn *c = arg; + nni_time now; nni_mtx_lock(&c->mtx); if (!c->closed) { HANDLE f = c->f; c->closed = true; - c->f = INVALID_HANDLE_VALUE; + + c->f = INVALID_HANDLE_VALUE; if (f != INVALID_HANDLE_VALUE) { + CancelIoEx(f, &c->send_io.olpd); + CancelIoEx(f, &c->recv_io.olpd); DisconnectNamedPipe(f); CloseHandle(f); } } + now = nni_clock(); + // wait up to a maximum of 10 seconds before assuming something is + // badly amiss. from what we can tell, this doesn't happen, and we do + // see the timer expire properly, but this safeguard can prevent a + // hang. + while ((c->recving || c->sending) && + ((nni_clock() - now) < (NNI_SECOND * 10))) { + nni_mtx_unlock(&c->mtx); + nni_msleep(1); + nni_mtx_lock(&c->mtx); + } nni_mtx_unlock(&c->mtx); } diff --git a/src/platform/windows/win_tcp.h b/src/platform/windows/win_tcp.h index e54f853c..d151b9a3 100644 --- a/src/platform/windows/win_tcp.h +++ b/src/platform/windows/win_tcp.h @@ -1,5 +1,5 @@ // -// Copyright 2019 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // Copyright 2019 Devolutions // @@ -24,16 +24,18 @@ struct nni_tcp_conn { nni_win_io conn_io; nni_list recv_aios; nni_list send_aios; - nni_aio * conn_aio; + nni_aio *conn_aio; SOCKADDR_STORAGE sockname; SOCKADDR_STORAGE peername; - nni_tcp_dialer * dialer; + nni_tcp_dialer *dialer; nni_tcp_listener *listener; int recv_rv; int send_rv; int conn_rv; bool closed; char buf[512]; // to hold acceptex results + bool sending; + bool recving; nni_mtx mtx; nni_cv cv; }; diff --git a/src/platform/windows/win_tcpconn.c b/src/platform/windows/win_tcpconn.c index 24605505..0e74ccfd 100644 --- a/src/platform/windows/win_tcpconn.c +++ b/src/platform/windows/win_tcpconn.c @@ -48,13 +48,15 @@ tcp_recv_start(nni_tcp_conn *c) } } - flags = 0; - rv = WSARecv( + c->recving = true; + flags = 0; + rv = WSARecv( c->s, iov, niov, &nrecv, &flags, &c->recv_io.olpd, NULL); if ((rv == SOCKET_ERROR) && ((rv = GetLastError()) != ERROR_IO_PENDING)) { // Synchronous error. + c->recving = false; nni_aio_list_remove(aio); nni_aio_finish_error(aio, nni_win_error(rv)); } else { @@ -76,7 +78,6 @@ tcp_recv_cb(nni_win_io *io, int rv, size_t num) nni_mtx_lock(&c->mtx); aio = nni_list_first(&c->recv_aios); NNI_ASSERT(aio != NULL); - nni_aio_list_remove(aio); if (c->recv_rv != 0) { rv = c->recv_rv; @@ -86,6 +87,8 @@ tcp_recv_cb(nni_win_io *io, int rv, size_t num) // A zero byte receive is a remote close from the peer. rv = NNG_ECONNSHUT; } + c->recving = false; + nni_aio_list_remove(aio); tcp_recv_start(c); nni_mtx_unlock(&c->mtx); @@ -164,11 +167,13 @@ tcp_send_start(nni_tcp_conn *c) } } + c->sending = true; rv = WSASend(c->s, iov, niov, NULL, 0, &c->send_io.olpd, NULL); if ((rv == SOCKET_ERROR) && ((rv = GetLastError()) != ERROR_IO_PENDING)) { // Synchronous failure. + c->sending = false; nni_aio_list_remove(aio); nni_aio_finish_error(aio, nni_win_error(rv)); } else { @@ -208,6 +213,7 @@ tcp_send_cb(nni_win_io *io, int rv, size_t num) aio = nni_list_first(&c->send_aios); NNI_ASSERT(aio != NULL); nni_aio_list_remove(aio); // should always be at head + c->sending = false; if (c->send_rv != 0) { rv = c->send_rv; @@ -246,14 +252,31 @@ tcp_close(void *arg) { nni_tcp_conn *c = arg; nni_mtx_lock(&c->mtx); + nni_time now; if (!c->closed) { + SOCKET s = c->s; + c->closed = true; - if (c->s != INVALID_SOCKET) { - shutdown(c->s, SD_BOTH); - closesocket(c->s); - c->s = INVALID_SOCKET; + c->s = INVALID_SOCKET; + + if (s != INVALID_SOCKET) { + CancelIoEx(s, &c->send_io.olpd); + CancelIoEx(s, &c->recv_io.olpd); + shutdown(s, SD_BOTH); + closesocket(s); } } + now = nni_clock(); + // wait up to a maximum of 10 seconds before assuming something is + // badly amiss. from what we can tell, this doesn't happen, and we do + // see the timer expire properly, but this safeguard can prevent a + // hang. + while ((c->recving || c->sending) && + ((nni_clock() - now) < (NNI_SECOND * 10))) { + nni_mtx_unlock(&c->mtx); + nni_msleep(1); + nni_mtx_lock(&c->mtx); + } nni_mtx_unlock(&c->mtx); } From a9307f8e7b3bc8a07c57da2fe7cad5227b1854f3 Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Mon, 22 Jul 2024 22:46:25 -0700 Subject: [PATCH 13/22] TLS: enable TLS 1.3 for Mbed TLS. This requires using a supporting version of Mbed TLS. We have to use PSA crypto for TLS 1.3. Signed-off-by: jaylin --- src/supplemental/tls/mbedtls/tls.c | 45 +++- src/supplemental/tls/tls_test.c | 303 ++++++++++++++++++++++ src/supplemental/websocket/wssfile_test.c | 96 +------ 3 files changed, 356 insertions(+), 88 deletions(-) diff --git a/src/supplemental/tls/mbedtls/tls.c b/src/supplemental/tls/mbedtls/tls.c index 379fde74..34b7d584 100644 --- a/src/supplemental/tls/mbedtls/tls.c +++ b/src/supplemental/tls/mbedtls/tls.c @@ -17,7 +17,9 @@ #include "mbedtls/version.h" // Must be first in order to pick up version #include "mbedtls/error.h" -#include "nng/nng.h" +#ifdef MBEDTLS_PSA_CRYPTO_C +#include "psa/crypto.h" +#endif #include "nng/nng.h" #include "nng/supplemental/tls/tls.h" @@ -29,6 +31,7 @@ #include "mbedtls/net.h" #endif +#include "mbedtls/debug.h" #include "mbedtls/ssl.h" #include "core/nng_impl.h" @@ -96,11 +99,13 @@ struct nng_tls_engine_config { static void tls_dbg(void *ctx, int level, const char *file, int line, const char *s) { - char buf[128]; NNI_ARG_UNUSED(ctx); NNI_ARG_UNUSED(level); - snprintf(buf, sizeof(buf), "%s:%04d: %s", file, line, s); - nni_plat_println(buf); + const char *f; + while ((f = strchr(file, '/')) != NULL) { + file = f + 1; + } + nng_log_debug("MBED", "%s: %d: %s", file, line, s); } static int @@ -466,7 +471,11 @@ config_init(nng_tls_engine_config *cfg, enum nng_tls_mode mode) // SSL v3.3. As of this writing, Mbed TLS still does not support // version 1.3, and we would want to test it before enabling it here. cfg->min_ver = MBEDTLS_SSL_MINOR_VERSION_3; +#ifdef MBEDTLS_SSL_PROTO_TLS1_3 + cfg->max_ver = MBEDTLS_SSL_MINOR_VERSION_4; +#else cfg->max_ver = MBEDTLS_SSL_MINOR_VERSION_3; +#endif mbedtls_ssl_conf_min_version( &cfg->cfg_ctx, MBEDTLS_SSL_MAJOR_VERSION_3, cfg->min_ver); @@ -684,9 +693,16 @@ config_version(nng_tls_engine_config *cfg, nng_tls_version min_ver, v1 = MBEDTLS_SSL_MINOR_VERSION_2; break; #endif +#ifdef MBEDTLS_SSL_MINOR_VERSION_3 case NNG_TLS_1_2: v1 = MBEDTLS_SSL_MINOR_VERSION_3; break; +#endif +#ifdef MBEDTLS_SSL_PROTO_TLS1_3 + case NNG_TLS_1_3: + v1 = MBEDTLS_SSL_MINOR_VERSION_4; + break; +#endif default: nng_log_err( "TLS-CFG-VER", "TLS minimum version not supported"); @@ -704,9 +720,17 @@ config_version(nng_tls_engine_config *cfg, nng_tls_version min_ver, v2 = MBEDTLS_SSL_MINOR_VERSION_2; break; #endif +#ifdef MBEDTLS_SSL_MINOR_VERSION_3 case NNG_TLS_1_2: + v2 = MBEDTLS_SSL_MINOR_VERSION_3; + break; +#endif case NNG_TLS_1_3: // We lack support for 1.3, so treat as 1.2. +#ifdef MBEDTLS_SSL_PROTO_TLS1_3 + v2 = MBEDTLS_SSL_MINOR_VERSION_4; +#else v2 = MBEDTLS_SSL_MINOR_VERSION_3; +#endif break; default: // Note that this means that if we ever TLS 1.4 or 2.0, @@ -773,10 +797,18 @@ nng_tls_engine_init_mbed(void) nni_mtx_fini(&rng_lock); return (rv); } +#endif +#ifdef MBEDTLS_PSA_CRYPTO_C + rv = psa_crypto_init(); + if (rv != 0) { + tls_log_err( + "NNG-TLS-INIT", "Failed initializing PSA crypto", rv); + return (rv); + } #endif // Uncomment the following to have noisy debug from mbedTLS. // This may be useful when trying to debug failures. - // mbedtls_debug_set_threshold(3); + // mbedtls_debug_set_threshold(9); rv = nng_tls_engine_register(&tls_engine_mbed); @@ -796,4 +828,7 @@ nng_tls_engine_fini_mbed(void) mbedtls_ctr_drbg_free(&rng_ctx); nni_mtx_fini(&rng_lock); #endif +#ifdef MBEDTLS_PSA_CRYPTO_C + mbedtls_psa_crypto_free(); +#endif } diff --git a/src/supplemental/tls/tls_test.c b/src/supplemental/tls/tls_test.c index 4a3f6e2d..29ed0924 100644 --- a/src/supplemental/tls/tls_test.c +++ b/src/supplemental/tls/tls_test.c @@ -170,6 +170,309 @@ test_tls_garbled_cert(void) nng_tls_config_free(c1); } +void +test_tls_psk(void) +{ + nng_stream_listener *l; + nng_stream_dialer *d; + nng_aio *aio1, *aio2; + nng_stream *s1; + nng_stream *s2; + nng_tls_config *c1; + nng_tls_config *c2; + char addr[32]; + uint8_t key[32]; + uint8_t *buf1; + uint8_t *buf2; + size_t size = 10000; + void *t1; + void *t2; + int port; + + NUTS_ENABLE_LOG(NNG_LOG_DEBUG); + // allocate messages + NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); + NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); + + for (size_t i = 0; i < sizeof(key); i++) { + key[i] = rand() & 0xff; + } + for (size_t i = 0; i < size; i++) { + buf1[i] = rand() & 0xff; + } + + NUTS_PASS(nng_aio_alloc(&aio1, NULL, NULL)); + NUTS_PASS(nng_aio_alloc(&aio2, NULL, NULL)); + nng_aio_set_timeout(aio1, 5000); + nng_aio_set_timeout(aio2, 5000); + + // Allocate the listener first. We use a wild-card port. + NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); + NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); + NUTS_PASS(nng_tls_config_psk(c1, "identity", key, sizeof(key))); + NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); + NUTS_PASS(nng_stream_listener_listen(l)); + NUTS_PASS( + nng_stream_listener_get_int(l, NNG_OPT_TCP_BOUND_PORT, &port)); + NUTS_TRUE(port > 0); + NUTS_TRUE(port < 65536); + + snprintf(addr, sizeof(addr), "tls+tcp://127.0.0.1:%d", port); + NUTS_PASS(nng_stream_dialer_alloc(&d, addr)); + NUTS_PASS(nng_tls_config_alloc(&c2, NNG_TLS_MODE_CLIENT)); + NUTS_PASS(nng_tls_config_psk(c2, "identity", key, sizeof(key))); + + NUTS_PASS(nng_stream_dialer_set_ptr(d, NNG_OPT_TLS_CONFIG, c2)); + + nng_stream_listener_accept(l, aio1); + nng_stream_dialer_dial(d, aio2); + + nng_aio_wait(aio1); + nng_aio_wait(aio2); + + NUTS_PASS(nng_aio_result(aio1)); + NUTS_PASS(nng_aio_result(aio2)); + + NUTS_TRUE((s1 = nng_aio_get_output(aio1, 0)) != NULL); + NUTS_TRUE((s2 = nng_aio_get_output(aio2, 0)) != NULL); + + t1 = nuts_stream_send_start(s1, buf1, size); + t2 = nuts_stream_recv_start(s2, buf2, size); + + NUTS_PASS(nuts_stream_wait(t1)); + NUTS_PASS(nuts_stream_wait(t2)); + NUTS_TRUE(memcmp(buf1, buf2, size) == 0); + + nng_free(buf1, size); + nng_free(buf2, size); + nng_stream_free(s1); + nng_stream_free(s2); + nng_stream_dialer_free(d); + nng_stream_listener_free(l); + nng_tls_config_free(c1); + nng_tls_config_free(c2); + nng_aio_free(aio1); + nng_aio_free(aio2); +} + +void +test_tls_psk_server_identities(void) +{ + nng_stream_listener *l; + nng_stream_dialer *d; + nng_aio *aio1, *aio2; + nng_stream *s1; + nng_stream *s2; + nng_tls_config *c1; + nng_tls_config *c2; + char addr[32]; + uint8_t *buf1; + uint8_t *buf2; + size_t size = 10000; + void *t1; + void *t2; + int port; + char *identity = "test_identity"; + uint8_t key[32]; + + NUTS_ENABLE_LOG(NNG_LOG_INFO); + // allocate messages + NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); + NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); + + for (size_t i = 0; i < sizeof(key); i++) { + key[i] = rand() & 0xff; + } + for (size_t i = 0; i < size; i++) { + buf1[i] = rand() & 0xff; + } + + NUTS_PASS(nng_aio_alloc(&aio1, NULL, NULL)); + NUTS_PASS(nng_aio_alloc(&aio2, NULL, NULL)); + nng_aio_set_timeout(aio1, 5000); + nng_aio_set_timeout(aio2, 5000); + + // Allocate the listener first. We use a wild-card port. + NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); + NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); + // Replace the identity .. first write one value, then we change it + NUTS_PASS( + nng_tls_config_psk(c1, "identity2", key + 4, sizeof(key) - 4)); + NUTS_PASS(nng_tls_config_psk(c1, identity, key + 4, sizeof(key) - 4)); + NUTS_PASS(nng_tls_config_psk(c1, identity, key, sizeof(key))); + NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); + NUTS_PASS(nng_stream_listener_listen(l)); + NUTS_PASS( + nng_stream_listener_get_int(l, NNG_OPT_TCP_BOUND_PORT, &port)); + NUTS_TRUE(port > 0); + NUTS_TRUE(port < 65536); + + snprintf(addr, sizeof(addr), "tls+tcp://127.0.0.1:%d", port); + NUTS_PASS(nng_stream_dialer_alloc(&d, addr)); + NUTS_PASS(nng_tls_config_alloc(&c2, NNG_TLS_MODE_CLIENT)); + NUTS_PASS(nng_tls_config_psk(c2, identity, key, sizeof(key))); + + NUTS_PASS(nng_stream_dialer_set_ptr(d, NNG_OPT_TLS_CONFIG, c2)); + + nng_stream_listener_accept(l, aio1); + nng_stream_dialer_dial(d, aio2); + + nng_aio_wait(aio1); + nng_aio_wait(aio2); + + NUTS_PASS(nng_aio_result(aio1)); + NUTS_PASS(nng_aio_result(aio2)); + + NUTS_TRUE((s1 = nng_aio_get_output(aio1, 0)) != NULL); + NUTS_TRUE((s2 = nng_aio_get_output(aio2, 0)) != NULL); + + t1 = nuts_stream_send_start(s1, buf1, size); + t2 = nuts_stream_recv_start(s2, buf2, size); + + NUTS_PASS(nuts_stream_wait(t1)); + NUTS_PASS(nuts_stream_wait(t2)); + NUTS_TRUE(memcmp(buf1, buf2, size) == 0); + + nng_free(buf1, size); + nng_free(buf2, size); + nng_stream_free(s1); + nng_stream_free(s2); + nng_stream_dialer_free(d); + nng_stream_listener_free(l); + nng_tls_config_free(c1); + nng_tls_config_free(c2); + nng_aio_free(aio1); + nng_aio_free(aio2); +} + +void +test_tls_psk_bad_identity(void) +{ + nng_stream_listener *l; + nng_stream_dialer *d; + nng_aio *aio1, *aio2; + nng_stream *s1; + nng_stream *s2; + nng_tls_config *c1; + nng_tls_config *c2; + char addr[32]; + uint8_t *buf1; + uint8_t *buf2; + size_t size = 10000; + void *t1; + void *t2; + int port; + uint8_t key[32]; + + NUTS_ENABLE_LOG(NNG_LOG_INFO); + // allocate messages + NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); + NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); + + for (size_t i = 0; i < sizeof(key); i++) { + key[i] = rand() & 0xff; + } + for (size_t i = 0; i < size; i++) { + buf1[i] = rand() & 0xff; + } + + NUTS_PASS(nng_aio_alloc(&aio1, NULL, NULL)); + NUTS_PASS(nng_aio_alloc(&aio2, NULL, NULL)); + nng_aio_set_timeout(aio1, 5000); + nng_aio_set_timeout(aio2, 5000); + + // Allocate the listener first. We use a wild-card port. + NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); + NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); + // Replace the identity .. first write one value, then we change it + NUTS_PASS(nng_tls_config_psk(c1, "identity1", key, sizeof(key))); + NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); + NUTS_PASS(nng_stream_listener_listen(l)); + NUTS_PASS( + nng_stream_listener_get_int(l, NNG_OPT_TCP_BOUND_PORT, &port)); + NUTS_TRUE(port > 0); + NUTS_TRUE(port < 65536); + + snprintf(addr, sizeof(addr), "tls+tcp://127.0.0.1:%d", port); + NUTS_PASS(nng_stream_dialer_alloc(&d, addr)); + NUTS_PASS(nng_tls_config_alloc(&c2, NNG_TLS_MODE_CLIENT)); + NUTS_PASS(nng_tls_config_psk(c2, "identity2", key, sizeof(key))); + NUTS_PASS(nng_tls_config_server_name(c2, "localhost")); + + NUTS_PASS(nng_stream_dialer_set_ptr(d, NNG_OPT_TLS_CONFIG, c2)); + + nng_stream_listener_accept(l, aio1); + nng_stream_dialer_dial(d, aio2); + + nng_aio_wait(aio1); + nng_aio_wait(aio2); + + NUTS_PASS(nng_aio_result(aio1)); + NUTS_PASS(nng_aio_result(aio2)); + + NUTS_TRUE((s1 = nng_aio_get_output(aio1, 0)) != NULL); + NUTS_TRUE((s2 = nng_aio_get_output(aio2, 0)) != NULL); + + t1 = nuts_stream_send_start(s1, buf1, size); + t2 = nuts_stream_recv_start(s2, buf2, size); + + // These can fail due to ECRYPTO, EPEERAUTH, or ECONNSHUT, for example + NUTS_ASSERT(nuts_stream_wait(t1) != 0); + NUTS_ASSERT(nuts_stream_wait(t2) != 0); + + nng_free(buf1, size); + nng_free(buf2, size); + nng_stream_free(s1); + nng_stream_free(s2); + nng_stream_dialer_free(d); + nng_stream_listener_free(l); + nng_tls_config_free(c1); + nng_tls_config_free(c2); + nng_aio_free(aio1); + nng_aio_free(aio2); +} + +void +test_tls_psk_key_too_big(void) +{ + nng_tls_config *c1; + uint8_t key[5000]; + + NUTS_ENABLE_LOG(NNG_LOG_INFO); + + // Allocate the listener first. We use a wild-card port. + NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_CLIENT)); + NUTS_FAIL( + nng_tls_config_psk(c1, "identity", key, sizeof(key)), NNG_ECRYPTO); + nng_tls_config_free(c1); +} + +void +test_tls_psk_config_busy(void) +{ + nng_tls_config *c1; + uint8_t key[32]; + nng_stream_listener *l; + nng_aio *aio; + + nng_aio_alloc(&aio, NULL, NULL); + + NUTS_ENABLE_LOG(NNG_LOG_INFO); + + NUTS_PASS(nng_stream_listener_alloc(&l, "tls+tcp://127.0.0.1:0")); + NUTS_PASS(nng_tls_config_alloc(&c1, NNG_TLS_MODE_SERVER)); + NUTS_PASS(nng_tls_config_psk(c1, "identity", key, sizeof(key))); + NUTS_PASS(nng_stream_listener_set_ptr(l, NNG_OPT_TLS_CONFIG, c1)); + nng_stream_listener_accept(l, aio); + nng_msleep(100); + NUTS_FAIL( + nng_tls_config_psk(c1, "identity2", key, sizeof(key)), NNG_EBUSY); + + nng_stream_listener_free(l); + nng_aio_free(aio); + nng_tls_config_free(c1); +} + TEST_LIST = { { "tls config version", test_tls_config_version }, { "tls conn refused", test_tls_conn_refused }, diff --git a/src/supplemental/websocket/wssfile_test.c b/src/supplemental/websocket/wssfile_test.c index ee7c8ffd..51b78645 100644 --- a/src/supplemental/websocket/wssfile_test.c +++ b/src/supplemental/websocket/wssfile_test.c @@ -1,5 +1,5 @@ // -// Copyright 2020 Staysail Systems, Inc. +// Copyright 2024 Staysail Systems, Inc. // Copyright 2018 Capitar IT Group BV // // This software is supplied under the terms of the MIT License, a @@ -13,82 +13,6 @@ #include #ifdef NNG_SUPP_TLS -// These keys are for demonstration purposes ONLY. DO NOT USE. -// The certificate is valid for 100 years, because I don't want to -// have to regenerate it ever again. The CN is 127.0.0.1, and self-signed. -// -// Generated using openssl: -// -// % openssl rsa -genkey -out key.key -// % openssl req -new -key key.key -out cert.csr -sha256 -// % openssl x509 -req -in cert.csr -days 36500 -out cert.crt -// -signkey key.key -sha256 -// -// Relevant metadata: -// -// Certificate: -// Data: -// Version: 1 (0x0) -// Serial Number: 17127835813110005400 (0xedb24becc3a2be98) -// Signature Algorithm: sha256WithRSAEncryption -// Issuer: C=US, ST=CA, L=San Diego, O=nanomsg.org, CN=localhost -// Validity -// Not Before: Jan 11 22:34:35 2018 GMT -// Not After : Dec 18 22:34:35 2117 GMT -// Subject: C=US, ST=CA, L=San Diego, O=nanomsg.org, CN=localhost -// Subject Public Key Info: -// Public Key Algorithm: rsaEncryption -// Public-Key: (2048 bit) -// -static const char cert[] = - "-----BEGIN CERTIFICATE-----\n" - "MIIDLjCCAhYCCQDtskvsw6K+mDANBgkqhkiG9w0BAQsFADBYMQswCQYDVQQGEwJV\n" - "UzELMAkGA1UECAwCQ0ExEjAQBgNVBAcMCVNhbiBEaWVnbzEUMBIGA1UECgwLbmFu\n" - "b21zZy5vcmcxEjAQBgNVBAMMCWxvY2FsaG9zdDAgFw0xODAxMTEyMjM0MzVaGA8y\n" - "MTE3MTIxODIyMzQzNVowWDELMAkGA1UEBhMCVVMxCzAJBgNVBAgMAkNBMRIwEAYD\n" - "VQQHDAlTYW4gRGllZ28xFDASBgNVBAoMC25hbm9tc2cub3JnMRIwEAYDVQQDDAls\n" - "b2NhbGhvc3QwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQDMvoHdEnfO\n" - "hmG3PTj6YC5qz6N5hgmcwf4EZkor4+R1Q5hDOKqOknWmVuGBD5mA61ObK76vycIT\n" - "Tp+H+vKvfgunySZrlyYg8IbgoDbvVgj9RF8xFHdN0PVeqnkBCsCzLtSu6TP8PSgI\n" - "SKiRMH0NUSakWqCPEc2E1r1CKdOpa7av/Na30LPsuKFcAUhu7QiVYfER86ktrO8G\n" - "F2PeVy44Q8RkiLw8uhU0bpAflqkR1KCjOLajw1eL3C+Io75Io8qUOLxWc3LH0hl3\n" - "oEI0jWu7JYlRAw/O7xm4pcGTwy5L8Odz4a7ZTAmuapFRarGOIcDg8Yr0tllRd1mH\n" - "1T4Z2Wv7Rs0tAgMBAAEwDQYJKoZIhvcNAQELBQADggEBAIfUXK7UonrYAOrlXUHH\n" - "gfHNdOXMzQP2Ms6Sxov+1tCTfgsYE65Mggo7hRJUqmKpstpbdRBVXhTyht/xjyTz\n" - "5sMjoeCyv1tXOHpLTfD3LBXwYZwsFdoLS1UHhD3qiYjCyyY2LWa6S786CtlcbCvu\n" - "Uij2q8zJ4WFrNqAzxZtsTfg16/6JRFw9zpVSCNlHqCxNQxzWucbmUFTiWn9rnc/N\n" - "r7utG4JsDPZbEI6QS43R7gGLDF7s0ftWKqzlQiZEtuDQh2p7Uejbft8XmZd/VuV/\n" - "dFMXOO1rleU0lWAJcXWOWHH3er0fivu2ISL8fRjjikYvhRGxtkwC0kPDa2Ntzgd3\n" - "Hsg=\n" - "-----END CERTIFICATE-----\n"; -static const char key[] = - "-----BEGIN RSA PRIVATE KEY-----\n" - "MIIEpQIBAAKCAQEAzL6B3RJ3zoZhtz04+mAuas+jeYYJnMH+BGZKK+PkdUOYQziq\n" - "jpJ1plbhgQ+ZgOtTmyu+r8nCE06fh/ryr34Lp8kma5cmIPCG4KA271YI/URfMRR3\n" - "TdD1Xqp5AQrAsy7Urukz/D0oCEiokTB9DVEmpFqgjxHNhNa9QinTqWu2r/zWt9Cz\n" - "7LihXAFIbu0IlWHxEfOpLazvBhdj3lcuOEPEZIi8PLoVNG6QH5apEdSgozi2o8NX\n" - "i9wviKO+SKPKlDi8VnNyx9IZd6BCNI1ruyWJUQMPzu8ZuKXBk8MuS/Dnc+Gu2UwJ\n" - "rmqRUWqxjiHA4PGK9LZZUXdZh9U+Gdlr+0bNLQIDAQABAoIBAC82HqvjfkzZH98o\n" - "9uKFGy72AjQbfEvxT6mkDKZiPmPr2khl4K5Ph2F71zPzbOoVWYoGZEoUs/PPxWmN\n" - "rDhbUES4VWupxtkBnZheWUyHAjukcG7Y0UnYTTwvAwgCerzWp6RNkfcwAvMmDfis\n" - "vak8dTSg0TUsXb+r5KhFDNGcTNv3f7R0cJmaZ/t9FT7SerXf1LW7itvTjRor8/ZK\n" - "KPwT4oklp1o6RFXSenn/e2e3rAjI+TEwJA3Zp5dqO/M/AhaZKVaxL4voDVdVVkT+\n" - "LHJWVhjLY5ilPkmPWqmZ2reTaF+gGSSjAQ+t/ahGWFqEdWIz9UoXhBBOd1ibeyvd\n" - "Kyxp1QECgYEA8KcDkmwPrhqFlQe/U+Md27OhrQ4cecLCa6EVLsCXN1bFyCi3NSo2\n" - "o5zFCC699KOL0ZwSmYlaQP4xjnqv4Gsa0s3uL7tqOJR2UuEtGK/MPMluGHVaWsGt\n" - "zbnWH3xgsvvsxdt6hInFhcABLDupW336tJ8EcH7mOKoIP+azwF4kPiUCgYEA2c09\n" - "zJBUW6SZXhgJ5vgENYc+UwDT7pfhIWZaRL+wXnwSoa7igodTKJtQp/KfFBJK4RA0\n" - "prvwj4Wr/1ScaboR2hYZApbqXU5zkEkjC1hHIbg1fBe0EcnhP7ojMXrk6B5ed+Lq\n" - "OVdYhUuvtdL/perelmbTJLnb8S214+tzVyg7EGkCgYEA6JLwX8zxpnhZSztOjBr9\n" - "2zuSb7YojQBNd0kZOLLGMaQ5xwSactYWMi8rOIo76Lc6RFxKmXnl8NP5PtKRMRkx\n" - "tjNxE05UDNRmOhkGxUn433JoZVjc9sMhXqZQKuPAbJoOLPW9RWQEsgtq1r3eId7x\n" - "sSfRWYs6od6p1F/4rlwNOMUCgYEAtJmqf+DCAoe3IL3gICRSISy28k7CbZqE9JQR\n" - "j+Y/Uemh7W29pyydOROoysq1PAh7DKrKbeNzcx8NYxh+5nCC8wrVzD7lsV8nFmJ+\n" - "655UxVIhD3f8Oa/j1lr7acEU5KCiBtkjDU8vOMBsv+FpWOQrlB1JQa/X/+G+bHLF\n" - "XmUerNkCgYEAv7R8vIKgJ1f69imgHdB31kue3wnOO/6NlfY3GTcaZcTdChY8SZ5B\n" - "xits8xog0VcaxXhWlfO0hyCnZ9YRQbyDu0qp5eBU2p3qcE01x4ljJBZUOTweG06N\n" - "cL9dYcwse5FhNMjrQ/OKv6B38SIXpoKQUtjgkaMtmpK8cXX1eqEMNkM=\n" - "-----END RSA PRIVATE KEY-----\n"; #define CACERT "wss_test_ca_cert.pem" #define CERT_KEY "wss_test_cert_key.pem" @@ -102,8 +26,10 @@ init_dialer_wss_file(nng_dialer d) NUTS_ASSERT((tmpdir = nni_plat_temp_dir()) != NULL); NUTS_ASSERT((pth = nni_file_join(tmpdir, CACERT)) != NULL); nng_strfree(tmpdir); - NUTS_PASS(nni_file_put(pth, cert, strlen(cert))); + NUTS_PASS(nni_file_put(pth, nuts_server_crt, strlen(nuts_server_crt))); NUTS_PASS(nng_dialer_set_string(d, NNG_OPT_TLS_CA_FILE, pth)); + NUTS_PASS( + nng_dialer_set_string(d, NNG_OPT_TLS_SERVER_NAME, "localhost")); nni_file_delete(pth); nng_strfree(pth); } @@ -119,7 +45,8 @@ init_listener_wss_file(nng_listener l) NUTS_ASSERT((pth = nni_file_join(tmpdir, CERT_KEY)) != NULL); nng_strfree(tmpdir); - NUTS_PASS(nni_asprintf(&cert_key, "%s\r\n%s\r\n", cert, key)); + NUTS_PASS(nni_asprintf( + &cert_key, "%s\r\n%s\r\n", nuts_server_key, nuts_server_crt)); NUTS_PASS(nni_file_put(pth, cert_key, strlen(cert_key))); nng_strfree(cert_key); @@ -178,11 +105,12 @@ test_no_verify(void) nng_listener l; nng_dialer d; char addr[64]; - nng_msg * msg; + nng_msg *msg; nng_pipe p; bool b; uint16_t port; + NUTS_ENABLE_LOG(NNG_LOG_DEBUG); NUTS_PASS(nng_pair_open(&s1)); NUTS_PASS(nng_pair_open(&s2)); NUTS_PASS(nng_socket_set_ms(s1, NNG_OPT_SENDTIMEO, 5000)); @@ -201,7 +129,7 @@ test_no_verify(void) NUTS_PASS(nng_dialer_set_int( d, NNG_OPT_TLS_AUTH_MODE, NNG_TLS_AUTH_MODE_OPTIONAL)); NUTS_PASS( - nng_dialer_set_string(d, NNG_OPT_TLS_SERVER_NAME, "example.com")); + nng_dialer_set_string(d, NNG_OPT_TLS_SERVER_NAME, "localhost")); NUTS_PASS(nng_dialer_start(d, 0)); nng_msleep(100); @@ -215,7 +143,9 @@ test_no_verify(void) p = nng_msg_get_pipe(msg); NUTS_TRUE(nng_pipe_id(p) > 0); NUTS_PASS(nng_pipe_get_bool(p, NNG_OPT_TLS_VERIFIED, &b)); - NUTS_TRUE(b == false); + // Server may have verified, us, or might not have. + // This is dependent + // NUTS_TRUE(b == false); nng_msg_free(msg); NUTS_CLOSE(s1); @@ -230,7 +160,7 @@ test_verify_works(void) nng_listener l; nng_dialer d; char addr[NNG_MAXADDRLEN]; - nng_msg * msg; + nng_msg *msg; nng_pipe p; bool b; uint16_t port; From 3114834837cf96f78f10eda6031185f98e5d7474 Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Tue, 13 Aug 2024 23:48:55 -0700 Subject: [PATCH 14/22] log: eliminate redundant newlines sometimes present --- src/core/log.c | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/src/core/log.c b/src/core/log.c index e415e159..9f6a10d6 100644 --- a/src/core/log.c +++ b/src/core/log.c @@ -11,6 +11,7 @@ #include "nng_impl.h" #include #include +#include #include #ifdef NNG_PLATFORM_WINDOWS #include @@ -167,9 +168,11 @@ stderr_logger(nng_log_level level, nng_log_facility facility, 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, + bool trailing_nl = + ((strlen(msg) != 0) && msg[strlen(msg) - 1] == '\n'); + (void) fprintf(stderr, "%s[%-6s]: %s.%03d: %s%s%s%s%s", sgr, level_str, when, nsec / 1000000, msgid ? msgid : "", msgid ? ": " : "", msg, - sgr0); + sgr0, trailing_nl ? "" : "\n"); } void From 2b2892ef9b0630d0648c27571d7ea61d80041a3a Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Wed, 14 Aug 2024 00:12:39 -0700 Subject: [PATCH 15/22] Disable TLS tests on Windows due to downrev vcpkg mbed --- .github/workflows/windows.yml | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/.github/workflows/windows.yml b/.github/workflows/windows.yml index 54a04cc3..2a031b2b 100644 --- a/.github/workflows/windows.yml +++ b/.github/workflows/windows.yml @@ -18,7 +18,9 @@ jobs: github-binarycache: true - name: Configure - run: cmake ${{ steps.vcpkg.outputs.vcpkg-cmake-config }} -D NNG_ENABLE_TLS=ON -B build + # TLS on Windows is not good because vcpkg is *old* mbedTLS 2.28, and we don't pass some newer tests. + # We should explore testing WolfSSL here instead. + run: cmake ${{ steps.vcpkg.outputs.vcpkg-cmake-config }} -B build - name: Build run: cmake --build build From a89e256d502438827d0fbfb2a454210ee03ced0d Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Wed, 14 Aug 2024 00:16:44 -0700 Subject: [PATCH 16/22] fixes #1858 Warning on calloc() --- src/tools/perf/pubdrop.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/tools/perf/pubdrop.c b/src/tools/perf/pubdrop.c index bc067d76..0e493116 100644 --- a/src/tools/perf/pubdrop.c +++ b/src/tools/perf/pubdrop.c @@ -275,7 +275,7 @@ do_pubdrop(int argc, char **argv) die("Message size too small."); } - thrs = calloc(sizeof(nng_thread *), (size_t) pa.count + 1); + thrs = calloc((size_t) pa.count + 1, sizeof(nng_thread *)); if (((rv = nng_mtx_alloc(&pa.mtx)) != 0) || ((nng_cv_alloc(&pa.cv, pa.mtx)) != 0)) { die("Startup: %s\n", nng_strerror(rv)); From ea81d967a3ffe82d0279099617ced6d75dcf3a34 Mon Sep 17 00:00:00 2001 From: Garrett D'Amore Date: Wed, 14 Aug 2024 00:18:01 -0700 Subject: [PATCH 17/22] fixes #1851 fix error in NNG_OPT_UNSUBSCRIBE description --- docs/man/nng_sub.7.adoc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/man/nng_sub.7.adoc b/docs/man/nng_sub.7.adoc index 2d0e6de1..a96c1217 100644 --- a/docs/man/nng_sub.7.adoc +++ b/docs/man/nng_sub.7.adoc @@ -76,7 +76,7 @@ TIP: To receive all messages, an empty topic (zero length) can be used. ((`NNG_OPT_SUB_UNSUBSCRIBE`)):: - This option, also read-only, removes a topic from the subscription list. + This option, also write-only, removes a topic from the subscription list. Note that if the topic was not previously subscribed to with `NNG_OPT_SUB_SUBSCRIBE` then an `NNG_ENOENT` error will result. From 983cbd386fe288aebdbb8d4f49488a1e6be956af Mon Sep 17 00:00:00 2001 From: jaylin Date: Wed, 21 Aug 2024 13:40:53 +0800 Subject: [PATCH 18/22] * MDF [init] change logging info to clarify Signed-off-by: jaylin --- src/core/init.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/core/init.c b/src/core/init.c index 1bd06582..bb19e799 100644 --- a/src/core/init.c +++ b/src/core/init.c @@ -47,7 +47,7 @@ nni_init_helper(void) nni_inited = true; nng_log_notice( - "NNG-INIT", "NNG library version %s initialized", nng_version()); + "NanoSDK-INIT", "NanoSDK library version %s initialized", nng_version()); return (0); } @@ -58,7 +58,7 @@ nni_init(void) int rv; if ((rv = nni_plat_init(nni_init_helper)) != 0) { nng_log_err("NNG-INIT", - "NNG library initialization failed: %s", nng_strerror(rv)); + "NanoSDK library initialization failed: %s", nng_strerror(rv)); } return (rv); } From a341e79c69242b0f5b66559eb1b4c71b07febc23 Mon Sep 17 00:00:00 2001 From: jaylin Date: Wed, 21 Aug 2024 13:46:35 +0800 Subject: [PATCH 19/22] * FIX merging conflicts with upstream Signed-off-by: jaylin --- include/nng/supplemental/nanolib/log.h | 24 ++++++++++++------------ src/core/socket.c | 1 + src/supplemental/nanolib/log.c | 14 +++++++------- 3 files changed, 20 insertions(+), 19 deletions(-) diff --git a/include/nng/supplemental/nanolib/log.h b/include/nng/supplemental/nanolib/log.h index 2f6effa5..89fe6cb4 100644 --- a/include/nng/supplemental/nanolib/log.h +++ b/include/nng/supplemental/nanolib/log.h @@ -61,12 +61,12 @@ typedef struct { typedef void (*log_func)(log_event *ev); enum { - NNG_LOG_FATAL = 0, - NNG_LOG_ERROR, - NNG_LOG_WARN, - NNG_LOG_INFO, - NNG_LOG_DEBUG, - NNG_LOG_TRACE, + NANO_LOG_FATAL = 0, + NANO_LOG_ERROR, + NANO_LOG_WARN, + NANO_LOG_INFO, + NANO_LOG_DEBUG, + NANO_LOG_TRACE, }; NNG_DECL const char *log_level_string(int level); @@ -89,17 +89,17 @@ NNG_DECL int conf_log_fini(); #ifdef ENABLE_LOG #define log_trace(...) \ - log_log(NNG_LOG_TRACE, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) + log_log(NANO_LOG_TRACE, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) #define log_debug(...) \ - log_log(NNG_LOG_DEBUG, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) + log_log(NANO_LOG_DEBUG, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) #define log_info(...) \ - log_log(NNG_LOG_INFO, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) + log_log(NANO_LOG_INFO, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) #define log_warn(...) \ - log_log(NNG_LOG_WARN, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) + log_log(NANO_LOG_WARN, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) #define log_error(...) \ - log_log(NNG_LOG_ERROR, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) + log_log(NANO_LOG_ERROR, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) #define log_fatal(...) \ - log_log(NNG_LOG_FATAL, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) + log_log(NANO_LOG_FATAL, __FILE__, __LINE__, __FUNCTION__, __VA_ARGS__) #else diff --git a/src/core/socket.c b/src/core/socket.c index 1e374121..e501a2da 100644 --- a/src/core/socket.c +++ b/src/core/socket.c @@ -12,6 +12,7 @@ #include "core/pipe.h" #include "list.h" #include "nng/nng.h" +#include "nng/supplemental/tls/tls.h" #include "sockimpl.h" #include diff --git a/src/supplemental/nanolib/log.c b/src/supplemental/nanolib/log.c index b9509cfd..8af161a9 100644 --- a/src/supplemental/nanolib/log.c +++ b/src/supplemental/nanolib/log.c @@ -117,16 +117,16 @@ static uint8_t convert_syslog_level(uint8_t level) { switch (level) { - case NNG_LOG_FATAL: + case NANO_LOG_FATAL: return LOG_EMERG; - case NNG_LOG_ERROR: + case NANO_LOG_ERROR: return LOG_ERR; - case NNG_LOG_WARN: + case NANO_LOG_WARN: return LOG_WARNING; - case NNG_LOG_INFO: + case NANO_LOG_INFO: return LOG_INFO; - case NNG_LOG_DEBUG: - case NNG_LOG_TRACE: + case NANO_LOG_DEBUG: + case NANO_LOG_TRACE: return LOG_DEBUG; default: return LOG_WARNING; @@ -400,7 +400,7 @@ conf_log_init(int level, int type, char *dir, char *file, uint64_t rotation_sz, int conf_log_fini() { - cli_log->level = NNG_LOG_WARN; + cli_log->level = NANO_LOG_WARN; if (cli_log->fp) { fclose(cli_log->fp); cli_log->fp = NULL; From 7aa4cd99e7383884d7f3a5b01d5b55add7529814 Mon Sep 17 00:00:00 2001 From: jaylin Date: Wed, 21 Aug 2024 13:47:35 +0800 Subject: [PATCH 20/22] * FIX sync mistakes Signed-off-by: jaylin --- src/platform/windows/win_clock.c | 10 ---------- 1 file changed, 10 deletions(-) diff --git a/src/platform/windows/win_clock.c b/src/platform/windows/win_clock.c index 5b8dd9a8..a51738e5 100644 --- a/src/platform/windows/win_clock.c +++ b/src/platform/windows/win_clock.c @@ -14,15 +14,6 @@ #ifdef NNG_PLATFORM_WINDOWS -// return standard timestamp in milliseconds -nni_time -nni_timestamp(void) -{ - SYSTEMTIME t; - GetSystemTime(&t); - return (nni_time) (time(NULL) * 1000 + t.wMilliseconds); -} - nni_time nni_clock(void) { @@ -33,7 +24,6 @@ nni_clock(void) 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; From 00c26595239760ed544347abd18a27b6514d79cd Mon Sep 17 00:00:00 2001 From: jaylin Date: Wed, 21 Aug 2024 13:50:29 +0800 Subject: [PATCH 21/22] fix mistakes of sync Signed-off-by: jaylin --- src/supplemental/tls/tls_test.c | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/src/supplemental/tls/tls_test.c b/src/supplemental/tls/tls_test.c index 29ed0924..3d0c16a0 100644 --- a/src/supplemental/tls/tls_test.c +++ b/src/supplemental/tls/tls_test.c @@ -8,6 +8,7 @@ // #include "nng/nng.h" +#include "nng/supplemental/tls/tls.h" #include void @@ -86,7 +87,7 @@ test_tls_large_message(void) void *t2; int port; - NUTS_ENABLE_LOG(NNG_LOG_INFO); + NUTS_ENABLE_LOG(NNG_LOG_DEBUG); // allocate messages NUTS_ASSERT((buf1 = nng_alloc(size)) != NULL); NUTS_ASSERT((buf2 = nng_alloc(size)) != NULL); @@ -477,6 +478,15 @@ TEST_LIST = { { "tls config version", test_tls_config_version }, { "tls conn refused", test_tls_conn_refused }, { "tls large message", test_tls_large_message }, +#ifndef NNG_TLS_ENGINE_WOLFSSL // wolfSSL doesn't validate certas until use { "tls garbled cert", test_tls_garbled_cert }, +#endif +#ifdef NNG_SUPP_TLS_PSK + { "tls psk", test_tls_psk }, + { "tls psk server identities", test_tls_psk_server_identities }, + { "tls psk bad identity", test_tls_psk_bad_identity }, + { "tls psk key too big", test_tls_psk_key_too_big }, + { "tls psk key config busy", test_tls_psk_config_busy }, +#endif { NULL, NULL }, }; From 1f0baf3d5a0eb5950860736c772bc72f480b6c56 Mon Sep 17 00:00:00 2001 From: jaylin Date: Wed, 21 Aug 2024 13:52:55 +0800 Subject: [PATCH 22/22] * MDF add tls logging Signed-off-by: jaylin --- src/supplemental/tls/mbedtls/tls.c | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/src/supplemental/tls/mbedtls/tls.c b/src/supplemental/tls/mbedtls/tls.c index 34b7d584..0e03bc82 100644 --- a/src/supplemental/tls/mbedtls/tls.c +++ b/src/supplemental/tls/mbedtls/tls.c @@ -512,10 +512,14 @@ config_psk_cb(void *arg, mbedtls_ssl_context *ssl, NNI_LIST_FOREACH (&cfg->psks, psk) { if (id_len == strlen(psk->identity) && (memcmp(identity, psk->identity, id_len) == 0)) { + nng_log_debug("NNG-TLS-PSK-IDENTITY", + "TLS client using PSK identity %s", psk->identity); return (mbedtls_ssl_set_hs_psk( ssl, psk->key, psk->keylen)); } } + nng_log_warn( + "NNG-TLS-PSK-NO-IDENTITY", "TLS client PSK identity not found"); return (MBEDTLS_ERR_SSL_UNKNOWN_IDENTITY); } @@ -546,6 +550,8 @@ config_psk(nng_tls_engine_config *cfg, const char *identity, (const unsigned char *) identity, strlen(identity))) != 0) { psk_free(newpsk); + tls_log_err("Nano-TLS-PSK-FAIL", + "Failed to configure PSK identity", rv); return (tls_mk_err(rv)); } } @@ -594,7 +600,7 @@ config_ca_chain(nng_tls_engine_config *cfg, const char *certs, const char *crl) pem = (const uint8_t *) certs; len = strlen(certs) + 1; if ((rv = mbedtls_x509_crt_parse(&cfg->ca_certs, pem, len)) != 0) { - tls_log_err("NNG-TLS-CA-FAIL", + tls_log_err("Nano-TLS-CA-FAIL", "Failed to parse CA certificate(s)", rv); return (tls_mk_err(rv)); } @@ -602,7 +608,7 @@ config_ca_chain(nng_tls_engine_config *cfg, const char *certs, const char *crl) pem = (const uint8_t *) crl; len = strlen(crl) + 1; if ((rv = mbedtls_x509_crl_parse(&cfg->crl, pem, len)) != 0) { - tls_log_err("NNG-TLS-CRL-FAIL", + tls_log_err("Nano-TLS-CRL-FAIL", "Failed to parse revocation list", rv); return (tls_mk_err(rv)); }