chore: enhance message port log

deps/message-port/async-uv.cc

@@ -47,33 +47,39 @@ AsyncUV::~AsyncUV() {
 
 bool AsyncUV::Send(uv_loop_t* loop, Task task) {
   if (loop == nullptr) {
+    TRACE(MSGPORT, "invalid loop");
     return false;
   }
   return (new AsyncUV(loop, task))->Send();
 }
 
 size_t AsyncUV::EnqueueTask(Task task) {
+  TRACE(MSGPORT, "EnqueueTask");
   std::lock_guard<std::mutex> lock(queue_mutex_);
   queue_.push(task);
   return queue_.size();
 }
 
 bool AsyncUV::DrainPendingTasks(uv_loop_t* loop) {
+  TRACE(MSGPORT, "DrainPendingTasks");
   std::lock_guard<std::mutex> lock(queue_mutex_);
   TRACE(MSGPORT, "drain pending tasks", queue_.size());
 
   if (loop == nullptr) {
+    TRACE(MSGPORT, "invalid loop");
     return false;
   }
 
   while (!queue_.empty()) {
     AsyncUV::Send(loop, queue_.front());
     queue_.pop();
   }
+  TRACE(MSGPORT, "/drain pending tasks");
   return true;
 }
 
 void AsyncUV::DeletePendingTasks() {
+  TRACE(MSGPORT, "DeletePendingTasks");
   std::lock_guard<std::mutex> lock(queue_mutex_);
   TRACE(MSGPORT, "delete pending tasks", queue_.size());
   if (!queue_.empty()) {
@@ -83,6 +89,7 @@ void AsyncUV::DeletePendingTasks() {
 }
 
 bool AsyncUV::IsPendingTasksEmpty() {
+  TRACE(MSGPORT, "IsPendingTasksEmpty");
   std::lock_guard<std::mutex> lock(queue_mutex_);
   return queue_.empty();
 }
@@ -95,7 +102,9 @@ void AsyncUV::Init(uv_loop_t* loop, Task task) {
   uv_async_init(loop, uv_h_, [](uv_async_t* handle) {
     auto event = static_cast<AsyncUV*>(handle->data);
     if (event->task_) {
+      TRACE(MSGPORT, "run task");
       event->task_(handle);
+      TRACE(MSGPORT, "/run task");
     }
     delete event;
   });

deps/message-port/message-port.cc

@@ -94,7 +94,6 @@ MessageEventSync::~MessageEventSync() {
   TRACE(MSGEVENT, "~MessageEventSync");
 }
 
-
 // Port::Internal
 // -----------------------------------------------------------------------------
 
@@ -152,18 +151,21 @@ Port::Result Port::PostMessageAsync(std::shared_ptr<MessageEvent> event) {
 
   // It's not allowed to use MessageEvents to be sent to different sinks.
   if (event->internal_->target.lock() != internal_->sink.lock()) {
+    TRACE(MSGPORT, "invalid target");
     return Error::InvalidMessageEvent;
   }
 
   // Get a valid loop handle if invalid.
   if (internal_->loop == nullptr) {
     if (!internal_->future.valid()) {
+      TRACE(MSGPORT, "invalid loop future");
       return Error::InvalidPortLoop;
     }
     if (internal_->future.wait_for(std::chrono::milliseconds(1)) ==
         std::future_status::ready) {
       auto loop = internal_->future.get();
       if (loop == nullptr) {
+        TRACE(MSGPORT, "invalid loop handle");
         return Error::InvalidPortLoop;
       }
       internal_->loop = loop;
@@ -182,7 +184,9 @@ Port::Result Port::PostMessageAsync(std::shared_ptr<MessageEvent> event) {
         // Since sink is locked, event->target() is always valid
         // inside the callback.
         try {
+          TRACE(MSGPORT, "call user callback");
           sink->internal_->callback(event.get());
+          TRACE(MSGPORT, "/call user callback");
         } catch (...) {
           TRACE(MSGPORT, "user callback error");
           return;
@@ -194,11 +198,14 @@ Port::Result Port::PostMessageAsync(std::shared_ptr<MessageEvent> event) {
   };
 
   if (internal_->loop == nullptr) {
+    TRACE(MSGPORT, "invalid loop handle, enqueue task instead");
     AsyncUV::EnqueueTask(std::move(task));
     return Error::MessageEventQueued;
   }
 
+  TRACE(MSGPORT, "async uv send");
   AsyncUV::Send(internal_->loop, std::move(task));
+  TRACE(MSGPORT, "/async uv send");
   return Error::NoError;
 }
 
@@ -208,6 +215,7 @@ Port::Result Port::PostMessage(std::shared_ptr<MessageEvent> event) {
 
 Port::Result Port::PostMessage(std::shared_ptr<MessageEventSync> event,
                                int timeout_ms) {
+  TRACE(MSGPORT, "post message sync");
   // TODO: If this function is called from the same thread as lwnode, it can
   // cause a deadlock. It should be called from another thread.
   std::future<std::string> future;
@@ -230,7 +238,9 @@ Port::Result Port::PostMessage(std::shared_ptr<MessageEventSync> event,
       return Error::Timeout;
     }
   } else {
+    TRACE(MSGPORT, "wait PostMessageSync");
     future.wait();
+    TRACE(MSGPORT, "/wait PostMessageSync");
   }
   return future.get();
 }

deps/message-port/nd/nd-logger.cc

@@ -86,10 +86,18 @@ static void writeHeader(std::ostream& ss,
 }
 #endif  // ENABLE_TRACE
 
+#if defined(HOST_TIZEN)
+#include <dlog.h>
+#endif
+
 void LogOutput(const unsigned priority,
                const char* id,
                const std::string& message,
                bool newline) {
+#if defined(HOST_TIZEN)
+  dlog_print(DLOG_INFO, "LWNODE", "[MessagePort] %s", message.c_str());
+  return;
+#else
 #if defined(ENABLE_TRACE)
   if (id && *id) {
     // Format for TRACE
@@ -104,6 +112,7 @@ void LogOutput(const unsigned priority,
 #endif  // ENABLE_TRACE
 
   std::cout << message << (newline ? "\n" : "");
+#endif // defined(HOST_TIZEN)
 }
 
 void PrintF(const unsigned priority,
@@ -133,6 +142,10 @@ std::string CreateCodeLocation(const char* functionName,
 }
 
 bool IsTraceEnabled(const char* key) {
+#if defined(HOST_TIZEN)
+  return true;
+#endif
+
   static std::map<std::string, bool> trace_map;
   static bool is_trace_map_initialized = false;
   static bool allow_all = false;

deps/message-port/nd/nd-logger.h

@@ -51,7 +51,7 @@ enum LOG_PRIORITY {
 
 // TRACE -----------------------------------------------------------------------
 
-#if defined(DEV)
+#if defined(HOST_TIZEN) || defined(DEV)
 #define ENABLE_TRACE
 #endif
 

include/lwnode/lwnode-version.h

@@ -18,5 +18,5 @@
 
  #define LWNODE_VERSION_MAJOR 1
  #define LWNODE_VERSION_MINOR 0
- #define LWNODE_VERSION_PATCH 15
- #define LWNODE_VERSION_TAG "v1.0.15"
+ #define LWNODE_VERSION_PATCH 16
+ #define LWNODE_VERSION_TAG "v1.0.16"

message-port.gyp

@@ -27,6 +27,13 @@
           '<(source_dir)/nd/utils',
         ],
       },
+      'conditions': [
+        ['target_os=="tizen"', {
+          'dependencies': [
+            'deps/tizen.gyp:dlog',
+          ],
+        }],
+      ],
     },
     {
       'target_name': 'nd-message-port',

src/lwnode/nd-mod-message-port.cc

@@ -58,6 +58,7 @@ static MainMessagePortType GetMainMessagePort(ContextRef* context) {
 
 static ObjectRef* InstantiateMessageEvent(ExecutionStateRef* state,
                                           const MessageEvent* event) {
+  TRACE(MSGPORT_JS, "InstantiateMessageEvent");
   ContextRef* context = state->context();
   GlobalObjectRef* global = context->globalObject();
 
@@ -86,6 +87,7 @@ static ObjectRef* InstantiateMessageEvent(ExecutionStateRef* state,
   };
 
   if (event->IsSync()) {
+    TRACE(MSGPORT_JS, "create sync message data");
     auto* data = new MessageEventExtraData();
     auto* event_sync =
         reinterpret_cast<MessageEventSync*>(const_cast<MessageEvent*>(event));
@@ -246,13 +248,15 @@ class MessagePortWrap : public BaseObject {
             v8::HandleScope handle_scope(lwIsolate->toV8());
 
             TryCatchScope scope(state->context(), false);
+            TRACE(MSGPORT_JS, "JS CallFunction");
             maybe = CallFunction(state->context(),
                                  ValueRef::createUndefined(),
                                  onmessage_->asFunctionObject(),
                                  COUNT_OF(argv),
                                  argv);
-
+            TRACE(MSGPORT_JS, "/JS CallFunction");
             if (scope.HasCaught()) {
+              TRACE(MSGPORT_JS, "Caught exception");
               lwIsolate->ScheduleThrow(scope.exception());
             }
 #endif