vrend: reduce tracing overhead by only calling vsnprintf when needed

Most of the time we pass a string that can simply be forwarded to
the perfetto trace function.

Signed-off-by: Gert Wollny <gert.wollny@collabora.com>
Reviewed-by: Chia-I Wu <olvaffe@gmail.com>

src/virgl_util.c

@@ -126,7 +126,13 @@ void trace_init(void)
    vperfetto_min_startTracing(&config);
 }
 
-char *trace_begin(const char* format, ...)
+char *trace_begin(const char* scope)
+{
+   vperfetto_min_beginTrackEvent_VMM(scope);
+   return (void *)1;
+}
+
+char *trace_begin_fmt(const char* format, ...)
 {
    char buffer[1024];
    va_list args;
@@ -150,7 +156,7 @@ void trace_init(void)
 {
 }
 
-char *trace_begin(const char* format, ...)
+char *trace_begin_fmt(const char* format, ...)
 {
    for (int i = 0; i < nesting_depth; ++i)
       fprintf(stderr, "  ");
@@ -171,6 +177,11 @@ char *trace_begin(const char* format, ...)
    return buffer;
 }
 
+char *trace_begin(const char* scope)
+{
+   return trace_begin_fmt("%s", scope);
+}
+
 void trace_end(char **func_name)
 {
    --nesting_depth;

src/virgl_util.h

@@ -63,22 +63,29 @@ void flush_eventfd(int fd);
 
 #ifdef ENABLE_TRACING
 void trace_init(void);
-char *trace_begin(const char* format, ...);
+char *trace_begin(const char* scope);
+char *trace_begin_fmt(const char* format, ...);
 void trace_end(char **dummy);
 
 #define TRACE_INIT() trace_init()
 #define TRACE_FUNC() \
    char *trace_dummy __attribute__((cleanup (trace_end), unused)) = \
-   trace_begin("%s", __func__)
+   trace_begin(__func__)
 
-#define TRACE_SCOPE(FORMAT, ...) \
+#define TRACE_SCOPE(SCOPE) \
    char *trace_dummy __attribute__((cleanup (trace_end), unused)) = \
-   trace_begin(FORMAT, __VA_ARGS__)
+   trace_begin(SCOPE)
+
+
+#define TRACE_SCOPE_FMT(FORMAT, ...) \
+   char *trace_dummy __attribute__((cleanup (trace_end), unused)) = \
+   trace_begin_fmt(FORMAT, __VA_ARGS__)
 
 #else
 #define TRACE_INIT()
 #define TRACE_FUNC()
 #define TRACE_SCOPE(FORMAT, ...)
+#define TRACE_SCOPE_FMT(FORMAT, ...)
 #endif
 
 #endif /* VIRGL_UTIL_H */

src/vrend_decode.c

@@ -757,7 +757,7 @@ static int vrend_decode_create_object(struct vrend_context *ctx, const uint32_t
    VREND_DEBUG(dbg_object, ctx,"  CREATE %-18s handle:0x%x len:%d\n",
                vrend_get_object_type_name(obj_type), handle, length);
 
-   TRACE_SCOPE("CREATE %-18s", vrend_get_object_type_name(obj_type));
+   TRACE_SCOPE_FMT("CREATE %-18s", vrend_get_object_type_name(obj_type));
 
    switch (obj_type){
    case VIRGL_OBJECT_BLEND:
@@ -1615,7 +1615,7 @@ static int vrend_decode_ctx_submit_cmd(struct virgl_context *ctx,
       VREND_DEBUG(dbg_cmd, gdctx->grctx, "%-4d %-20s len:%d\n",
                   cur_offset, vrend_get_comand_name(cmd), len);
 
-      TRACE_SCOPE("%s", vrend_get_comand_name(cmd));
+      TRACE_SCOPE(vrend_get_comand_name(cmd));
 
       ret = decode_table[cmd](gdctx->grctx, buf, len);
       if (ret) {