NODESASS_TRACE: Live tracing facility

binding.gyp

@@ -8,6 +8,7 @@
         'src/create_string.cpp',
         'src/custom_function_bridge.cpp',
         'src/custom_importer_bridge.cpp',
+        'src/debug.cpp',
         'src/sass_context_wrapper.cpp',
         'src/sass_types/boolean.cpp',
         'src/sass_types/color.cpp',

src/custom_function_bridge.cpp

@@ -3,10 +3,12 @@
 #include "custom_function_bridge.h"
 #include "sass_types/factory.h"
 #include "sass_types/value.h"
+#include "debug.h"
 
 Sass_Value* CustomFunctionBridge::post_process_return_value(v8::Local<v8::Value> val) const {
   SassTypes::Value *v_;
   if ((v_ = SassTypes::Factory::unwrap(val))) {
+    TRACEINST(&val) << " CustomFunctionBridge: unwrapping custom function return value...";
     return v_->get_sass_value();
   } else {
     return sass_make_error("A SassValue object was expected.");
@@ -17,6 +19,7 @@ std::vector<v8::Local<v8::Value>> CustomFunctionBridge::pre_process_args(std::ve
   std::vector<v8::Local<v8::Value>> argv = std::vector<v8::Local<v8::Value>>();
 
   for (void* value : in) {
+    TRACEINST(&value) << " CustomFunctionBridge: wrapping custom function parameters...";
     argv.push_back(SassTypes::Factory::create(static_cast<Sass_Value*>(value))->get_js_object());
   }
 

src/debug.cpp

@@ -0,0 +1,27 @@
+#include <stdio.h>
+#include <sstream>
+
+#include <uv.h>
+
+#include "debug.h"
+
+Log::Log() {} 
+
+std::ostringstream& Log::Get(TLogLevel level, void *p, const char *f, const char *filen, int lineno)
+{
+   os << "[NODESASS@" << uv_thread_self() << "] " << p << ":" << f << " " << filen << ":" << lineno << " ";
+   messageLevel = level;
+   return os;
+}
+std::ostringstream& Log::Get(TLogLevel level, const char *f, const char *filen, int lineno)
+{
+   os << "[NODESASS@" << uv_thread_self() << "] " << f << " " << filen << ":" << lineno << " ";
+   messageLevel = level;
+   return os;
+}
+Log::~Log()
+{
+   os << std::endl;
+   fprintf(stderr, "%s", os.str().c_str());
+   fflush(stderr);
+}

src/debug.h

@@ -0,0 +1,38 @@
+#ifndef NODE_SASS_DEBUG_H
+#define NODE_SASS_DEBUG_H
+
+#include <sstream>
+
+enum TLogLevel {logINFO, logTRACE};
+static TLogLevel LogReportingLevel = getenv("NODESASS_TRACE") ? logTRACE : logINFO;
+class Log
+{
+public:
+  Log();
+  virtual ~Log();
+  std::ostringstream& Get(TLogLevel level, void *p, const char *f, const char *filen, int lineno);
+  std::ostringstream& Get(TLogLevel level, const char *f, const char *filen, int lineno);
+public:
+protected:
+  std::ostringstream os;
+private:
+  Log(const Log&);
+  Log& operator =(const Log&);
+private:
+  TLogLevel messageLevel;
+};
+
+// Visual Studio 2013 does not like __func__
+#if _MSC_VER < 1900
+#define __func__ __FUNCTION__
+#endif
+
+#define TRACE() \
+  if (logTRACE > LogReportingLevel) ; \
+  else Log().Get(logTRACE, __func__, __FILE__, __LINE__)
+
+#define TRACEINST(obj) \
+  if (logTRACE > LogReportingLevel) ; \
+  else Log().Get(logTRACE, (obj), __func__, __FILE__, __LINE__)
+
+#endif

src/sass_types/sass_value_wrapper.h

@@ -4,6 +4,7 @@
 #include <stdexcept>
 #include <vector>
 #include <nan.h>
+#include "../debug.h"
 #include "value.h"
 #include "factory.h"
 
@@ -27,6 +28,59 @@ namespace SassTypes
       static NAN_METHOD(New);
       static Sass_Value *fail(const char *, Sass_Value **);
 
+      static void print_value(Sass_Value *v) {
+        if (v) {
+          if (sass_value_is_null(v)) {
+            TRACEINST(v) << "#null";
+          } else if (sass_value_is_number(v)) {
+            TRACEINST(v) << "#number "
+                << sass_number_get_value(v)
+                << " unit=<" << sass_number_get_unit(v) << ">";
+          } else if (sass_value_is_string(v)) {
+            TRACEINST(v) << "#string "
+                << '"' << sass_string_get_value(v) << '"'
+                << ", quoted=" << (sass_string_is_quoted(v) ? 'Y' : 'N');
+          } else if (sass_value_is_boolean(v)) {
+            TRACEINST(v) << "#boolean " << sass_boolean_get_value(v);
+          } else if (sass_value_is_color(v)) {
+            TRACEINST(v) << "#color RGBA: <"
+                << sass_color_get_r(v) << ","
+                << sass_color_get_g(v) << ","
+                << sass_color_get_b(v) << ","
+                << sass_color_get_a(v) << ">";
+          } else if (sass_value_is_list(v)) {
+            enum Sass_Separator sep = sass_list_get_separator(v); 
+            size_t len = sass_list_get_length(v);
+            TRACEINST(v) << "#list "
+                << "separator=<" << (sep == SASS_COMMA ? ',' : ' ') << ">"
+                << "length=" << len;
+            for(size_t i = 0; i < len; i ++) {
+              TRACEINST(v) << "item(" << i << ")";
+              print_value(sass_list_get_value(v, i)); 
+            }
+            TRACEINST(v) << "#list end";
+          } else if (sass_value_is_map(v)) {
+            size_t len = sass_map_get_length(v);
+            TRACEINST(v) << "#map length=" << len;
+            for(size_t i = 0; i < len; i ++) {
+              TRACEINST(v) << "key(" << i << ")";
+              print_value(sass_map_get_key(v, i)); 
+              TRACEINST(v) << "value(" << i << ")";
+              print_value(sass_map_get_value(v, i)); 
+            }
+            TRACEINST(v) << "#map end";
+          } else if (sass_value_is_error(v)) {
+            TRACEINST(v) << "#error " << sass_error_get_message(v);
+          } else if (sass_value_is_warning(v)) {
+            TRACEINST(v) << "#warn " << sass_warning_get_message(v);
+          } else { 
+            TRACEINST(v) << "#unknown";
+          }
+        } else { 
+          TRACE() << "(null value)";
+        }
+      }
+
     protected:
       Sass_Value* value;
       static T* unwrap(v8::Local<v8::Object>);
@@ -42,6 +96,9 @@ namespace SassTypes
   template <class T>
   SassValueWrapper<T>::SassValueWrapper(Sass_Value* v) {
     this->value = sass_clone_value(v);
+    TRACEINST(this) << "ctor " << (void *)this->value << " := " << (void *)v;
+    print_value(v);
+    TRACEINST(this) << "done";
   }
 
   template <class T>
@@ -52,7 +109,11 @@ namespace SassTypes
 
   template <class T>
   Sass_Value* SassValueWrapper<T>::get_sass_value() {
-    return sass_clone_value(this->value);
+    Sass_Value *nv = sass_clone_value(this->value);
+    TRACEINST(this) << (void *)nv << " := " << (void *)this->value;
+    print_value(this->value);
+    TRACEINST(this) << "done";
+    return nv;
   }
 
   template <class T>