implement logging

CMakeLists.txt

@@ -6,6 +6,11 @@ set(CMAKE_C_STANDARD              23)
 set(CMAKE_C_STANDARD_REQUIRED     ON)
 set(CMAKE_EXPORT_COMPILE_COMMANDS ON)
 
+if (NOT PROJECT_BINARY_DIR MATCHES "^${PROJECT_SOURCE_DIR}")
+  message(FATAL_ERROR "build dir must be inside of source dir")
+endif()
+string(LENGTH "${PROJECT_SOURCE_DIR}" PROJECT_DIR_LEN)
+
 include(tool/meta.cmake)
 
 # ---- thirdparty import
@@ -21,6 +26,10 @@ target_include_directories(nf7config
     ${PROJECT_SOURCE_DIR}
     ${NF7_GENERATED_DIR}
 )
+target_compile_definitions(nf7config
+  INTERFACE
+    NF7_PROJECT_DIR_LEN=${PROJECT_DIR_LEN}
+)
 target_compile_options(nf7config INTERFACE
   $<$<CXX_COMPILER_ID:MSVC>:
     /W4
@@ -28,6 +37,7 @@ target_compile_options(nf7config INTERFACE
   >
   $<$<NOT:$<CXX_COMPILER_ID:MSVC>>:
     -Wall -Wextra -Wpedantic
+    -Wno-gnu-zero-variadic-macro-arguments
     $<$<CONFIG:Debug>:-Werror>
   >
 )

core/all.c.sh

@@ -4,6 +4,8 @@ echo "#include \"core/all.h\""
 echo
 echo "#include <assert.h>"
 echo
+echo "#include \"util/log.h\""
+echo
 echo "const uint32_t NF7_CORE_MAX_MODS = UINT32_C($#);"
 echo
 echo "uint32_t nf7_core_new(const struct nf7* nf7, struct nf7_mod** mods) {"
@@ -13,11 +15,16 @@ echo
 echo "  uint32_t i = 0;"
 echo
 for name in $@; do
+  echo "  extern const struct nf7_mod_meta nf7_core_${name};"
   echo "  extern struct nf7_mod* nf7_core_${name}_new(const struct nf7*);"
+  echo "  nf7_util_log_debug(\"loading module: %s\", nf7_core_${name}.name);"
   echo "  mods[i] = nf7_core_${name}_new(nf7);"
   echo "  if (nullptr != mods[i]) {"
   echo "    assert(nullptr != mods[i]->meta);"
   echo "    ++i;"
+  echo "    nf7_util_log_info(\"loaded module: %s\", nf7_core_${name}.name);"
+  echo "  } else {"
+  echo "    nf7_util_log_warn(\"failed to load module: %s\", nf7_core_${name}.name);"
   echo "  }"
   echo
 done

core/sdl2/mod.c

@@ -9,6 +9,7 @@
 
 #include "nf7.h"
 
+#include "util/log.h"
 #include "util/malloc.h"
 
 #include "core/sdl2/poll.h"
@@ -26,14 +27,19 @@ static void del_(struct nf7_mod*);
 struct nf7_mod* nf7_core_sdl2_new(const struct nf7* nf7) {
   assert(nullptr != nf7);
 
-  if (0 == atomic_fetch_add(&sdl_refcnt_, 1)) {
-    if (0 != SDL_Init(SDL_INIT_VIDEO)) {
-      return nullptr;
-    }
+  if (0 < atomic_fetch_add(&sdl_refcnt_, 1)) {
+    nf7_util_log_error(
+        "multiple SDL2 module instance cannot be exists at the same time");
+    return nullptr;
+  }
+  if (0 != SDL_Init(SDL_INIT_VIDEO)) {
+    nf7_util_log_error("failed to init SDL: %s", SDL_GetError());
+    return nullptr;
   }
 
   struct nf7_core_sdl2* this = nf7_util_malloc_new(nf7->malloc, sizeof(*this));
   if (nullptr == this) {
+    nf7_util_log_error("failed to allocate instance");
     goto ABORT;
   }
   *this = (struct nf7_core_sdl2) {
@@ -47,14 +53,21 @@ struct nf7_mod* nf7_core_sdl2_new(const struct nf7* nf7) {
   nf7_util_signal_init(&this->update, this->malloc);
 
   if (!(new_setup_gl_() && new_init_win_(this))) {
+    nf7_util_log_error("failed to setup OpenGL");
     goto ABORT;
   }
+  nf7_util_log_debug("OpenGL is ready");
+
   if (!poll_init_(this)) {
+    nf7_util_log_error("failed to setup event polling");
     goto ABORT;
   }
+  nf7_util_log_debug("polling is activated");
+
   return (struct nf7_mod*) this;
 
 ABORT:
+  nf7_util_log_warn("initialization is aborted");
   del_((struct nf7_mod*) this);
   return nullptr;
 }
@@ -84,14 +97,23 @@ static bool new_init_win_(struct nf7_core_sdl2* this) {
       1280, 720,
       SDL_WINDOW_OPENGL | SDL_WINDOW_RESIZABLE | SDL_WINDOW_ALLOW_HIGHDPI);
   if (nullptr == this->win) {
+    nf7_util_log_error("failed to create SDL window: %s", SDL_GetError());
     return false;
   }
+  nf7_util_log_debug("GUI window is created");
 
   this->gl = SDL_GL_CreateContext(this->win);
   if (nullptr == this->gl) {
+    nf7_util_log_error("failed to create GL context: %s", SDL_GetError());
     return false;
   }
-  SDL_GL_SetSwapInterval(0);
+  nf7_util_log_debug("OpenGL context is created");
+
+  if (0 != SDL_GL_SetSwapInterval(0)) {
+    nf7_util_log_warn(
+        "failed to set swap interval, this will cause a performance issue: %s",
+        SDL_GetError());
+  }
   return true;
 }
 
@@ -101,16 +123,19 @@ static void del_(struct nf7_mod* this_) {
   if (nullptr != this) {
     if (nullptr != this->gl) {
       SDL_GL_DeleteContext(this->gl);
+      nf7_util_log_debug("OpenGL context is deleted");
     }
     if (nullptr != this->win) {
       SDL_DestroyWindow(this->win);
+      nf7_util_log_debug("GUI window is destroyed");
     }
-
     nf7_util_signal_deinit(&this->update);
     nf7_util_malloc_del(this->malloc, this);
   }
-  if (0 == atomic_fetch_sub(&sdl_refcnt_, 1)) {
+  if (1 == atomic_fetch_sub(&sdl_refcnt_, 1)) {
+    nf7_util_log_debug("finalizing SDL...");
     SDL_Quit();
+    nf7_util_log_info("SDL is finalized");
   }
 }
 

core/sdl2/poll.h

@@ -3,6 +3,8 @@
 
 #include <assert.h>
 
+#include "util/log.h"
+
 #include "core/sdl2/mod.h"
 
 static bool poll_init_(struct nf7_core_sdl2*);
@@ -15,11 +17,13 @@ static bool poll_init_(struct nf7_core_sdl2* this) {
   assert(nullptr != this);
 
   if (0 != uv_timer_init(this->uv, &this->poll_timer)) {
+    nf7_util_log_error("failed to init poll timer");
     return false;
   }
   this->poll_timer.data = this;
 
   if (0 != uv_timer_start(&this->poll_timer, poll_proc_, 0, 0)) {
+    nf7_util_log_error("failed to start poll timer");
     poll_deinit_(this);
     return false;
   }
@@ -36,9 +40,16 @@ static void poll_proc_(uv_timer_t* timer) {
   struct nf7_core_sdl2* this = timer->data;
 
   SDL_Event e;
-  while (0 != SDL_PollEvent(&e)) { }
+  while (0 != SDL_PollEvent(&e)) {
+    if (SDL_QUIT == e.type) {
+      nf7_util_log_info("SDL2 event poller is uninstalled");
+      poll_deinit_(this);
+      return;
+    }
+  }
 
   if (0 != uv_timer_start(&this->poll_timer, poll_proc_, this->poll_interval, 0)) {
+    nf7_util_log_error("failed to restart poll timer");
     poll_deinit_(this);
   }
 }

main.c

@@ -1,4 +1,5 @@
 // No copyright
+#include <assert.h>
 #include <stdatomic.h>
 #include <stdbool.h>
 #include <stdio.h>
@@ -8,6 +9,7 @@
 
 #include "nf7.h"
 
+#include "util/log.h"
 #include "util/malloc.h"
 
 #include "core/all.h"
@@ -17,9 +19,12 @@ static void cb_close_all_handles_(uv_handle_t*, void*);
 
 
 int main(int argc, char** argv) {
+  nf7_util_log_info("HELLO :)");
+
   // init loop
   uv_loop_t uv;
-  if (0 != uv_loop_init(&uv)) {
+  if (0 != nf7_util_log_uv(uv_loop_init(&uv))) {
+    nf7_util_log_error("failed to init main loop");
     return EXIT_FAILURE;
   }
   struct nf7 nf7 = {
@@ -34,29 +39,39 @@ int main(int argc, char** argv) {
   struct nf7_mod* nf7_mods[NF7_CORE_MAX_MODS];
   nf7.mods.n   = nf7_core_new(&nf7, nf7_mods);
   nf7.mods.ptr = nf7_mods;
+  nf7_util_log_info("loaded %" PRIu32 " modules", nf7.mods.n);
 
   // main loop
-  if (0 != uv_run(&uv, UV_RUN_DEFAULT)) {
+  if (0 != nf7_util_log_uv(uv_run(&uv, UV_RUN_DEFAULT))) {
+    nf7_util_log_error("failed to start main loop");
     return EXIT_FAILURE;
   }
+  nf7_util_log_info("exiting Nf7...");
 
   // destroy modules
   for (uint32_t i = 0; i < nf7.mods.n; ++i) {
     struct nf7_mod* mod = nf7.mods.ptr[i];
-    if (nullptr != mod->meta->delete) {
-      mod->meta->delete(mod);
-    }
+    assert(mod->meta->delete);
+
+    nf7_util_log_debug("unloading module: %s", mod->meta->name);
+    mod->meta->delete(mod);
   }
+  nf7_util_log_info("unloaded all modules");
 
   // teardown loop
   uv_walk(&uv, cb_close_all_handles_, nullptr);
   uv_run(&uv, UV_RUN_DEFAULT);
   if (0 != uv_loop_close(&uv)) {
+    nf7_util_log_warn("failed to close main loop gracefully");
     return EXIT_FAILURE;
   }
+
+  nf7_util_log_info("ALL DONE X)");
   return EXIT_SUCCESS;
 }
 
 static void cb_close_all_handles_(uv_handle_t* handle, void*) {
+  nf7_util_log_debug(
+      "closing remaining handle: %s", uv_handle_type_name(handle->type));
   uv_close(handle, nullptr);
 }

tool/meta.cmake

@@ -36,7 +36,7 @@ function(target_meta_source args_target args_scope args_src)
   add_custom_command(
     COMMAND "${src_abs}" ${args_ARGS} > "${dst_abs}"
     OUTPUT "${dst_abs}"
-    DEPENDS ${args_DEPENDS}
+    DEPENDS "${src_abs}" ${args_DEPENDS}
     WORKING_DIRECTORY "${src_dir_abs}"
     VERBATIM
   )

util/CMakeLists.txt

@@ -4,6 +4,7 @@ target_sources(nf7util
     malloc.c
   PUBLIC
     array.h
+    log.h
     malloc.h
     signal.h
 )

util/log.h

@@ -0,0 +1,38 @@
+// No copyright
+#pragma once
+
+#include <inttypes.h>
+#include <stdint.h>
+#include <stdio.h>
+
+#define NF7_UTIL_LOG_CURRENT_FILE  \
+    ((const char*) __FILE__ + NF7_PROJECT_DIR_LEN)
+
+#define nf7_util_log(level, file, line, func, fmt, ...)  \
+    printf(level "|%s:%" PRIu64 "|%s|" fmt "\n", file, (uint64_t) line, func __VA_OPT__(,) __VA_ARGS__)
+#define nf7_util_log_sugar(level, ...)  \
+    nf7_util_log(level, NF7_UTIL_LOG_CURRENT_FILE, __LINE__, __func__, __VA_ARGS__)
+
+#if !defined(NDEBUG)
+# define nf7_util_log_debug(...)  \
+    nf7_util_log_sugar("DBG", __VA_ARGS__)
+#else
+# define nf7_util_log_debug(fmt, ...) do { } while (0)
+#endif
+
+#define nf7_util_log_info(...)  \
+    nf7_util_log_sugar("INF", __VA_ARGS__)
+#define nf7_util_log_warn(...)  \
+    nf7_util_log_sugar("WRN", __VA_ARGS__)
+#define nf7_util_log_error(...)  \
+    nf7_util_log_sugar("ERR", __VA_ARGS__)
+
+#define nf7_util_log_uv(ret)  \
+    nf7_util_log_uv_((ret), NF7_UTIL_LOG_CURRENT_FILE, __LINE__, __func__)
+static inline int nf7_util_log_uv_(
+    int ret, const char* file, uint64_t line, const char* func) {
+  if (0 != ret) {
+    nf7_util_log("INF", file, line, func, "uv api error: %s", uv_strerror(ret));
+  }
+  return ret;
+}