plugin-style logging support

CMakeLists.txt

@@ -92,7 +92,7 @@ target_compile_definitions(open62541-objects PRIVATE UA_DYNAMIC_LINKING)
 target_compile_definitions(open62541-static PRIVATE UA_DYNAMIC_LINKING)
 
 ## logging
-set(UA_LOGLEVEL 400 CACHE STRING "Level at which logs shall be reported")
+set(UA_LOGLEVEL 300 CACHE STRING "Level at which logs shall be reported")
 
 ## coverage
 option(ENABLE_COVERAGE "Enable gcov coverage" OFF)

examples/logger_stdout.c

@@ -4,7 +4,6 @@
  */
 
 #include <stdio.h>
-#include <stdarg.h>
 
 #include "logger_stdout.h"
 #include "ua_types.h"
@@ -13,20 +12,15 @@ static void print_time(void) {
 	UA_DateTime now = UA_DateTime_now();
 	UA_ByteString str;
 	UA_DateTime_toString(now, &str);
-	printf("\"%.*s\"}", str.length, str.data);
+	printf("%.*s", str.length, str.data);
 	UA_ByteString_deleteMembers(&str);
 }
 
 #define LOG_FUNCTION(LEVEL) \
-	static void log_##LEVEL(UA_LoggerCategory category, const char *msg, ...) { \
-		va_list args;												   \
-		puts("##LEVEL - ");											   \
-		print_time();												   \
-		puts(" - ");												   \
-		va_start(args, msg);										   \
-		vprintf(msg, args);											   \
-		puts("\n");													   \
-		va_end(args);												   \
+	static void log_##LEVEL(UA_LoggerCategory category, const char *msg) { \
+        printf("[");                                                    \
+		print_time();                                                   \
+        printf("] " #LEVEL "/%s\t%s\n", UA_LoggerCategoryNames[category], msg); \
 	}
 
 LOG_FUNCTION(trace)
@@ -36,8 +30,8 @@ LOG_FUNCTION(warning)
 LOG_FUNCTION(error)
 LOG_FUNCTION(fatal)
 
-void Logger_Stdout_init(UA_Logger *logger) {
-	*logger = (UA_Logger){
+UA_Logger Logger_Stdout_new(void) {
+	return (UA_Logger){
 		.log_trace = log_trace,
 		.log_debug = log_debug,
 		.log_info = log_info,

examples/logger_stdout.h

@@ -9,6 +9,6 @@
 #include "ua_log.h"
 
 /** Initialises the logger for the current thread. */
-void Logger_Stdout_init(UA_Logger *logger);
+UA_Logger Logger_Stdout_new(void);
 
 #endif /* LOGGER_STDOUT_H_ */

examples/networklayer_tcp.c

@@ -254,7 +254,7 @@ void writeCallback(TCPConnection *handle, UA_ByteStringArray gather_buf) {
 #endif
 }
 
-static UA_StatusCode NetworkLayerTCP_start(NetworkLayerTCP *layer) {
+static UA_StatusCode NetworkLayerTCP_start(NetworkLayerTCP *layer, UA_Logger *logger) {
 #ifdef _WIN32
 	WORD wVersionRequested;
 	WSADATA wsaData;
@@ -293,9 +293,11 @@ static UA_StatusCode NetworkLayerTCP_start(NetworkLayerTCP *layer) {
 
 	setNonBlocking(layer->serversockfd);
 	listen(layer->serversockfd, MAXBACKLOG);
-    printf("Listening for TCP connections on %s:%d\n",
-           inet_ntoa(serv_addr.sin_addr),
-           ntohs(serv_addr.sin_port));
+    char msg[256];
+    sprintf(msg, "Listening for TCP connections on %s:%d",
+            inet_ntoa(serv_addr.sin_addr),
+            ntohs(serv_addr.sin_port));
+    UA_LOG_INFO((*logger), UA_LOGGERCATEGORY_SERVER, msg);
     return UA_STATUSCODE_GOOD;
 }
 
@@ -394,7 +396,7 @@ UA_ServerNetworkLayer ServerNetworkLayerTCP_new(UA_ConnectionConfig conf, UA_UIn
 
     UA_ServerNetworkLayer nl;
     nl.nlHandle = tcplayer;
-    nl.start = (UA_StatusCode (*)(void*))NetworkLayerTCP_start;
+    nl.start = (UA_StatusCode (*)(void*, UA_Logger *logger))NetworkLayerTCP_start;
     nl.getWork = (UA_Int32 (*)(void*, UA_WorkItem**, UA_UInt16)) NetworkLayerTCP_getWork;
     nl.stop = (UA_Int32 (*)(void*, UA_WorkItem**)) NetworkLayerTCP_stop;
     nl.free = (void (*)(void*))NetworkLayerTCP_delete;

examples/networklayer_udp.c

@@ -150,7 +150,7 @@ void writeCallbackUDP(UDPConnection *handle, UA_ByteStringArray gather_buf) {
 #endif
 }
 
-static UA_StatusCode ServerNetworkLayerUDP_start(ServerNetworkLayerUDP *layer) {
+static UA_StatusCode ServerNetworkLayerUDP_start(ServerNetworkLayerUDP *layer, UA_Logger *logger) {
 #ifdef _WIN32
 	WORD wVersionRequested;
 	WSADATA wsaData;
@@ -188,10 +188,11 @@ static UA_StatusCode ServerNetworkLayerUDP_start(ServerNetworkLayerUDP *layer) {
 	}
 
 	setNonBlocking(layer->serversockfd);
-
-    printf("Listening for UDP connections on %s:%d\n",
-           inet_ntoa(serv_addr.sin_addr),
-           ntohs(serv_addr.sin_port));
+    char msg[256];
+    sprintf(msg, "Listening for TCP connections on %s:%d",
+            inet_ntoa(serv_addr.sin_addr),
+            ntohs(serv_addr.sin_port));
+    UA_LOG_INFO((*logger), UA_LOGGERCATEGORY_SERVER, msg);
     return UA_STATUSCODE_GOOD;
 }
 

examples/server.c

@@ -18,6 +18,7 @@
 #include "networklayer_tcp.h"
 
 UA_Boolean running = 1;
+UA_Logger logger;
 
 static void stopHandler(int sign) {
     printf("Received Ctrl-C\n");
@@ -50,13 +51,15 @@ static UA_ByteString loadCertificate(void) {
 }
 
 static void testCallback(UA_Server *server, void *data) {
-       printf("testcallback\n");
+    logger.log_info(UA_LOGGERCATEGORY_USERLAND, "testcallback");
 }
 
 int main(int argc, char** argv) {
 	signal(SIGINT, stopHandler); /* catches ctrl-c */
 
 	UA_Server *server = UA_Server_new();
+    logger = Logger_Stdout_new();
+    UA_Server_setLogger(server, logger);
     UA_Server_setServerCertificate(server, loadCertificate());
     UA_Server_addNetworkLayer(server, ServerNetworkLayerTCP_new(UA_ConnectionConfig_standard, 16664));
 

include/ua_log.h

@@ -31,55 +31,58 @@ extern "C" {
  */
 
 typedef enum UA_LoggerCategory {
-    UA_LOGGINGCATEGORY_CONNECTION,
-    UA_LOGGINGCATEGORY_SESSION,
-    UA_LOGGINGCATEGORY_SUBSCRIPTION,
-    UA_LOGGINGCATEGORY_SERVER
+    UA_LOGGERCATEGORY_CONNECTION,
+    UA_LOGGERCATEGORY_SESSION,
+    UA_LOGGERCATEGORY_SUBSCRIPTION,
+    UA_LOGGERCATEGORY_SERVER,
+    UA_LOGGERCATEGORY_USERLAND
 } UA_LoggerCategory;
 
+extern const char *UA_LoggerCategoryNames[5];
+
 typedef struct UA_Logger {
-    void (*log_trace)(UA_LoggerCategory category, const char *msg, ...);
-    void (*log_debug)(UA_LoggerCategory category, const char *msg, ...);
-    void (*log_info)(UA_LoggerCategory category, const char *msg, ...);
-    void (*log_warning)(UA_LoggerCategory category, const char *msg, ...);
-    void (*log_error)(UA_LoggerCategory category, const char *msg, ...);
-    void (*log_fatal)(UA_LoggerCategory category, const char *msg, ...);
+    void (*log_trace)(UA_LoggerCategory category, const char *msg);
+    void (*log_debug)(UA_LoggerCategory category, const char *msg);
+    void (*log_info)(UA_LoggerCategory category, const char *msg);
+    void (*log_warning)(UA_LoggerCategory category, const char *msg);
+    void (*log_error)(UA_LoggerCategory category, const char *msg);
+    void (*log_fatal)(UA_LoggerCategory category, const char *msg);
 } UA_Logger;
 
 #if UA_LOGLEVEL <= 100
-#define UA_LOG_TRACE(CATEGORY, MSG, ...) do { logger.log_trace(CATEGORY, MSG, __VA_ARGS__); } while(0)
+#define UA_LOG_TRACE(LOGGER, CATEGORY, MSG) do { if(LOGGER.log_trace) LOGGER.log_trace(CATEGORY, MSG); } while(0)
 #else
-#define UA_LOG_TRACE(CATEGORY, MSG, ...) do {} while(0)
+#define UA_LOG_TRACE(LOGGER, CATEGORY, MSG) do {} while(0)
 #endif
 
 #if UA_LOGLEVEL <= 200
-#define UA_LOG_DEBUG(CATEGORY, MSG, ...) do { logger.log_debug(CATEGORY, MSG, __VA_ARGS__); } while(0)
+#define UA_LOG_DEBUG(LOGGER, CATEGORY, MSG) do { if(LOGGER.log_debug) LOGGER.log_debug(CATEGORY, MSG); } while(0)
 #else
-#define UA_LOG_DEBUG(CATEGORY, MSG, ...) do {} while(0)
+#define UA_LOG_DEBUG(LOGGER, CATEGORY, MSG) do {} while(0)
 #endif
 
 #if UA_LOGLEVEL <= 300
-#define UA_LOG_INFO(CATEGORY, MSG, ...) do { logger.log_info(CATEGORY, MSG, __VA_ARGS__); } while(0)
+#define UA_LOG_INFO(LOGGER, CATEGORY, MSG) do { if(LOGGER.log_info) LOGGER.log_info(CATEGORY, MSG); } while(0)
 #else
-#define UA_LOG_INFO(CATEGORY, MSG, ...) do {} while(0)
+#define UA_LOG_INFO(LOGGER, CATEGORY, MSG) do {} while(0)
 #endif
 
 #if UA_LOGLEVEL <= 400
-#define UA_LOG_WARNING(CATEGORY, MSG, ...) do { logger.log_warning(CATEGORY, MSG, __VA_ARGS__); } while(0)
+#define UA_LOG_WARNING(LOGGER, CATEGORY, MSG) do { if(LOGGER.log_warning) LOGGER.log_warning(CATEGORY, MSG); } while(0)
 #else
-#define UA_LOG_WARNING(CATEGORY, MSG, ...) do {} while(0)
+#define UA_LOG_WARNING(LOGGER, CATEGORY, MSG) do {} while(0)
 #endif
 
 #if UA_LOGLEVEL <= 500
-#define UA_LOG_ERROR(CATEGORY, MSG, ...) do { logger.log_error(CATEGORY, MSG, __VA_ARGS__); } while(0)
+#define UA_LOG_ERROR(LOGGER, CATEGORY, MSG) do { if(LOGGER.log_error) LOGGER.log_error(CATEGORY, MSG); } while(0)
 #else
-#define UA_LOG_ERROR(CATEGORY, MSG, ...) do {} while(0)
+#define UA_LOG_ERROR(LOGGER, CATEGORY, MSG) do {} while(0)
 #endif
 
 #if UA_LOGLEVEL <= 600
-#define UA_LOG_FATAL(CATEGORY, MSG, ...) do { logger.log_fatal(CATEGORY, MSG, __VA_ARGS__); } while(0)
+#define UA_LOG_FATAL(LOGGER, CATEGORY, MSG) do { if(LOGGER.log_fatal) LOGGER.log_fatal(CATEGORY, MSG); } while(0)
 #else
-#define UA_LOG_FATAL(CATEGORY, MSG, ...) do {} while(0)
+#define UA_LOG_FATAL(LOGGER, CATEGORY, MSG) do {} while(0)
 #endif
 
 #ifdef __cplusplus

include/ua_server.h

@@ -39,6 +39,9 @@ UA_Server UA_EXPORT * UA_Server_new(void);
 void UA_EXPORT UA_Server_setServerCertificate(UA_Server *server, UA_ByteString certificate);
 void UA_EXPORT UA_Server_delete(UA_Server *server);
 
+/** Sets the logger used by the server */
+void UA_EXPORT UA_Server_setLogger(UA_Server *server, UA_Logger logger);
+
 /**
  * Runs the main loop of the server. In each iteration, this calls into the
  * networklayers to see if work have arrived and checks if timed events need to
@@ -162,7 +165,7 @@ typedef struct {
      *
      * @return Returns UA_STATUSCODE_GOOD or an error code.
      */
-    UA_StatusCode (*start)(void *nlHandle);
+    UA_StatusCode (*start)(void *nlHandle, UA_Logger *logger);
     
     /**
      * Gets called from the main server loop and returns the work that

src/server/ua_server.c

@@ -11,6 +11,11 @@
 #include "ua_services.h"
 #include "ua_nodeids.h"
 
+
+const char *UA_LoggerCategoryNames[5] =
+    {"connection", "session", "subscription", "server",
+     "userland"};
+
 /**********************/
 /* Namespace Handling */
 /**********************/
@@ -33,12 +38,17 @@ void UA_Server_addNetworkLayer(UA_Server *server, UA_ServerNetworkLayer networkL
     server->nls = UA_realloc(server->nls, sizeof(UA_ServerNetworkLayer)*(server->nlsSize+1));
     server->nls[server->nlsSize] = networkLayer;
     server->nlsSize++;
+    UA_LOG_INFO(server->logger, UA_LOGGERCATEGORY_SERVER, "Networklayer added");
 }
 
 void UA_Server_setServerCertificate(UA_Server *server, UA_ByteString certificate) {
     UA_ByteString_copy(&certificate, &server->serverCertificate);
 }
 
+void UA_Server_setLogger(UA_Server *server, UA_Logger logger) {
+    server->logger = logger;
+}
+
 /**********/
 /* Server */
 /**********/
@@ -107,6 +117,9 @@ UA_Server * UA_Server_new(void) {
     server->delayedWork = UA_NULL;
 #endif
 
+    // logger
+    server->logger = (UA_Logger){UA_NULL, UA_NULL, UA_NULL, UA_NULL, UA_NULL, UA_NULL};
+
     // random seed
     server->random_seed = (UA_UInt32) UA_DateTime_now();
 

src/server/ua_server_worker.c

@@ -428,7 +428,7 @@ UA_StatusCode UA_Server_run(UA_Server *server, UA_UInt16 nThreads, UA_Boolean *r
 
     // 2) Start the networklayers
     for(UA_Int32 i=0;i<server->nlsSize;i++)
-        server->nls[i].start(server->nls[i].nlHandle);
+        server->nls[i].start(server->nls[i].nlHandle, &server->logger);
 
     // 3) The loop
     server->timeStarted = UA_DateTime_now();

src/ua_types.c

@@ -240,7 +240,7 @@ UA_StatusCode UA_DateTime_toString(UA_DateTime atime, UA_String *timeString) {
     timeString->length = 31;
 
     UA_DateTimeStruct tSt = UA_DateTime_toStruct(atime);
-    sprintf((char*)timeString->data, "%2d/%2d/%4d %2d:%2d:%2d.%3d.%3d.%3d", tSt.month, tSt.day, tSt.year,
+    sprintf((char*)timeString->data, "%02d/%02d/%04d %02d:%02d:%02d.%03d.%03d.%03d", tSt.month, tSt.day, tSt.year,
             tSt.hour, tSt.min, tSt.sec, tSt.milliSec, tSt.microSec, tSt.nanoSec);
     return UA_STATUSCODE_GOOD;
 }

tests/check_builtin.c

@@ -1198,7 +1198,7 @@ START_TEST(UA_DateTime_toStringShallWorkOnExample) {
 	// when
 	UA_DateTime_toString(src, &dst);
 	// then
-	ck_assert_int_eq(dst.data[0], ' ');
+	ck_assert_int_eq(dst.data[0], '0');
 	ck_assert_int_eq(dst.data[1], '4');
 	ck_assert_int_eq(dst.data[2], '/');
 	ck_assert_int_eq(dst.data[3], '1');