chore: improve development logs

Signed-off-by: Daeyeon Jeong <[email protected]>

Author: daeyeon

deps/node/lib/internal/main/run_main_module.js

@@ -1,17 +1,31 @@
 'use strict';
 
+// @lwnode
+process._rawDebug('js:run_main_module');
+
 const {
   prepareMainThreadExecution
 } = require('internal/bootstrap/pre_execution');
 
+process._rawDebug('js:prepareMainThreadExecution');
+
 prepareMainThreadExecution(true);
 
+process._rawDebug('js:markBootstrapComplete');
+
 markBootstrapComplete();
 
+process._rawDebug('+js:runMain');
+
 // Note: this loads the module through the ESM loader if the module is
 // determined to be an ES module. This hangs from the CJS module loader
 // because we currently allow monkey-patching of the module loaders
 // in the preloaded scripts through require('module').
 // runMain here might be monkey-patched by users in --require.
 // XXX: the monkey-patchability here should probably be deprecated.
 require('internal/modules/cjs/loader').Module.runMain(process.argv[1]);
+
+process._rawDebug('-js:runMain');
+
+let list = process.lwnode.getModuleList();
+process._rawDebug(list, list.length);

deps/node/lib/internal/modules/cjs/helpers.js

@@ -32,6 +32,8 @@ function loadNativeModule(filename, request) {
   const mod = NativeModule.map.get(filename);
   if (mod) {
     debug('load native module %s', request);
+    // @lwnode
+    process._rawDebug('=js:load native module', request);
     mod.compileForPublicLoader();
     return mod;
   }

deps/node/lib/internal/modules/cjs/loader.js

@@ -1065,8 +1065,11 @@ Module.prototype._compile = function(content, filename) {
     result = inspectorWrapper(compiledWrapper, thisValue, exports,
                               require, module, filename, dirname);
   } else {
+    // @lwnode
+    process._rawDebug('+js:compiledWrapper.call', filename);
     result = compiledWrapper.call(thisValue, exports, require, module,
                                   filename, dirname);
+    process._rawDebug('-js:compiledWrapper.call', filename);
   }
   hasLoadedAnyUserCJSModule = true;
   if (requireDepth === 0) statCache = null;

deps/node/lib/internal/process/execution.js

@@ -148,7 +148,11 @@ function createOnGlobalUncaughtException() {
         }
       } catch {}  // Ignore the exception. Diagnostic reporting is unavailable.
     }
-
+    // @lwnode
+    process._rawDebug('js:uncaughtException or unhandledRejection detected.');
+    if (process.lwnode.hasSystemInfo('tizen')) {
+      console.warn(`Warning: It is not safe to resume normal operation after 'uncaughtException' or 'unhandledRejection'. (https://nodejs.org/api/process.html#warning-using-uncaughtexception-correctly)`);
+    }
     const type = fromPromise ? 'unhandledRejection' : 'uncaughtException';
     process.emit('uncaughtExceptionMonitor', er, type);
     if (exceptionHandlerState.captureFn !== null) {

deps/node/src/lwnode/lwnode-public.cc

@@ -145,7 +145,7 @@ Runtime::~Runtime() {
 
 int Runtime::Start(int argc, char** argv, std::promise<void>&& promise) {
   LWNODE_PERF_LOG("[Runtime::Start]");
-  LWNODE_DEV_LOG("[Runtime] version:", LWNODE_VERSION_TAG);
+  LWNODE_DEV_LOG("[Runtime] version: %s", LWNODE_VERSION_TAG);
 #if defined(NDEBUG)
   LWNODE_DEV_LOG("[Runtime] release mode");
 #else

deps/node/src/node_main_lw_runner-inl.h

@@ -121,10 +121,11 @@ class LWNodeMainRunner {
     Isolate::Scope isolate_scope(isolate_);
     HandleScope handle_scope(isolate_);
 
+    LWNODE_DEV_LOG("[LWNodeMainRunner::Run] create main environment");
     int exit_code = 0;
     DeleteFnPtr<Environment, FreeEnvironment> env_ =
         nodeMainInstance.CreateMainEnvironment(&exit_code);
-    LWNODE_DEV_LOG("[LWNodeMainRunner::Run] create main environment");
+    LWNODE_DEV_LOG("[LWNodeMainRunner::Run] /create main environment");
 
     CHECK_NOT_NULL(env_);
 
@@ -148,16 +149,20 @@ class LWNodeMainRunner {
     }
 
     if (exit_code == 0) {
-      LoadEnvironment(env_.get());
       LWNODE_DEV_LOG("[LWNodeMainRunner::Run] load environment");
+      LoadEnvironment(env_.get());
+      LWNODE_DEV_LOG("[LWNodeMainRunner::Run] /load environment");
 
       env_->set_trace_sync_io(env_->options()->trace_sync_io);
 
       try {
         LWNODE_PERF_LOG("[LWNodeMainRunner::Run] loaded script");
+        LWNODE_DEV_LOG("[LWNodeMainRunner::Run] set runtime ready");
         promise_.set_value();
       } catch (const std::exception& e) {
-        LWNODE_DEV_LOG("[LWNodeMainRunner::Run] promise error:", e.what());
+        LWNODE_DEV_LOG("[LWNodeMainRunner::Run] promise error: %s", e.what());
+        v8::V8::ShutdownPlatform();
+        return 1;
       }
 
       {

deps/node/src/node_process_methods.cc

@@ -221,8 +221,12 @@ void RawDebug(const FunctionCallbackInfo<Value>& args) {
   CHECK(args.Length() == 1 && args[0]->IsString() &&
         "must be called with a single string");
   Utf8Value message(args.GetIsolate(), args[0]);
-  FPrintF(stderr, "%s\n", message);
-  fflush(stderr);
+#if defined(HOST_TIZEN) || defined(DEV)
+  LWNode::rawDebug(message.ToString());
+#else
+  // FPrintF(stderr, "%s\n", message);
+  // fflush(stderr);
+#endif
 }
 
 static void Umask(const FunctionCallbackInfo<Value>& args) {

deps/node/test/skip_tests.txt

@@ -64,6 +64,7 @@ test/parallel/test-process-env-allowed-flags-are-documented.js
 test/parallel/test-process-env-symbols.js
 test/parallel/test-process-env-tz.js
 test/parallel/test-process-env.js
+test/parallel/test-process-raw-debug.js # rawDebug 는 js 로그로 사용
 test/parallel/test-process-versions.js
 test/parallel/test-promise-reject-callback-exception.js
 test/parallel/test-promise-swallowed-event.js

include/lwnode/lwnode.h

@@ -58,6 +58,7 @@ void SetCanCallIntoJS(bool can_call_into_js);
 void IdleGC(v8::Isolate* isolate = nullptr);
 void initDebugger();
 bool dumpSelfMemorySnapshot();
+void rawDebug(std::string message);
 
 class MessageLoop {
   using WakeupMainloopHandler = std::function<void()>;

src/api/utils/logger/logger.h

@@ -20,13 +20,21 @@
 #include "logger-impl.h"
 #include "logger-util.h"
 
+#if defined(HOST_TIZEN)
+#include <dlog.h>
+#endif
+
 // loggers using LWNodeLogger which supports dlog
 #define LWNODE_USER_LOG(...) LWNodeLogger(LogKind::user()).log(__VA_ARGS__)
+
 #if defined(HOST_TIZEN)
-#define LWNODE_DEV_LOG(...) LWNodeLogger(LogKind::lwnode()).log(__VA_ARGS__)
+#define LWNODE_DEV_LOG(...) dlog_print(DLOG_INFO, "LWNODE", __VA_ARGS__);
+#elif defined(DEV)
+#define LWNODE_DEV_LOG(fmt, ...) printf(fmt "\n", ##__VA_ARGS__);
 #else
-#define LWNODE_DEV_LOG(...)
+#define LWNODE_DEV_LOG(fmt, ...)
 #endif
+
 #define LWNODE_DEV_LOGF(fmt, ...)                                              \
   LWNodeLogger(LogKind::lwnode()).print(fmt, ##__VA_ARGS__)
 
@@ -36,7 +44,7 @@
 #define LWNODE_PERF_LOG(...)                                                   \
   dlog_print(DLOG_INFO,                                                        \
              "LWNODE",                                                         \
-             "[%.0lfms] %s\n",                                                 \
+             "[%.0lfms] %s",                                                   \
              measurePerformance(),                                             \
              ##__VA_ARGS__);
 #elif !defined(NDEBUG)

src/lwnode/lwnode.cc

@@ -103,6 +103,10 @@ bool dumpSelfMemorySnapshot() {
   return dumpMemorySnapshot(createDumpFilePath(), smaps);
 }
 
+void rawDebug(std::string message) {
+  LWNODE_DEV_LOG("%s", message.c_str());
+}
+
 static ValueRef* PssUsage(ExecutionStateRef* state,
                           ValueRef* thisValue,
                           size_t argc,
@@ -332,6 +336,7 @@ void IdleGC(v8::Isolate* isolate) {
   }
   Escargot::Memory::gc();
   malloc_trim(0);
+  LWNODE_DEV_LOG("[GC] heap %zu", Escargot::Memory::heapSize());
 }
 
 void initDebugger() {

src/lwnode/nd-vm-main-message-port.cc

@@ -57,7 +57,7 @@ void MainMessagePort::Init(ContextRef* context, uv_loop_t* loop) {
   try {
     internal_->uv_promise_.set_value(uv_loop_);
   } catch (const std::exception& e) {
-    LWNODE_DEV_LOG("[MainMessagePort::Init] promise error:", e.what());
+    LWNODE_DEV_LOG("[MainMessagePort::Init] promise error: %s", e.what());
   }
 
   Channel::DrainPendingMessages(uv_loop_);