From db3bcaf7d1d4f3b1df4b85a3d760cc673805f515 Mon Sep 17 00:00:00 2001 From: Tobias Reisinger Date: Fri, 24 Apr 2020 15:08:26 +0200 Subject: [PATCH] fix: logger --- CMakeLists.txt | 18 +++-------- controller.ini | 3 +- handlers/command.c | 12 +++---- handlers/discovery.c | 14 ++++---- handlers/loop.c | 6 ++-- handlers/poll.c | 4 +-- helpers/bind_server.c | 7 ++-- helpers/connect_server.c | 2 +- helpers/get_port.c | 2 +- helpers/load_config.c | 39 ++++++++++++++++++++-- helpers/open_discovery_socket.c | 8 ++--- helpers/parse_cli.c | 4 +-- include/config.h | 1 + include/constants.h | 6 ---- include/enums.h | 10 ++++++ include/log_levels.h | 11 ------- include/logger.h | 57 +++++---------------------------- include/wiring_debug.h | 16 +++------ logger.c | 57 ++++++++++++++++++++++++++++++--- main.c | 14 ++++---- models/controller.c | 12 +++---- models/controller_load.c | 10 +++--- models/controller_save.c | 16 ++++----- models/relay.c | 13 +++----- models/relay_load.c | 14 ++++---- models/relay_save.c | 14 ++++---- models/schedule.c | 8 ++--- runners/test.c | 2 +- 28 files changed, 200 insertions(+), 180 deletions(-) delete mode 100644 include/log_levels.h diff --git a/CMakeLists.txt b/CMakeLists.txt index fe0df2c..23f390b 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -3,27 +3,17 @@ project(controller) add_executable(controller main.c) -option(WIRING_PI_DEBUG "Use WiringPi Debugging Tool (0=off, 1=silent, 2=LOG_DEBUG) (0)" OFF) -option(LOG_LEVEL "Set logging level (5=trace, 4=debug, 3=info, 2=warn, 1=error, 0=fatal) (3)" OFF) +option(WIRING_PI_DEBUG "Use WiringPi Debugging Tool (0)" OFF) -SET(CMAKE_C_FLAGS "-Wall -Wextra -Werror -Wpedantic -lwiringPi -lwiringPiDev -luuid -llmdb -g") +SET(CMAKE_C_FLAGS "-std=gnu99 -Wall -Wextra -Werror -Wpedantic -lwiringPi -lwiringPiDev -luuid -llmdb -g") string(LENGTH "${CMAKE_SOURCE_DIR}/" SOURCE_PATH_SIZE) add_definitions("-DSOURCE_PATH_SIZE=${SOURCE_PATH_SIZE}") if(WIRING_PI_DEBUG) - if(WIRING_PI_DEBUG GREATER 1) - message("Showing wiringPi calls as debug") - else(WIRING_PI_DEBUG GREATER 1) - message("Ignoring wiringPi calls") - endif(WIRING_PI_DEBUG GREATER 1) - add_definitions("-DWIRING_PI_DEBUG=${WIRING_PI_DEBUG}") + message("Showing wiringPi calls as debug") + add_definitions("-DWIRING_PI_DEBUG") endif(WIRING_PI_DEBUG) -if(LOG_LEVEL) - add_definitions("-DLOG_LEVEL=${LOG_LEVEL}") -else(LOG_LEVEL) - add_definitions("-DLOG_LEVEL=3") -endif(LOG_LEVEL) aux_source_directory(vendor VENDOR_SRC) # vendor first to put their warnings on top aux_source_directory(. SRC_DIR) diff --git a/controller.ini b/controller.ini index 900ea0f..f6a83ae 100644 --- a/controller.ini +++ b/controller.ini @@ -2,7 +2,8 @@ name = new emgauwa device discovery-port = 4421 relay-count = 10 -database = db.lmdb +database = controller_db.lmdb +log-level = debug [relay-0] driver = piface diff --git a/handlers/command.c b/handlers/command.c index 520cce0..1935d32 100644 --- a/handlers/command.c +++ b/handlers/command.c @@ -64,7 +64,7 @@ handler_command(int fd, controller_t *controller) if((client_fd = accept(fd, (struct sockaddr *) &their_addr, &addr_size)) < 0) { - LOG_ERROR("could not accept client: %s", strerror(errno)); + LOG_ERROR("could not accept client: %s\n", strerror(errno)); return; } @@ -72,7 +72,7 @@ handler_command(int fd, controller_t *controller) if(recv(client_fd, &payload_length, sizeof(payload_length), 0) <= 0) { - LOG_ERROR("unable to receive header: %s", strerror(errno)); + LOG_ERROR("unable to receive header: %s\n", strerror(errno)); return; } @@ -81,7 +81,7 @@ handler_command(int fd, controller_t *controller) if((bytes_transferred = recv(client_fd, payload, payload_length, 0)) <= 0) { - LOG_ERROR("unable to receive payload: %s", strerror(errno)); + LOG_ERROR("unable to receive payload: %s\n", strerror(errno)); return; } @@ -92,7 +92,7 @@ handler_command(int fd, controller_t *controller) uint8_t command_code = mpack_node_u8(mpack_node_map_uint(root, COMMAND_MAPPING_CODE)); - LOG_INFO("received command %d", command_code); + LOG_INFO("received command %d\n", command_code); switch(command_code) { @@ -116,12 +116,12 @@ handler_command(int fd, controller_t *controller) case COMMAND_CODE_GET_RELAY_NAME: break; default: - LOG_ERROR("received invalid command"); + LOG_ERROR("received invalid command\n"); } if(mpack_tree_destroy(&tree) != mpack_ok) { - LOG_WARN("error when destroying mpack tree"); + LOG_WARN("error when destroying mpack tree\n"); } free(payload); close(client_fd); diff --git a/handlers/discovery.c b/handlers/discovery.c index ede9c6c..7ed817c 100644 --- a/handlers/discovery.c +++ b/handlers/discovery.c @@ -26,14 +26,14 @@ handler_discovery(int fd, controller_t *controller) if((bytes_transferred = recvfrom(fd, &discovery_answer_port, sizeof(discovery_answer_port), 0, (struct sockaddr *) &si_other, &slen)) <= 0) { - LOG_ERROR("received invalid discovery from %s", inet_ntoa(si_other.sin_addr)); + LOG_ERROR("received invalid discovery from %s\n", inet_ntoa(si_other.sin_addr)); return; } - LOG_INFO("received discovery from %s:%d", inet_ntoa(si_other.sin_addr), discovery_answer_port); + LOG_INFO("received discovery from %s:%d\n", inet_ntoa(si_other.sin_addr), discovery_answer_port); if(discovery_answer_port == 0) { - LOG_ERROR("invalid port received"); + LOG_ERROR("invalid port received\n"); return; } @@ -56,7 +56,7 @@ handler_discovery(int fd, controller_t *controller) // finish writing if(mpack_writer_destroy(&writer) != mpack_ok) { - LOG_ERROR("error writing discovery answer payload"); + LOG_ERROR("error writing discovery answer payload\n"); return; } @@ -64,21 +64,21 @@ handler_discovery(int fd, controller_t *controller) int fd_answer = helper_connect_tcp_server(inet_ntoa(si_other.sin_addr), discovery_answer_port); if(fd_answer == -1) { - LOG_ERROR("error during connecting"); + LOG_ERROR("error during connecting\n"); free(payload); return; } if((bytes_transferred = send(fd_answer, &payload_size, sizeof(payload_size), 0)) <= 0) { - LOG_ERROR("error during sending"); + LOG_ERROR("error during sending\n"); free(payload); close(fd_answer); return; } if((bytes_transferred = send(fd_answer, payload, payload_size, 0)) <= 0) { - LOG_ERROR("error during sending"); + LOG_ERROR("error during sending\n"); free(payload); close(fd_answer); return; diff --git a/handlers/loop.c b/handlers/loop.c index 2c3c934..8ea01e6 100644 --- a/handlers/loop.c +++ b/handlers/loop.c @@ -15,14 +15,14 @@ void handler_loop(controller_t *controller) { - LOG_DEBUG("===== IDLE LOOP START ====="); + LOG_DEBUG("===== IDLE LOOP START =====\n"); for(uint_fast8_t i = 0; i < controller->relay_count; ++i) { relay_t *relay = controller->relays[i]; int is_active = 0; if(relay_is_active(relay, time(NULL))) { - LOG_DEBUG("relay %d is active", i); + LOG_DEBUG("relay %d is active\n", i); is_active = 1; } if(global_config.relay_configs[i].inverted) @@ -38,7 +38,7 @@ handler_loop(controller_t *controller) driver_piface_set(global_config.relay_configs[i].pin, is_active); break; default: - LOG_WARN("relay %d is not using a driver", i); + LOG_WARN("relay %d is not using a driver\n", i); } } } diff --git a/handlers/poll.c b/handlers/poll.c index d75f9d7..7a2d8ab 100644 --- a/handlers/poll.c +++ b/handlers/poll.c @@ -29,7 +29,7 @@ handler_poll(struct pollfd *fds, controller_t *controller, MDB_env *mdb_env) if(fds[i].revents & POLLIN) { /* data may be read on device number i. */ - LOG_DEBUG("fd %i may read data", fds[i].fd); + LOG_DEBUG("fd %i may read data\n", fds[i].fd); switch(i) { case POLL_FDS_DISCOVERY: @@ -44,7 +44,7 @@ handler_poll(struct pollfd *fds, controller_t *controller, MDB_env *mdb_env) if(fds[i].revents & POLLHUP) { /* A hangup has occurred on device number i. */ - LOG_DEBUG("fd %i got closed", fds[i].fd); + LOG_DEBUG("fd %i got closed\n", fds[i].fd); } } } diff --git a/helpers/bind_server.c b/helpers/bind_server.c index 3d08ec6..b796d5b 100644 --- a/helpers/bind_server.c +++ b/helpers/bind_server.c @@ -3,6 +3,7 @@ #include #include #include +#include #include #include @@ -25,7 +26,7 @@ helper_bind_tcp_server(char* addr, uint16_t port, int max_client_backlog) if ((status = getaddrinfo(addr, port_str, &hints, &res)) != 0) { - LOG_ERROR("getaddrinfo: %s", gai_strerror(status)); + LOG_ERROR("getaddrinfo: %s\n", gai_strerror(status)); return -1; } @@ -33,14 +34,14 @@ helper_bind_tcp_server(char* addr, uint16_t port, int max_client_backlog) if ((status = bind(fd, res->ai_addr, res->ai_addrlen)) == -1) { - LOG_ERROR("error binding socket: %s", strerror(errno)); + LOG_ERROR("error binding socket: %s\n", strerror(errno)); freeaddrinfo(res); return -1; } if ((status = listen(fd, max_client_backlog)) == -1) { - LOG_ERROR("error setting up listener: %s", strerror(errno)); + LOG_ERROR("error setting up listener: %s\n", strerror(errno)); freeaddrinfo(res); return -1; } diff --git a/helpers/connect_server.c b/helpers/connect_server.c index 615056a..1f81afb 100644 --- a/helpers/connect_server.c +++ b/helpers/connect_server.c @@ -28,7 +28,7 @@ helper_connect_tcp_server(char* host, uint16_t port) s = socket(res->ai_family, res->ai_socktype, res->ai_protocol); //creating Socket if ((status = connect(s, res->ai_addr, res->ai_addrlen)) != 0) { - LOG_ERROR("connect() failed"); + LOG_ERROR("connect() failed\n"); freeaddrinfo(res); return -1; } diff --git a/helpers/get_port.c b/helpers/get_port.c index edcd8a4..58c9ce8 100644 --- a/helpers/get_port.c +++ b/helpers/get_port.c @@ -14,7 +14,7 @@ helper_get_port(int sock) socklen_t len = sizeof(sin); if (getsockname(sock, (struct sockaddr *)&sin, &len) == -1) { - LOG_ERROR("could not get socket name for port: %s", strerror(errno)); + LOG_ERROR("could not get socket name for port: %s\n", strerror(errno)); return 0; } else diff --git a/helpers/load_config.c b/helpers/load_config.c index f4bdd8d..22c83a5 100644 --- a/helpers/load_config.c +++ b/helpers/load_config.c @@ -30,6 +30,41 @@ helper_load_config(IniDispatch *disp, void *config_void) strcpy(config->database, disp->value); return 0; } + if(CONFINI_IS_KEY("controller", "log-level")) + { + if(strcasecmp(disp->value, "trace") == 0) + { + config->log_level = LOG_LEVEL_TRACE; + return 0; + } + if(strcasecmp(disp->value, "debug") == 0) + { + config->log_level = LOG_LEVEL_DEBUG; + return 0; + } + if(strcasecmp(disp->value, "info") == 0) + { + config->log_level = LOG_LEVEL_INFO; + return 0; + } + if(strcasecmp(disp->value, "warn") == 0) + { + config->log_level = LOG_LEVEL_WARN; + return 0; + } + if(strcasecmp(disp->value, "error") == 0) + { + config->log_level = LOG_LEVEL_ERROR; + return 0; + } + if(strcasecmp(disp->value, "fatal") == 0) + { + config->log_level = LOG_LEVEL_FATAL; + return 0; + } + LOG_WARN("invalid log-level '%s'\n", disp->value); + return 0; + } if(CONFINI_IS_KEY("controller", "discovery-port")) { config->discovery_port = atoi(disp->value); @@ -43,7 +78,7 @@ helper_load_config(IniDispatch *disp, void *config_void) { config->relay_configs[i].driver= RELAY_DRIVER_NONE; } - LOG_TRACE("config relay-count set to %u", config->relay_count); + LOG_TRACE("config relay-count set to %u\n", config->relay_count); return 0; } for(uint8_t i = 0; i < config->relay_count; ++i) @@ -71,7 +106,7 @@ helper_load_config(IniDispatch *disp, void *config_void) config->relay_configs[i].driver = RELAY_DRIVER_PIFACE; return 0; } - LOG_WARN("invalid driver '%s' in section '%s'", disp->value, relay_section_name); + LOG_WARN("invalid driver '%s' in section '%s'\n", disp->value, relay_section_name); return 0; } } diff --git a/helpers/open_discovery_socket.c b/helpers/open_discovery_socket.c index 0b0db89..855bc0a 100644 --- a/helpers/open_discovery_socket.c +++ b/helpers/open_discovery_socket.c @@ -25,7 +25,7 @@ helper_open_discovery_socket(uint16_t discovery_port) //get connection info for our computer if ((status = getaddrinfo(NULL, discovery_port_str, &hints, &res)) != 0) { - LOG_FATAL("getaddrinfo: %s", gai_strerror(status)); + LOG_FATAL("getaddrinfo: %s\n", gai_strerror(status)); freeaddrinfo(res); exit(EXIT_FAILURE); } @@ -37,21 +37,21 @@ helper_open_discovery_socket(uint16_t discovery_port) // lose the pesky "Address already in use" error message if (setsockopt(fd, SOL_SOCKET, SO_REUSEADDR, &yes, sizeof(yes)) == -1) { - LOG_FATAL("setsockopt: %s", strerror(errno)); + LOG_FATAL("setsockopt: %s\n", strerror(errno)); freeaddrinfo(res); exit(EXIT_FAILURE); } if (bind(fd, res->ai_addr, res->ai_addrlen) == -1) { - LOG_FATAL("bind: %s", strerror(errno)); + LOG_FATAL("bind: %s\n", strerror(errno)); freeaddrinfo(res); exit(EXIT_FAILURE); } freeaddrinfo(res); - LOG_INFO("opened discovery socket on port %u", discovery_port); + LOG_INFO("opened discovery socket on port %u\n", discovery_port); return fd; } diff --git a/helpers/parse_cli.c b/helpers/parse_cli.c index 7f9c094..38f5ff4 100644 --- a/helpers/parse_cli.c +++ b/helpers/parse_cli.c @@ -50,12 +50,12 @@ helpers_parse_cli(int argc, const char **argv, config_t *config) config->run_type = RUN_TYPE_TEST; return; } - LOG_FATAL("bad action '%s' given ('start', 'test')", argv[0]); + LOG_FATAL("bad action '%s' given ('start', 'test')\n", argv[0]); exit(1); } else { - LOG_FATAL("no action given ('start', 'test')"); + LOG_FATAL("no action given ('start', 'test')\n"); exit(1); } return; diff --git a/include/config.h b/include/config.h index 3c74c4f..f8757e4 100644 --- a/include/config.h +++ b/include/config.h @@ -17,6 +17,7 @@ typedef struct { char *file; char *database; + log_level_t log_level; run_type_t run_type; char name[MAX_NAME_LENGTH + 1]; uint16_t discovery_port; diff --git a/include/constants.h b/include/constants.h index a350491..0d27ab7 100644 --- a/include/constants.h +++ b/include/constants.h @@ -1,8 +1,6 @@ #ifndef CONTROLLER_CONTANTS_H #define CONTROLLER_CONTANTS_H -#include - #define SECONDS_PER_DAY 86400 // 60 * 60 * 24 #define SECONDS_PER_MINUTE 60 @@ -30,8 +28,4 @@ #define PIFACE_GPIO_BASE 200 -#ifndef LOG_LEVEL - #define LOG_LEVEL LOG_LEVEL_INFO -#endif - #endif /* CONTROLLER_CONTANTS_H */ diff --git a/include/enums.h b/include/enums.h index c461215..80fc0af 100644 --- a/include/enums.h +++ b/include/enums.h @@ -50,4 +50,14 @@ typedef enum RUN_TYPE_TEST, } run_type_t; +typedef enum +{ + LOG_LEVEL_TRACE = 5, + LOG_LEVEL_DEBUG = 4, + LOG_LEVEL_INFO = 3, + LOG_LEVEL_WARN = 2, + LOG_LEVEL_ERROR = 1, + LOG_LEVEL_FATAL = 0, +} log_level_t; + #endif /* CONTROLLER_ENUMS_H */ diff --git a/include/log_levels.h b/include/log_levels.h deleted file mode 100644 index 32cb011..0000000 --- a/include/log_levels.h +++ /dev/null @@ -1,11 +0,0 @@ -#ifndef CONTROLLER_LOG_LEVELS_H -#define CONTROLLER_LOG_LEVELS_H - -#define LOG_LEVEL_TRACE 5 -#define LOG_LEVEL_DEBUG 4 -#define LOG_LEVEL_INFO 3 -#define LOG_LEVEL_WARN 2 -#define LOG_LEVEL_ERROR 1 -#define LOG_LEVEL_FATAL 0 - -#endif //CONTROLLER_LOG_LEVELS_H diff --git a/include/logger.h b/include/logger.h index 9bfac04..4b33561 100644 --- a/include/logger.h +++ b/include/logger.h @@ -8,55 +8,14 @@ #include #include -#define COLOR_TRACE COLOR_GREEN -#define COLOR_DEBUG COLOR_BLUE -#define COLOR_INFO COLOR_CYAN -#define COLOR_WARN COLOR_YELLOW -#define COLOR_ERROR COLOR_RED -#define COLOR_FATAL COLOR_MAGENTA +void +logger_log(FILE *stream, log_level_t level, const char *filename, int line, const char *func, const char *msg, ...); -#define _LOGGER_TIMESTAMP_SIZE 32 -char _LOGGER_TIMESTAMP[_LOGGER_TIMESTAMP_SIZE]; - -char* -logger_get_timestamp(); - -#define _LOGGER_MESSAGE(msg) " %s %s:%d:%s: " COLOR_NONE msg "\n", logger_get_timestamp(), __FILENAME__, __LINE__, __func__ - -#if LOG_LEVEL >= LOG_LEVEL_TRACE - #define LOG_TRACE(msg, ...) fprintf(stdout, COLOR_TRACE "[TRACE]" _LOGGER_MESSAGE(msg), ##__VA_ARGS__) -#else - #define LOG_TRACE(msg, ...) -#endif - -#if LOG_LEVEL >= LOG_LEVEL_DEBUG - #define LOG_DEBUG(msg, ...) fprintf(stdout, COLOR_DEBUG "[DEBUG]" _LOGGER_MESSAGE(msg), ##__VA_ARGS__) -#else - #define LOG_DEBUG(msg, ...) -#endif - -#if LOG_LEVEL >= LOG_LEVEL_INFO - #define LOG_INFO(msg, ...) fprintf(stdout, COLOR_INFO "[ INFO]" _LOGGER_MESSAGE(msg), ##__VA_ARGS__) -#else - #define LOG_INFO(msg, ...) -#endif - -#if LOG_LEVEL >= LOG_LEVEL_WARN - #define LOG_WARN(msg, ...) fprintf(stdout, COLOR_WARN "[ WARN]" _LOGGER_MESSAGE(msg), ##__VA_ARGS__) -#else - #define LOG_WARN(msg, ...) -#endif - -#if LOG_LEVEL >= LOG_LEVEL_ERROR - #define LOG_ERROR(msg, ...) fprintf(stderr, COLOR_ERROR "[ERROR]" _LOGGER_MESSAGE(msg), ##__VA_ARGS__) -#else - #define LOG_ERROR(msg, ...) -#endif - -#if LOG_LEVEL >= LOG_LEVEL_FATAL - #define LOG_FATAL(msg, ...) fprintf(stderr, COLOR_FATAL "[FATAL]" _LOGGER_MESSAGE(msg), ##__VA_ARGS__) -#else - #define LOG_FATAL(msg, ...) -#endif +#define LOG_TRACE(...) logger_log(stdout, LOG_LEVEL_TRACE, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) +#define LOG_DEBUG(...) logger_log(stdout, LOG_LEVEL_DEBUG, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) +#define LOG_INFO(...) logger_log(stdout, LOG_LEVEL_INFO , __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) +#define LOG_WARN(...) logger_log(stdout, LOG_LEVEL_WARN , __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) +#define LOG_ERROR(...) logger_log(stderr, LOG_LEVEL_ERROR, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) +#define LOG_FATAL(...) logger_log(stderr, LOG_LEVEL_FATAL, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) #endif //CONTROLLER_LOGGER_H diff --git a/include/wiring_debug.h b/include/wiring_debug.h index 906f6cd..ab77be0 100644 --- a/include/wiring_debug.h +++ b/include/wiring_debug.h @@ -4,18 +4,12 @@ #include #ifdef WIRING_PI_DEBUG - #if WIRING_PI_DEBUG > 1 - #define LOG_WIRING_DEBUG(x, ...) LOG_DEBUG(x, ##__VA_ARGS__) - #else - #define LOG_WIRING_DEBUG(x, ...) - #endif + #define wiringPiSetup() LOG_DEBUG("wiringPi wiringPiSetup()\n") + #define wiringPiSetupSys() LOG_DEBUG("wiringPi wiringPiSetupSys()\n") + #define pinMode(x,y) LOG_DEBUG("wiringPi pinMode(%d, %d)\n", x, y) + #define digitalWrite(x,y) LOG_DEBUG("wiringPi digitalWrite(%d, %d)\n", x, y) - #define wiringPiSetup() LOG_WIRING_DEBUG("wiringPi wiringPiSetup()") - #define wiringPiSetupSys() LOG_WIRING_DEBUG("wiringPi wiringPiSetupSys()") - #define pinMode(x,y) LOG_WIRING_DEBUG("wiringPi pinMode(%d, %d)", x, y) - #define digitalWrite(x,y) LOG_WIRING_DEBUG("wiringPi digitalWrite(%d, %d)", x, y) - - #define piFaceSetup(x) LOG_WIRING_DEBUG("wiringPi piFaceSetup(%d)", x) + #define piFaceSetup(x) LOG_DEBUG("wiringPi piFaceSetup(%d)\n", x) #endif #endif /* CONTROLLER_WIRING_DEBUG_H */ diff --git a/logger.c b/logger.c index d7c8136..fb26d56 100644 --- a/logger.c +++ b/logger.c @@ -1,10 +1,59 @@ +#include +#include +#include + +#include #include -char* -logger_get_timestamp() +#define COLOR_TRACE COLOR_GREEN +#define COLOR_DEBUG COLOR_BLUE +#define COLOR_INFO COLOR_CYAN +#define COLOR_WARN COLOR_YELLOW +#define COLOR_ERROR COLOR_RED +#define COLOR_FATAL COLOR_MAGENTA + +void +logger_log(FILE *stream, log_level_t level, const char *filename, int line, const char *func, const char *msg, ...) { + if(global_config.log_level < level) + { + return; + } + + switch(level) + { + case LOG_LEVEL_TRACE: + fprintf(stream, COLOR_TRACE "[TRACE] "); + break; + case LOG_LEVEL_DEBUG: + fprintf(stream, COLOR_DEBUG "[DEBUG] "); + break; + case LOG_LEVEL_INFO: + fprintf(stream, COLOR_INFO "[INFO ] "); + break; + case LOG_LEVEL_WARN: + fprintf(stream, COLOR_WARN "[WARN ] "); + break; + case LOG_LEVEL_ERROR: + fprintf(stream, COLOR_ERROR "[ERROR] "); + break; + case LOG_LEVEL_FATAL: + fprintf(stream, COLOR_FATAL "[FATAL] "); + break; + default: + fprintf(stream, COLOR_NONE "[LOG ] "); + break; + } + + char timestamp_str[32]; time_t rawtime; time(&rawtime); - strftime(_LOGGER_TIMESTAMP, _LOGGER_TIMESTAMP_SIZE, "%Y-%m-%d %H:%M:%S", localtime(&rawtime)); - return _LOGGER_TIMESTAMP; + strftime(timestamp_str, 32, "%Y-%m-%d %H:%M:%S", localtime(&rawtime)); + + fprintf(stream, "%s %s:%d:%s " COLOR_NONE, timestamp_str, filename, line, func); + + va_list args; + va_start(args, msg); + vfprintf(stream, msg, args); + va_end(args); } diff --git a/main.c b/main.c index 360391b..d81c7a5 100644 --- a/main.c +++ b/main.c @@ -32,7 +32,7 @@ static struct pollfd poll_fds[POLL_FDS_COUNT]; static void terminate(int signum) { - LOG_INFO("terminating controller (%d)", signum); + LOG_INFO("terminating controller (%d)\n", signum); for(int i = 0; i < POLL_FDS_COUNT; ++i) { @@ -69,18 +69,20 @@ main(int argc, const char** argv) /******************** LOAD CONFIG ********************/ global_config.file = "controller.ini"; + global_config.database = "controller_db.lmdb"; + global_config.log_level = LOG_LEVEL_INFO; helpers_parse_cli(argc, argv, &global_config); FILE * const ini_file = fopen(global_config.file, "rb"); if(ini_file == NULL) { - LOG_FATAL("config file '%s' was not found", global_config.file); + LOG_FATAL("config file '%s' was not found\n", global_config.file); exit(1); } if(load_ini_file( ini_file, INI_DEFAULT_FORMAT, NULL, helper_load_config, &global_config)) { - LOG_FATAL("unable to parse ini file"); + LOG_FATAL("unable to parse ini file\n"); exit(1); } @@ -88,7 +90,7 @@ main(int argc, const char** argv) if(sizeof(time_t) < 8) { - LOG_WARN("this system is not using 8-bit time"); + LOG_WARN("this system is not using 8-bit time\n"); } /******************** SETUP DATABASE AND THIS CONTROLLER ********************/ @@ -127,10 +129,10 @@ main(int argc, const char** argv) /* Open STREAMS device. */ poll_fds[POLL_FDS_DISCOVERY].fd = fd_discovery; poll_fds[POLL_FDS_DISCOVERY].events = POLLIN; - LOG_DEBUG("setup fd_discovery as %i on index %i", fd_discovery, POLL_FDS_DISCOVERY); + LOG_DEBUG("setup fd_discovery as %i on index %i\n", fd_discovery, POLL_FDS_DISCOVERY); poll_fds[POLL_FDS_COMMAND].fd = fd_command; poll_fds[POLL_FDS_COMMAND].events = POLLIN; - LOG_DEBUG("setup fd_command as %i on index %i", fd_command, POLL_FDS_COMMAND); + LOG_DEBUG("setup fd_command as %i on index %i\n", fd_command, POLL_FDS_COMMAND); /******************** CHECK FOR TESTING RUN ********************/ diff --git a/models/controller.c b/models/controller.c index 735e4d7..764cf2b 100644 --- a/models/controller.c +++ b/models/controller.c @@ -55,16 +55,16 @@ controller_debug(controller_t *controller) { if(controller == NULL) { - LOG_DEBUG("controller is NULL"); + LOG_DEBUG("controller is NULL\n"); return; } char uuid_str[37]; uuid_unparse(controller->id, uuid_str); - LOG_DEBUG("(1/5) %s @ %p", uuid_str, (void*)controller); - LOG_DEBUG("(2/5) name: %s", controller->name); - LOG_DEBUG("(3/5) command_port: %5d discovery_port: %5d", controller->command_port, controller->discovery_port); - LOG_DEBUG("(4/5) relay count: %3d", controller->relay_count); - LOG_DEBUG("(5/5) relays @ %p:", (void*)controller->relays); + LOG_DEBUG("(1/5) %s @ %p\n", uuid_str, (void*)controller); + LOG_DEBUG("(2/5) name: %s\n", controller->name); + LOG_DEBUG("(3/5) command_port: %5d discovery_port: %5d\n", controller->command_port, controller->discovery_port); + LOG_DEBUG("(4/5) relay count: %3d\n", controller->relay_count); + LOG_DEBUG("(5/5) relays @ %p:\n", (void*)controller->relays); for(uint8_t i = 0; i < controller->relay_count; ++i) { relay_debug(controller->relays[i]); diff --git a/models/controller_load.c b/models/controller_load.c index 4c0fb19..4dc4fff 100644 --- a/models/controller_load.c +++ b/models/controller_load.c @@ -18,7 +18,7 @@ controller_load_single(MDB_txn *mdb_txn, MDB_dbi mdb_dbi, db_key_controller_e ke if((err = mdb_get(mdb_txn, mdb_dbi, &key, value)) != 0) { - LOG_ERROR("mdb_get error %s", mdb_strerror(err)); + LOG_ERROR("mdb_get error %s\n", mdb_strerror(err)); exit(1); } } @@ -34,7 +34,7 @@ controller_load(MDB_env *mdb_env) if((err = mdb_txn_begin(mdb_env, NULL, MDB_RDONLY, &mdb_txn)) != 0) { - LOG_ERROR("mdb_txn_begin error %s", mdb_strerror(err)); + LOG_ERROR("mdb_txn_begin error %s\n", mdb_strerror(err)); return NULL; } if((err = mdb_dbi_open(mdb_txn, "controller", 0, &mdb_dbi)) != 0) @@ -42,13 +42,13 @@ controller_load(MDB_env *mdb_env) switch(err) { case MDB_NOTFOUND: - LOG_INFO("no controller found in db. creating new one"); + LOG_INFO("no controller found in db. creating new one\n"); mdb_txn_abort(mdb_txn); new_controller = controller_create(); controller_save(new_controller, mdb_env); return new_controller; default: - LOG_ERROR("mdb_txn_begin error %s", mdb_strerror(err)); + LOG_ERROR("mdb_txn_begin error %s\n", mdb_strerror(err)); return NULL; } } @@ -77,7 +77,7 @@ controller_load(MDB_env *mdb_env) new_controller->relays = malloc(sizeof(relay_t*) * new_controller->relay_count); for(uint8_t i = 0; i < new_controller->relay_count; i++) { - LOG_TRACE("loading relay %d", i); + LOG_TRACE("loading relay %d\n", i); new_controller->relays[i] = relay_load(mdb_env, i); } diff --git a/models/controller_save.c b/models/controller_save.c index d99950a..bc24baf 100644 --- a/models/controller_save.c +++ b/models/controller_save.c @@ -18,7 +18,7 @@ controller_save_single(MDB_txn *mdb_txn, MDB_dbi mdb_dbi, db_key_controller_e ke if((err = mdb_put(mdb_txn, mdb_dbi, &key, &value, 0)) != 0) { - LOG_ERROR("mdb_put error %s", mdb_strerror(err)); + LOG_ERROR("mdb_put error %s\n", mdb_strerror(err)); mdb_txn_abort(mdb_txn); return 1; } @@ -36,13 +36,13 @@ controller_save(controller_t *controller, MDB_env *mdb_env) if((err = mdb_txn_begin(mdb_env, NULL, 0, &mdb_txn)) != 0) { - LOG_ERROR("mdb_txn_begin error %s", mdb_strerror(err)); + LOG_ERROR("mdb_txn_begin error %s\n", mdb_strerror(err)); exit(1); } if((err = mdb_dbi_open(mdb_txn, "controller", MDB_CREATE, &mdb_dbi)) != 0) { - LOG_ERROR("mdb_dbi_open error %s", mdb_strerror(err)); + LOG_ERROR("mdb_dbi_open error %s\n", mdb_strerror(err)); exit(1); } @@ -50,7 +50,7 @@ controller_save(controller_t *controller, MDB_env *mdb_env) value.mv_data = controller->id; if(controller_save_single(mdb_txn, mdb_dbi, DB_KEY_CONTROLLER_ID, value)) { - LOG_ERROR("failed to save ID"); + LOG_ERROR("failed to save ID\n"); return 1; } @@ -58,7 +58,7 @@ controller_save(controller_t *controller, MDB_env *mdb_env) value.mv_data = controller->name; if(controller_save_single(mdb_txn, mdb_dbi, DB_KEY_CONTROLLER_NAME, value)) { - LOG_ERROR("failed to save name"); + LOG_ERROR("failed to save name\n"); return 1; } @@ -66,7 +66,7 @@ controller_save(controller_t *controller, MDB_env *mdb_env) value.mv_data = &controller->command_port; if(controller_save_single(mdb_txn, mdb_dbi, DB_KEY_CONTROLLER_COMMAND_PORT, value)) { - LOG_ERROR("failed to save command port"); + LOG_ERROR("failed to save command port\n"); return 1; } @@ -74,7 +74,7 @@ controller_save(controller_t *controller, MDB_env *mdb_env) value.mv_data = &controller->discovery_port; if(controller_save_single(mdb_txn, mdb_dbi, DB_KEY_CONTROLLER_DISCOVERY_PORT, value)) { - LOG_ERROR("failed to save discovery port"); + LOG_ERROR("failed to save discovery port\n"); return 1; } @@ -82,7 +82,7 @@ controller_save(controller_t *controller, MDB_env *mdb_env) for(uint8_t i = 0; i < controller->relay_count; ++i) { - LOG_TRACE("saving relays[%d/%d]", i, controller->relay_count); + LOG_TRACE("saving relays[%d/%d]\n", i, controller->relay_count); relay_save(controller->relays[i], mdb_env); } diff --git a/models/relay.c b/models/relay.c index deffd95..5610c20 100644 --- a/models/relay.c +++ b/models/relay.c @@ -51,23 +51,18 @@ relay_is_active(relay_t *relay, time_t timestamp_now) } return 0; } -//struct tm time_start, time_now, time_end; -//localtime_r(×tamp_start, &time_start); -//localtime_r(×tamp_now, &time_now); -//localtime_r(×tamp_end, &time_end); -//LOG_DEBUG("%02d:%02d - %02d:%02d - %02d:%02d", time_start.tm_hour, time_start.tm_min, time_now.tm_hour, time_now.tm_min, time_end.tm_hour, time_end.tm_min); void relay_debug(relay_t *relay) { if(relay == NULL) { - LOG_DEBUG("relay is NULL"); + LOG_DEBUG("relay is NULL\n"); return; } - LOG_DEBUG("(1/3) %d @ %p", relay->number, (void*)relay); - LOG_DEBUG("(2/3) name: %s", relay->name); - LOG_DEBUG("(3/3) schedule:"); + LOG_DEBUG("(1/3) %d @ %p\n", relay->number, (void*)relay); + LOG_DEBUG("(2/3) name: %s\n", relay->name); + LOG_DEBUG("(3/3) schedule:\n"); schedule_debug(relay->schedule); } diff --git a/models/relay_load.c b/models/relay_load.c index 141f7c2..7dd9456 100644 --- a/models/relay_load.c +++ b/models/relay_load.c @@ -23,7 +23,7 @@ relay_load_single(MDB_txn *mdb_txn, MDB_dbi mdb_dbi, db_key_relay_e key_relay, u if((err = mdb_get(mdb_txn, mdb_dbi, &key, value)) != 0) { - LOG_ERROR("mdb_get error %s", mdb_strerror(err)); + LOG_ERROR("mdb_get error %s\n", mdb_strerror(err)); mdb_txn_abort(mdb_txn); free(key_data); return 1; @@ -43,7 +43,7 @@ relay_load(MDB_env *mdb_env, uint8_t num) if((err = mdb_txn_begin(mdb_env, NULL, MDB_RDONLY, &mdb_txn)) != 0) { - LOG_ERROR("mdb_txn_begin error %s", mdb_strerror(err)); + LOG_ERROR("mdb_txn_begin error %s\n", mdb_strerror(err)); return relay_create(num); } @@ -52,11 +52,11 @@ relay_load(MDB_env *mdb_env, uint8_t num) switch(err) { case MDB_NOTFOUND: - LOG_INFO("no relay for num %d found in db. returning new one (no relays db)", num); + LOG_INFO("no relay for num %d found in db. returning new one (no relays db)\n", num); mdb_txn_abort(mdb_txn); return relay_create(num); default: - LOG_ERROR("mdb_txn_begin error %s", mdb_strerror(err)); + LOG_ERROR("mdb_txn_begin error %s\n", mdb_strerror(err)); return relay_create(num); } } @@ -68,7 +68,7 @@ relay_load(MDB_env *mdb_env, uint8_t num) if((err = relay_load_single(mdb_txn, mdb_dbi, DB_KEY_RELAY_NAME, num, &value)) != 0) { - LOG_INFO("no relay for num %d found in db. returning new one", num); + LOG_INFO("no relay for num %d found in db. returning new one\n", num); mdb_txn_abort(mdb_txn); // transaction is read only return relay_create(num); } @@ -77,7 +77,7 @@ relay_load(MDB_env *mdb_env, uint8_t num) if((err = relay_load_single(mdb_txn, mdb_dbi, DB_KEY_RELAY_SCHEDULE_ID, num, &value)) != 0) { - LOG_INFO("no relay for num %d found in db. returning new one", num); + LOG_INFO("no relay for num %d found in db. returning new one\n", num); mdb_txn_abort(mdb_txn); // transaction is read only return relay_create(num); } @@ -85,7 +85,7 @@ relay_load(MDB_env *mdb_env, uint8_t num) if((err = relay_load_single(mdb_txn, mdb_dbi, DB_KEY_RELAY_SCHEDULE_PERIODS, num, &value)) != 0) { - LOG_INFO("no relay for num %d found in db. returning new one", num); + LOG_INFO("no relay for num %d found in db. returning new one\n", num); mdb_txn_abort(mdb_txn); // transaction is read only return relay_create(num); } diff --git a/models/relay_save.c b/models/relay_save.c index ff91c9e..28b6a92 100644 --- a/models/relay_save.c +++ b/models/relay_save.c @@ -23,7 +23,7 @@ relay_save_single(MDB_txn *mdb_txn, MDB_dbi mdb_dbi, db_key_relay_e key_relay, u if((err = mdb_put(mdb_txn, mdb_dbi, &key, &value, 0)) != 0) { - LOG_ERROR("mdb_put error %s", mdb_strerror(err)); + LOG_ERROR("mdb_put error %s\n", mdb_strerror(err)); mdb_txn_abort(mdb_txn); free(key_data); return 1; @@ -35,7 +35,7 @@ relay_save_single(MDB_txn *mdb_txn, MDB_dbi mdb_dbi, db_key_relay_e key_relay, u int relay_save(relay_t *relay, MDB_env *mdb_env) { - LOG_TRACE("saving relay %d @ %p", relay->number, relay); + LOG_TRACE("saving relay %d @ %p\n", relay->number, relay); int err; MDB_txn *mdb_txn; @@ -44,13 +44,13 @@ relay_save(relay_t *relay, MDB_env *mdb_env) if((err = mdb_txn_begin(mdb_env, NULL, 0, &mdb_txn)) != 0) { - LOG_ERROR("mdb_txn_begin error %s", mdb_strerror(err)); + LOG_ERROR("mdb_txn_begin error %s\n", mdb_strerror(err)); exit(1); } if((err = mdb_dbi_open(mdb_txn, "relays", MDB_CREATE, &mdb_dbi)) != 0) { - LOG_ERROR("mdb_dbi_open error %s", mdb_strerror(err)); + LOG_ERROR("mdb_dbi_open error %s\n", mdb_strerror(err)); exit(1); } @@ -58,7 +58,7 @@ relay_save(relay_t *relay, MDB_env *mdb_env) value.mv_data = relay->name; if(relay_save_single(mdb_txn, mdb_dbi, DB_KEY_RELAY_NAME, relay->number, value)) { - LOG_ERROR("failed to save name"); + LOG_ERROR("failed to save name\n"); return 1; } @@ -66,7 +66,7 @@ relay_save(relay_t *relay, MDB_env *mdb_env) value.mv_data = relay->schedule->id; if(relay_save_single(mdb_txn, mdb_dbi, DB_KEY_RELAY_SCHEDULE_ID, relay->number, value)) { - LOG_ERROR("failed to save ID"); + LOG_ERROR("failed to save ID\n"); return 1; } @@ -77,7 +77,7 @@ relay_save(relay_t *relay, MDB_env *mdb_env) if(relay_save_single(mdb_txn, mdb_dbi, DB_KEY_RELAY_SCHEDULE_PERIODS, relay->number, value)) { free(periods_blob); - LOG_ERROR("failed to save periods"); + LOG_ERROR("failed to save periods\n"); return 1; } free(periods_blob); diff --git a/models/schedule.c b/models/schedule.c index 901e2ef..894d86f 100644 --- a/models/schedule.c +++ b/models/schedule.c @@ -61,13 +61,13 @@ schedule_debug(schedule_t *schedule) { if(schedule == NULL) { - LOG_DEBUG("schedule is NULL"); + LOG_DEBUG("schedule is NULL\n"); return; } char uuid_str[37]; uuid_unparse(schedule->id, uuid_str); - LOG_DEBUG("(1/3) %s @ %p", uuid_str, (void*)schedule); - LOG_DEBUG("(2/3) period count: %3d", schedule->length); + LOG_DEBUG("(1/3) %s @ %p\n", uuid_str, (void*)schedule); + LOG_DEBUG("(2/3) period count: %3d\n", schedule->length); // one block: "HH:MM-HH:MM, " --> size: 13 (14 with '\0') char *periods_debug_str = malloc(sizeof(char) * ((schedule->length * 13) + 1)); @@ -85,5 +85,5 @@ schedule_debug(schedule_t *schedule) ); } - LOG_DEBUG("(3/3) periods: %s", periods_debug_str); + LOG_DEBUG("(3/3) periods: %s\n", periods_debug_str); } diff --git a/runners/test.c b/runners/test.c index 216637e..a631860 100644 --- a/runners/test.c +++ b/runners/test.c @@ -27,7 +27,7 @@ runner_test(controller_t *controller) driver_piface_set(global_config.relay_configs[i].pin, is_active); break; default: - LOG_WARN("relay %d is not using a driver", i); + LOG_WARN("relay %d is not using a driver\n", i); } sleep(1); }