Debug traces + CB (#90)

Documentation will be part of BabylonNative.

2 levels of logging
# Code logging
Works are a console log. Enable Debug Trace (off by default) and set an
outputter(none set by default) then call Trace.
```
SetTraceOutput([](const char *trace){
printf("%s\n", trace);
});
SetDebugTrace(true);
...
Trace("Error detected.");
```

# Babylon code instrumentation
Babylon code is instrumented and will use Trace function described
earlier IF `JSRUNTIMEHOST_DEBUG_TRACE` preprocessor is defined. If it's
not (default), no log will happen and no performance impact.

To summarize, user can log in his own code with Babylon logging API.
Babylon Native and JSRuntimeHost code is instrumented but will only log
if `JSRUNTIMEHOST_DEBUG_TRACE` preprocessor is defined and logging is
enabled and an outputer function is set.

Thread safety in the logging output is responsability of the user.

Author: CedricGuillemet

CMakeLists.txt

@@ -56,6 +56,7 @@ set(CMAKE_CXX_STANDARD_REQUIRED ON)
 # General
 option(JSRUNTIMEHOST_TESTS "Include JsRuntimeHost Tests." ${PROJECT_IS_TOP_LEVEL})
 option(NAPI_BUILD_ABI "Build the ABI layer." ON)
+option(BABYLON_DEBUG_TRACE "Debug Trace callback."  OFF)
 
 # Core
 option(JSRUNTIMEHOST_CORE_APPRUNTIME "Include JsRuntimeHost Core AppRuntime" ON)
@@ -80,6 +81,10 @@ if(JSRUNTIMEHOST_POLYFILL_XMLHTTPREQUEST)
     set_property(TARGET UrlLib PROPERTY FOLDER Dependencies)
 endif()
 
+if(BABYLON_DEBUG_TRACE)
+    add_definitions(-DBABYLON_DEBUG_TRACE)
+endif()
+
 if(NAPI_JAVASCRIPT_ENGINE STREQUAL "V8" AND JSRUNTIMEHOST_CORE_APPRUNTIME_V8_INSPECTOR)
     FetchContent_MakeAvailable_With_Message(asio)
     add_library(asio INTERFACE)

Core/Foundation/CMakeLists.txt

@@ -1,7 +1,9 @@
 set(SOURCES
-    "Include/Babylon/Api.h")
+    "Include/Babylon/Api.h"
+    "Include/Babylon/DebugTrace.h"
+    "Source/DebugTrace.cpp")
 
-add_library(Foundation INTERFACE)
+add_library(Foundation ${SOURCES})
 
 target_include_directories(Foundation INTERFACE "Include")
 

Core/Foundation/Include/Babylon/DebugTrace.h

@@ -0,0 +1,25 @@
+#pragma once
+#include <functional>
+
+#ifdef BABYLON_DEBUG_TRACE
+#define _STRINGIFY(x) #x
+#define _TOSTRING(x) _STRINGIFY(x)
+#define _DEBUG_TRACE(format, ...) Babylon::DebugTrace::Trace(__FILE__ "(" _TOSTRING(__LINE__) "): " format "\n", ##__VA_ARGS__); 
+
+#define DEBUG_TRACE _DEBUG_TRACE
+#else // No debugging trace enabled
+#define DEBUG_TRACE(...)
+#endif // BABYLON_DEBUG_TRACE
+
+namespace Babylon
+{
+    namespace DebugTrace
+    {
+        // off by default.
+        void EnableDebugTrace(bool enabled);
+        // equivalent of a printf that will use TraceOutput function to log. Need Debug Trace to be enabled.
+        void Trace(const char* format, ...);
+        // set the function used to output.
+        void SetTraceOutput(std::function<void(const char* trace)> traceOutputFunction);
+    }
+}

Core/Foundation/Source/DebugTrace.cpp

@@ -0,0 +1,52 @@
+#include <stdarg.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <functional>
+
+namespace
+{
+    bool g_debugTraceEnabled{};
+    std::function<void(const char* output)> g_traceOutputFunction;
+    void TraceArgs(const char* format, va_list args)
+    {
+        char temp[8192];
+        auto len = vsnprintf(temp, sizeof(temp), format, args);
+        if (len >= 0 && len < sizeof(temp))
+        {
+            temp[len] = '\0';
+            g_traceOutputFunction(temp);
+        }
+        else
+        {
+            g_traceOutputFunction("Error while printing trace string.");
+        }
+    }
+}
+
+namespace Babylon
+{
+    namespace DebugTrace
+    {
+        void EnableDebugTrace(bool enabled)
+        {
+            g_debugTraceEnabled = enabled;
+        }
+
+        void Trace(const char* format, ...)
+        {
+            if (!(g_debugTraceEnabled && g_traceOutputFunction))
+            {
+                return;
+            }
+            va_list args;
+            va_start(args, format);
+            TraceArgs(format, args);
+            va_end(args);
+        }
+
+        void SetTraceOutput(std::function<void(const char* trace)> traceOutputFunction)
+        {
+            g_traceOutputFunction = std::move(traceOutputFunction);
+        }
+    }
+}

Core/JsRuntime/Source/JsRuntime.cpp

@@ -1,4 +1,5 @@
 #include "JsRuntime.h"
+#include "Babylon/DebugTrace.h"
 
 namespace Babylon
 {
@@ -23,6 +24,8 @@ namespace Babylon
 
         Napi::Value jsRuntime = Napi::External<JsRuntime>::New(env, this, [](Napi::Env, JsRuntime* runtime) { delete runtime; });
         jsNative.Set(JS_RUNTIME_NAME, jsRuntime);
+
+        DEBUG_TRACE("JsRuntime created");
     }
 
     JsRuntime& BABYLON_API JsRuntime::CreateForJavaScript(Napi::Env env, DispatchFunctionT dispatchFunction)

Core/ScriptLoader/Source/ScriptLoader.cpp

@@ -1,6 +1,7 @@
 #include <Babylon/ScriptLoader.h>
 #include <UrlLib/UrlLib.h>
 #include <arcana/threading/task.h>
+#include "Babylon/DebugTrace.h"
 
 namespace Babylon
 {
@@ -16,11 +17,13 @@ namespace Babylon
         void LoadScript(std::string url)
         {
             UrlLib::UrlRequest request;
+            DEBUG_TRACE("Loading script at url %s", url.c_str());
             request.Open(UrlLib::UrlMethod::Get, url);
             request.ResponseType(UrlLib::UrlResponseType::String);
             m_task = arcana::when_all(m_task, request.SendAsync()).then(arcana::inline_scheduler, arcana::cancellation::none(), [dispatchFunction = m_dispatchFunction, request = std::move(request), url = std::move(url)](auto) mutable {
                 arcana::task_completion_source<void, std::exception_ptr> taskCompletionSource{};
                 dispatchFunction([taskCompletionSource, request = std::move(request), url = std::move(url)](Napi::Env env) mutable {
+                    DEBUG_TRACE("Evaluating script at url %s", url.c_str());
                     Napi::Eval(env, request.ResponseString().data(), url.data());
                     taskCompletionSource.complete();
                 });

Tests/UnitTests/Android/app/src/main/cpp/JNI.cpp

@@ -3,7 +3,7 @@
 #include <AndroidExtensions/Globals.h>
 #include <AndroidExtensions/JavaWrappers.h>
 #include <AndroidExtensions/StdoutLogger.h>
-
+#include "Babylon/DebugTrace.h"
 #include <Shared/Shared.h>
 
 extern "C" JNIEXPORT jint JNICALL
@@ -21,6 +21,9 @@ Java_com_jsruntimehost_unittests_Native_javaScriptTests(JNIEnv* env, jclass claz
 
     android::global::Initialize(javaVM, context);
 
+    Babylon::DebugTrace::EnableDebugTrace(true);
+    Babylon::DebugTrace::SetTraceOutput([](const char* trace) { printf("%s\n", trace); fflush(stdout); });
+
     auto testResult = RunTests();
 
     android::StdoutLogger::Stop();

Tests/UnitTests/CMakeLists.txt

@@ -52,6 +52,7 @@ target_link_libraries(UnitTests
     PRIVATE XMLHttpRequest
     PRIVATE WebSocket
     PRIVATE gtest_main
+    PRIVATE Foundation
     ${ADDITIONAL_LIBRARIES})
 
 # See https://gitlab.kitware.com/cmake/cmake/-/issues/23543

Tests/UnitTests/Linux/App.cpp

@@ -1,6 +1,11 @@
 #include "../Shared/Shared.h"
+#include "Babylon/DebugTrace.h"
+#include <cstdio>
 
 int main()
 {
+    Babylon::DebugTrace::EnableDebugTrace(true);
+    Babylon::DebugTrace::SetTraceOutput([](const char* trace) { printf("%s\n", trace); fflush(stdout); });
+
     return RunTests();
 }

Tests/UnitTests/Win32/App.cpp

@@ -1,9 +1,13 @@
 #include "../Shared/Shared.h"
 #include <Windows.h>
+#include "Babylon/DebugTrace.h"
 
 int main()
 {
     SetConsoleOutputCP(CP_UTF8);
 
+    Babylon::DebugTrace::EnableDebugTrace(true);
+    Babylon::DebugTrace::SetTraceOutput([](const char* trace) { OutputDebugStringA(trace); });
+
     return RunTests();
 }