Rework debug output

Make it consistent across the various build options (with or without
profiling enabled), and add a timestamp using the monotonic clock to
every debug message.

4 files changed, 54 insertions, 39 deletions

diff --git a/clutter/clutter-debug.h b/clutter/clutter-debug.h
index 5cce83393..a49812cdf 100644
--- a/clutter/clutter-debug.h
+++ b/clutter/clutter-debug.h
@@ -52,7 +52,7 @@ typedef enum {
 /* Try the GCC extension for valists in macros */
 #define CLUTTER_NOTE(type,x,a...)                     G_STMT_START { \
         if (G_UNLIKELY (CLUTTER_HAS_DEBUG (type)))                   \
-          { _clutter_profile_trace_message ("[" #type "] "           \
+          { _clutter_profile_trace_message ("[" #type "]:"           \
                                             G_STRLOC ": " x, ##a); } \
                                                       } G_STMT_END
 
@@ -65,15 +65,13 @@ typedef enum {
         if (G_UNLIKELY (CLUTTER_HAS_DEBUG (type)))                   \
           {                                                          \
             gchar * _fmt = g_strdup_printf (__VA_ARGS__);            \
-            _clutter_profile_trace_message ("[" #type "] "           \
-                                            G_STRLOC ": %s",_fmt);  \
+            _clutter_profile_trace_message ("[" #type "]:"           \
+                                            G_STRLOC ": %s",_fmt);   \
             g_free (_fmt);                                           \
-          }                                                          \
-                                                      } G_STMT_END
+          }                                           } G_STMT_END
 #endif
 
 #define CLUTTER_MARK()      CLUTTER_NOTE(MISC, "== mark ==")
-#define CLUTTER_DBG(x) { a }
 
 #define CLUTTER_GLERR()                         G_STMT_START {  \
         if (clutter_debug_flags & CLUTTER_DEBUG_GL) {           \
@@ -87,7 +85,6 @@ typedef enum {
 
 #define CLUTTER_NOTE(type,...)         G_STMT_START { } G_STMT_END
 #define CLUTTER_MARK()                 G_STMT_START { } G_STMT_END
-#define CLUTTER_DBG(x)                 G_STMT_START { } G_STMT_END
 #define CLUTTER_GLERR()                G_STMT_START { } G_STMT_END
 #define CLUTTER_HAS_DEBUG(type)        FALSE
 
@@ -97,6 +94,11 @@ extern guint clutter_debug_flags;
 extern guint clutter_pick_debug_flags;
 extern guint clutter_paint_debug_flags;
 
+void    _clutter_debug_messagev         (const char *format,
+                                         va_list     var_args);
+void    _clutter_debug_message          (const char *format,
+                                         ...);
+
 G_END_DECLS
 
 #endif /* __CLUTTER_DEBUG_H__ */
diff --git a/clutter/clutter-main.c b/clutter/clutter-main.c
index 6d01afce7..3f78bd16b 100644
--- a/clutter/clutter-main.c
+++ b/clutter/clutter-main.c
@@ -3703,3 +3703,29 @@ _clutter_get_sync_to_vblank (void)
 {
   return clutter_sync_to_vblank;
 }
+
+void
+_clutter_debug_messagev (const char *format,
+                         va_list     var_args)
+{
+  gchar *stamp, *fmt;
+
+  stamp = g_strdup_printf ("[%16" G_GINT64_FORMAT "]",
+                           g_get_monotonic_time ());
+  fmt = g_strconcat (stamp, ":", format, NULL);
+  g_free (stamp);
+
+  g_logv (G_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE, fmt, var_args);
+
+  g_free (fmt);
+}
+
+void
+_clutter_debug_message (const char *format, ...)
+{
+  va_list args;
+
+  va_start (args, format);
+  _clutter_debug_messagev (format, args);
+  va_end (args);
+}
diff --git a/clutter/clutter-profile.c b/clutter/clutter-profile.c
index d12850c2c..4b5ceb9ee 100644
--- a/clutter/clutter-profile.c
+++ b/clutter/clutter-profile.c
@@ -1,11 +1,11 @@
 #ifdef CLUTTER_ENABLE_PROFILE
 
+#include <stdlib.h>
+
 /* XXX - we need this for g_atexit() */
 #define G_DISABLE_DEPRECATION_WARNINGS
 #include "clutter-profile.h"
 
-#include <stdlib.h>
-
 UProfContext *_clutter_uprof_context;
 
 static UProfReport *clutter_uprof_report;
@@ -287,12 +287,10 @@ _clutter_profile_trace_message (const char *format, ...)
   va_list ap;
 
   va_start (ap, format);
-  g_logv (G_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE, format, ap);
+  _clutter_debug_messagev (format, ap);
   va_end (ap);
 
-  if (_clutter_uprof_context)
+  if (_clutter_uprof_context != NULL)
     uprof_context_vtrace_message (_clutter_uprof_context, format, ap);
 }
-
 #endif
-
diff --git a/clutter/clutter-profile.h b/clutter/clutter-profile.h
index 8f99bab0c..66d42aeca 100644
--- a/clutter/clutter-profile.h
+++ b/clutter/clutter-profile.h
@@ -19,12 +19,8 @@
  * License along with this library. If not, see <http://www.gnu.org/licenses/>.
  */
 
-#if !defined(__CLUTTER_H_INSIDE__) && !defined(CLUTTER_COMPILATION)
-#error "Only <clutter/clutter.h> can be included directly."
-#endif
-
-#ifndef _CLUTTER_PROFILE_H_
-#define _CLUTTER_PROFILE_H_
+#ifndef __CLUTTER_PROFILE_H__
+#define __CLUTTER_PROFILE_H__
 
 #include <glib.h>
 
@@ -39,7 +35,8 @@ typedef enum {
 
 #include <uprof.h>
 
-extern UProfContext *_clutter_uprof_context;
+extern UProfContext *   _clutter_uprof_context;
+extern guint            clutter_profile_flags;
 
 #define CLUTTER_STATIC_TIMER    UPROF_STATIC_TIMER
 #define CLUTTER_STATIC_COUNTER  UPROF_STATIC_COUNTER
@@ -48,35 +45,27 @@ extern UProfContext *_clutter_uprof_context;
 #define CLUTTER_TIMER_START     UPROF_TIMER_START
 #define CLUTTER_TIMER_STOP      UPROF_TIMER_STOP
 
-void
-_clutter_uprof_init (void);
-
-void
-_clutter_profile_suspend (void);
-void
-_clutter_profile_resume (void);
-
-void
-_clutter_profile_trace_message (const char *format, ...);
+void    _clutter_uprof_init             (void);
+void    _clutter_profile_suspend        (void);
+void    _clutter_profile_resume         (void);
+void    _clutter_profile_trace_message  (const char *format, ...);
 
 #else /* CLUTTER_ENABLE_PROFILE */
 
 #define CLUTTER_STATIC_TIMER(A,B,C,D,E) extern void _clutter_dummy_decl (void)
 #define CLUTTER_STATIC_COUNTER(A,B,C,D) extern void _clutter_dummy_decl (void)
-#define CLUTTER_COUNTER_INC(A,B) G_STMT_START{ (void)0; }G_STMT_END
-#define CLUTTER_COUNTER_DEC(A,B) G_STMT_START{ (void)0; }G_STMT_END
-#define CLUTTER_TIMER_START(A,B) G_STMT_START{ (void)0; }G_STMT_END
-#define CLUTTER_TIMER_STOP(A,B) G_STMT_START{ (void)0; }G_STMT_END
+#define CLUTTER_COUNTER_INC(A,B)        G_STMT_START{ (void)0; }G_STMT_END
+#define CLUTTER_COUNTER_DEC(A,B)        G_STMT_START{ (void)0; }G_STMT_END
+#define CLUTTER_TIMER_START(A,B)        G_STMT_START{ (void)0; }G_STMT_END
+#define CLUTTER_TIMER_STOP(A,B)         G_STMT_START{ (void)0; }G_STMT_END
 
-#define _clutter_profile_suspend() G_STMT_START {} G_STMT_END
-#define _clutter_profile_resume() G_STMT_START {} G_STMT_END
+#define _clutter_profile_suspend()      G_STMT_START {} G_STMT_END
+#define _clutter_profile_resume()       G_STMT_START {} G_STMT_END
 
-#define _clutter_profile_trace_message g_message
+#define _clutter_profile_trace_message  _clutter_debug_message
 
 #endif /* CLUTTER_ENABLE_PROFILE */
 
-extern guint clutter_profile_flags;
-
 G_END_DECLS
 
 #endif /* _CLUTTER_PROFILE_H_ */