Logging and CMake config

.clang-format

@@ -3,3 +3,7 @@ Language: Cpp
 BasedOnStyle: LLVM
 IndentWidth: 4
 ColumnLimit: 120
+---
+Language: Json
+BasedOnStyle: llvm
+

CMakeLists.txt

@@ -2,6 +2,8 @@ cmake_minimum_required(VERSION 3.20)
 
 project(wakaama C)
 
+include(wakaama.cmake)
+
 add_subdirectory(examples)
 
 # Enable "test" target

CMakePresets.json

@@ -0,0 +1,88 @@
+{
+  "version": 3,
+  "cmakeMinimumRequired": {
+    "major": 3,
+    "minor": 21,
+    "patch": 0
+  },
+  "configurePresets": [
+    {
+      "name": "log_base",
+      "description": "Run the tests with corresponding log level",
+      "hidden": true,
+      "binaryDir": "${sourceDir}/build-presets/log_tests/${presetName}",
+      "cacheVariables": {
+        "WAKAAMA_LOG_CUSTOM_HANDLER": {
+          "type": "BOOL",
+          "value": "ON"
+        },
+        "WAKAAMA_ENABLE_EXAMPLES": {
+          "type": "BOOL",
+          "value": "OFF"
+        }
+      }
+    },
+    {
+      "name": "log_dbg",
+      "description": "Run the tests with debug log level",
+      "inherits": "log_base",
+      "cacheVariables": {
+        "WAKAAMA_LOG_LEVEL": {
+          "type": "STRING",
+          "value": "DBG"
+        }
+      }
+    },
+    {
+      "name": "log_info",
+      "description": "Run the tests with info log level",
+      "inherits": "log_base",
+      "cacheVariables": {
+        "WAKAAMA_LOG_LEVEL": {
+          "type": "STRING",
+          "value": "INFO"
+        }
+      }
+    },
+    {
+      "name": "log_warn",
+      "description": "Run the tests with warning log level",
+      "inherits": "log_base",
+      "cacheVariables": {
+        "WAKAAMA_LOG_LEVEL": {
+          "type": "STRING",
+          "value": "WARN"
+        }
+      }
+    },
+    {
+      "name": "log_fatal",
+      "description": "Run the tests with fatal log level",
+      "inherits": "log_base",
+      "cacheVariables": {
+        "WAKAAMA_LOG_LEVEL": {
+          "type": "STRING",
+          "value": "FATAL"
+        }
+      }
+    }
+  ],
+  "buildPresets": [
+    {
+      "name": "log_dbg",
+      "configurePreset": "log_dbg"
+    },
+    {
+      "name": "log_info",
+      "configurePreset": "log_info"
+    },
+    {
+      "name": "log_warn",
+      "configurePreset": "log_warn"
+    },
+    {
+      "name": "log_fatal",
+      "configurePreset": "log_fatal"
+    }
+  ]
+}

README.md

@@ -96,6 +96,17 @@ Several preprocessor definitions are supported:
    This option enable each unprocessed block 1 payload to be passed to the application, typically to be stored to a flash memory. 
  - LWM2M_COAP_DEFAULT_BLOCK_SIZE CoAP block size used by CoAP layer when performing block-wise transfers. Possible values: 16, 32, 64, 128, 256, 512 and 1024. Defaults to 1024.
 
+### Logging
+
+The logging infrastructure can be configured with CMake cache variables (e.g. `cmake -DWAKAAMA_LOG_LEVEL=INFO`).
+
+- WAKAAMA_LOG_LEVEL: Lowest log level to be enabled. Higher levels are also enabled.
+  - One of: DBG, INFO, WARN, ERR, FATAL, LOG_DISABLED (default)
+- WAKAAMA_LOG_CUSTOM_HANDLER: Set this define to provide a custom handler function for log entries. See the default implementation for details.
+- WAKAAMA_LOG_MAX_MSG_TXT_SIZE: The max. size of the formatted log message. This is only the message without additional data like severity and function name.
+
+
+
 ## Development
 
 ### Dependencies and Tools
@@ -152,6 +163,9 @@ pytest -v tests/integration
 
 ## Examples
 
+The examples can be enabled (or disabled) with the CMake cache variable `WAKAAMA_ENABLE_EXAMPLES` (e.g.
+`cmake -DWAKAAMA_ENABLE_EXAMPLES=OFF`).
+
 There are some example applications provided to test the server, client and bootstrap capabilities of Wakaama.
 The following recipes assume you are on a unix like platform and you have cmake and make installed.
 

coap/transaction.c

@@ -239,7 +239,7 @@ lwm2m_transaction_t * transaction_new(void * sessionH,
         }
     }
 
-    LOG_ARG("Exiting on success. new transac=%p", transacP);
+    LOG_ARG("Exiting on success. new transac=%p", (void *)transacP);
     return transacP;
 
 error:
@@ -255,7 +255,7 @@ lwm2m_transaction_t * transaction_new(void * sessionH,
 
 void transaction_free(lwm2m_transaction_t * transacP)
 {
-    LOG_ARG("Entering. transaction=%p", transacP);
+    LOG_ARG("Entering. transaction=%p", (void *)transacP);
     if (transacP->message)
     {
        coap_free_header(transacP->message);
@@ -279,7 +279,7 @@ void transaction_free(lwm2m_transaction_t * transacP)
 void transaction_remove(lwm2m_context_t * contextP,
                         lwm2m_transaction_t * transacP)
 {
-    LOG_ARG("Entering. transaction=%p", transacP);
+    LOG_ARG("Entering. transaction=%p", (void *)transacP);
     contextP->transactionList = (lwm2m_transaction_t *) LWM2M_LIST_RM(contextP->transactionList, transacP->mID, NULL);
     transaction_free(transacP);
 }
@@ -370,7 +370,7 @@ int transaction_send(lwm2m_context_t * contextP,
 {
     bool maxRetriesReached = false;
 
-    LOG_ARG("Entering: transaction=%p", transacP);
+    LOG_ARG("Entering: transaction=%p", (void *)transacP);
     if (transacP->buffer == NULL)
     {
         transacP->buffer_len = coap_serialize_get_size(transacP->message);
@@ -444,7 +444,7 @@ int transaction_send(lwm2m_context_t * contextP,
 error:
     if (transacP->callback)
     {
-        LOG_ARG("transaction %p expired..calling callback", transacP);
+        LOG_ARG("transaction %p expired..calling callback", (void *)transacP);
         transacP->callback(contextP, transacP, NULL);
     }
     transaction_remove(contextP, transacP);

core/internals.h

@@ -64,31 +64,53 @@
 
 #include "er-coap-13/er-coap-13.h"
 
-#ifdef LWM2M_WITH_LOGS
+#if LWM2M_LOG_LEVEL != LWM2M_LOG_DISABLED
 #include <inttypes.h>
-#define LOG(STR) lwm2m_printf("[%s:%d] " STR "\r\n", __func__ , __LINE__)
-#define LOG_ARG(FMT, ...) lwm2m_printf("[%s:%d] " FMT "\r\n", __func__ , __LINE__ , __VA_ARGS__)
-#ifdef LWM2M_VERSION_1_0
-#define LOG_URI(URI)                                                                \
-{                                                                                   \
-    if ((URI) == NULL) lwm2m_printf("[%s:%d] NULL\r\n", __func__ , __LINE__);       \
-    else                                                                            \
-    {                                                                               \
-        lwm2m_printf("[%s:%d] /%d", __func__ , __LINE__ , (URI)->objectId);         \
-        if (LWM2M_URI_IS_SET_INSTANCE(URI)) lwm2m_printf("/%d", (URI)->instanceId); \
-        if (LWM2M_URI_IS_SET_RESOURCE(URI)) lwm2m_printf("/%d", (URI)->resourceId); \
-        lwm2m_printf("\r\n");                                                       \
-    }                                                                               \
-}
+
+#ifdef _WIN32
+#define LWM2M_NEW_LINE "\r\n"
 #else
-#define LOG_URI(URI)                                                                \
-    if ((URI) == NULL) lwm2m_printf("[%s:%d] NULL\r\n", __func__ , __LINE__);       \
-    else if (!LWM2M_URI_IS_SET_OBJECT(URI)) lwm2m_printf("[%s:%d] /\r\n", __func__ , __LINE__); \
-    else if (!LWM2M_URI_IS_SET_INSTANCE(URI)) lwm2m_printf("[%s:%d] /%d\r\n", __func__ , __LINE__, (URI)->objectId); \
-    else if (!LWM2M_URI_IS_SET_RESOURCE(URI)) lwm2m_printf("[%s:%d] /%d/%d\r\n", __func__ , __LINE__, (URI)->objectId, (URI)->instanceId); \
-    else if (!LWM2M_URI_IS_SET_RESOURCE_INSTANCE(URI)) lwm2m_printf("[%s:%d] /%d/%d/%d\r\n", __func__ , __LINE__, (URI)->objectId, (URI)->instanceId, (URI)->resourceId); \
-    else lwm2m_printf("[%s:%d] /%d/%d/%d/%d\r\n", __func__ , __LINE__, (URI)->objectId, (URI)->instanceId, (URI)->resourceId, (URI)->resourceInstanceId)
+#define LWM2M_NEW_LINE "\n"
+#endif
+
+#ifndef LWM2M_LOG_MAX_MSG_TXT_SIZE
+#define LWM2M_LOG_MAX_MSG_TXT_SIZE 200
 #endif
+
+/* clang-format off */
+#define STR_LOGGING_LEVEL(level) \
+((level) == LWM2M_LOGGING_DBG ? "DBG" : \
+((level) == LWM2M_LOGGING_INFO ? "INFO" : \
+((level) == LWM2M_LOGGING_WARN ? "WARN" : \
+((level) == LWM2M_LOGGING_ERR ? "ERR" : \
+((level) == LWM2M_LOGGING_FATAL ? "FATAL" : \
+"unknown")))))
+/* clang-format on */
+
+/** Format the message part of a log entry. This function is not thread save.
+ * This function should not be called directly. It's used internally in the logging system. */
+char *lwm2m_log_fmt_message(const char *fmt, ...);
+
+/** Basic logging macro. Usually this is not called directly. Use the macros for a given level (e.g. LOG_DBG).
+ * Supports arguments if the message (including format specifiers) is a string literal. Otherwise the use uf
+ * LOG_ARG_DBG (and related macros) are needed.
+ * The limitation that the message needs to be a literal string is due to C11 limitations regarding empty __VA_ARGS__
+ * preceded by an coma. The workaround is inspired by: https://stackoverflow.com/a/53875012 */
+#define LOG_L(LEVEL, ...) LOG_ARG_L_INTERNAL(LEVEL, __VA_ARGS__, '\0')
+
+/* For internal use only. Required for workaround with empty __VA_ARGS__ in C11 */
+#define LOG_ARG_L_INTERNAL(LEVEL, FMT, ...) LOG_ARG_L(LEVEL, FMT "%c", __VA_ARGS__)
+
+/** Basic logging macro that supports arguments. Usually this is not called directly. Use the macros for a given level
+ * (e.g. LOG_ARG_DBG). */
+#define LOG_ARG_L(LEVEL, FMT, ...)                                                                                     \
+    do {                                                                                                               \
+        char *txt = lwm2m_log_fmt_message(FMT, __VA_ARGS__);                                                           \
+        lwm2m_log_handler(LEVEL, txt, __func__, __LINE__, __FILE__);                                                   \
+    } while (0)
+
+#define LOG_URI_TO_STRING(URI) uri_logging_to_string(URI)
+
 /* clang-format off */
 #define STR_STATUS(S)                                           \
 ((S) == STATE_DEREGISTERED ? "STATE_DEREGISTERED" :             \
@@ -144,13 +166,55 @@
 ((S) == STATE_READY ? "STATE_READY" :      \
 "Unknown"))))))
 /* clang-format on */
+
 #define STR_NULL2EMPTY(S) ((const char *)(S) ? (const char *)(S) : "")
+#endif
+
+#if LWM2M_LOG_LEVEL <= LWM2M_DBG
+#define LOG_DBG(...) LOG_L(LWM2M_LOGGING_DBG, __VA_ARGS__)
+#define LOG_ARG_DBG(STR, ...) LOG_ARG_L(LWM2M_LOGGING_DBG, STR, __VA_ARGS__)
+#else
+#define LOG_DBG(...)
+#define LOG_ARG_DBG(STR, ...)
+#endif
+
+#if LWM2M_LOG_LEVEL <= LWM2M_INFO
+#define LOG_INFO(...) LOG_L(LWM2M_LOGGING_INFO, __VA_ARGS__)
+#define LOG_ARG_INFO(STR, ...) LOG_ARG_L(LWM2M_LOGGING_INFO, STR, __VA_ARGS__)
+#else
+#define LOG_INFO(...)
+#define LOG_ARG_INFO(STR, ...)
+#endif
+
+#if LWM2M_LOG_LEVEL <= LWM2M_WARN
+#define LOG_WARN(...) LOG_L(LWM2M_LOGGING_WARN, __VA_ARGS__)
+#define LOG_ARG_WARN(STR, ...) LOG_ARG_L(LWM2M_LOGGING_WARN, STR, __VA_ARGS__)
 #else
-#define LOG_ARG(FMT, ...)
-#define LOG(STR)
-#define LOG_URI(URI)
+#define LOG_WARN(...)
+#define LOG_ARG_WARN(STR, ...)
 #endif
 
+#if LWM2M_LOG_LEVEL <= LWM2M_ERR
+#define LOG_ERR(...) LOG_L(LWM2M_LOGGING_ERR, __VA_ARGS__)
+#define LOG_ARG_ERR(STR, ...) LOG_ARG_L(LWM2M_LOGGING_ERR, STR, __VA_ARGS__)
+#else
+#define LOG_ERR(...)
+#define LOG_ARG_ERR(STR, ...)
+#endif
+
+#if LWM2M_LOG_LEVEL <= LWM2M_FATAL
+#define LOG_FATAL(...) LOG_L(LWM2M_LOGGING_FATAL, __VA_ARGS__)
+#define LOG_ARG_FATAL(STR, ...) LOG_ARG_L(LWM2M_LOGGING_FATAL, STR, __VA_ARGS__)
+#else
+#define LOG_FATAL(...)
+#define LOG_ARG_FATAL(STR, ...)
+#endif
+
+/* Legacy logging macros. Replace with `LOG_DBG` and related. */
+#define LOG(STR) LOG_DBG(STR)
+#define LOG_ARG(STR, ...) LOG_ARG_DBG(STR, __VA_ARGS__)
+#define LOG_URI(URI) LOG_ARG_DBG("%s", LOG_URI_TO_STRING(URI))
+
 #define LWM2M_DEFAULT_LIFETIME  86400
 
 #ifdef LWM2M_SUPPORT_SENML_CBOR

core/logging.c

@@ -0,0 +1,42 @@
+/*******************************************************************************
+ *
+ * Copyright (c) 2023 GARDENA GmbH
+ *
+ * All rights reserved. This program and the accompanying materials
+ * are made available under the terms of the Eclipse Public License v2.0
+ * and Eclipse Distribution License v1.0 which accompany this distribution.
+ *
+ * The Eclipse Public License is available at
+ *    http://www.eclipse.org/legal/epl-v20.html
+ * The Eclipse Distribution License is available at
+ *    http://www.eclipse.org/org/documents/edl-v10.php.
+ *
+ * Contributors:
+ *   Lukas Woodtli, GARDENA GmbH - Please refer to git log
+ *
+ *******************************************************************************/
+
+#include "internals.h"
+
+#if LWM2M_LOG_LEVEL != LWM2M_LOG_DISABLED
+#include "liblwm2m.h"
+#include <stdarg.h>
+
+char *lwm2m_log_fmt_message(const char *fmt, ...) {
+    va_list args;
+    va_start(args, fmt);
+    static char txt[LWM2M_LOG_MAX_MSG_TXT_SIZE];
+    memset(txt, 0, sizeof txt); // just to be safe
+    vsnprintf(txt, LWM2M_LOG_MAX_MSG_TXT_SIZE, fmt, args);
+    return txt;
+}
+
+#ifndef LWM2M_LOG_CUSTOM_HANDLER
+void lwm2m_log_handler(const lwm2m_logging_level_t level, const char *const msg, const char *const func, const int line,
+                       const char *const file) {
+    (void)file;
+    lwm2m_printf("%s - [%s:%d] %s" LWM2M_NEW_LINE, STR_LOGGING_LEVEL(level), func, line, msg);
+}
+#endif
+
+#endif

core/management.c

@@ -238,12 +238,8 @@ uint8_t dm_handleRequest(lwm2m_context_t * contextP,
                             else
                             {
                                 length = (size_t)res;
-                                LOG_ARG("Observe Request[/%d/%d/%d]: %.*s\n",
-                                        uriP->objectId,
-                                        uriP->instanceId,
-                                        uriP->resourceId,
-                                        length,
-                                        STR_NULL2EMPTY(buffer));
+                                LOG_ARG("Observe Request[/%d/%d/%d]: %.*s\n", uriP->objectId, uriP->instanceId,
+                                        uriP->resourceId, (int)length, STR_NULL2EMPTY(buffer));
                             }
                         }
                     }
@@ -575,7 +571,7 @@ static int prv_lwm2m_dm_write(lwm2m_context_t *contextP, uint16_t clientID, lwm2
                               lwm2m_result_callback_t callback, void *userData) {
     coap_method_t method = partialUpdate ? COAP_POST : COAP_PUT;
 
-    LOG_ARG("clientID: %d, format: %s, length: %d", clientID, STR_MEDIA_TYPE(format), length);
+    LOG_ARG("clientID: %d, format: %s, length: %zd", clientID, STR_MEDIA_TYPE(format), length);
     LOG_URI(uriP);
     if (!LWM2M_URI_IS_SET_INSTANCE(uriP)
      || length == 0)
@@ -604,7 +600,7 @@ int lwm2m_dm_write(lwm2m_context_t *contextP, uint16_t clientID, lwm2m_uri_t *ur
 
 int lwm2m_dm_execute(lwm2m_context_t *contextP, uint16_t clientID, lwm2m_uri_t *uriP, lwm2m_media_type_t format,
                      uint8_t *buffer, size_t length, lwm2m_result_callback_t callback, void *userData) {
-    LOG_ARG("clientID: %d, format: %s, length: %d", clientID, STR_MEDIA_TYPE(format), length);
+    LOG_ARG("clientID: %d, format: %s, length: %zd", clientID, STR_MEDIA_TYPE(format), length);
     LOG_URI(uriP);
     if (!LWM2M_URI_IS_SET_RESOURCE(uriP))
     {

core/objects.c

@@ -304,7 +304,7 @@ uint8_t object_read(lwm2m_context_t * contextP,
     }
     lwm2m_data_free(size, dataP);
 
-    LOG_ARG("result: %u.%02u, length: %d", (result & 0xFF) >> 5, (result & 0x1F), *lengthP);
+    LOG_ARG("result: %u.%02u, length: %zd", (result & 0xFF) >> 5, (result & 0x1F), *lengthP);
 
     return result;
 }