[Title] Added a new trace option 'COREGL_TRACE_API_FRAME=1'

[Issue#]
[Problem]
[Cause]
[Solution]
- Shows informations of API usages in one frame.
- Requires an enabled option 'COREGL_TRACE_API=1'
- When using 'COREGL_TRACE_API_FRAME=1',
   'COREGL_TRACE_API_ALL=1' shows logs for all frame.
   otherwise, shows logs for 5 secs.

diff --git a/src/coregl_internal.h b/src/coregl_internal.h
index fb05065..21137be 100644 (file)
--- a/src/coregl_internal.h
+++ b/src/coregl_internal.h
@@ -92,6 +92,7 @@ extern FILE               *trace_fp;
 
 extern int                 trace_api_flag;
 extern int                 trace_api_all_flag;
+extern int                 trace_api_frame_flag;
 extern int                 trace_mem_flag;
 extern int                 trace_mem_all_flag;
 extern int                 trace_ctx_flag;

diff --git a/src/coregl_trace.c b/src/coregl_trace.c
index d86f33d..dac7dcd 100644 (file)
--- a/src/coregl_trace.c
+++ b/src/coregl_trace.c
@@ -6,6 +6,7 @@
 
 int                 trace_api_flag = 0;
 int                 trace_api_all_flag = 0;
+int                 trace_api_frame_flag = 0;
 int                 trace_ctx_flag = 0;
 int                 trace_ctx_force_flag = 0;
 int                 trace_mem_flag = 0;

diff --git a/src/modules/fastpath/coregl_fastpath_egl.c b/src/modules/fastpath/coregl_fastpath_egl.c
index 44d7b06..9a47de1 100644 (file)
--- a/src/modules/fastpath/coregl_fastpath_egl.c
+++ b/src/modules/fastpath/coregl_fastpath_egl.c
@@ -58,7 +58,7 @@ _dump_context_info(const char *ment, int force_output)
                        GET_MY_TSTATE(cur_tstate_tm, cur_tstate);
                        AST(cur_tstate_tm != NULL);
 
-                       TRACE(" %c Thread  [%12d] : Surf <D=[%12p] R=[%12p]>",
+                       TRACE(" %c Thread  [0x%12x] : Surf <D=[%12p] R=[%12p]>",
                              (tstate == cur_tstate_tm) ? '*' : ' ',
                              cur_tstate->thread_id,
                              cur_tstate_tm->rsurf_draw,

diff --git a/src/modules/tracepath/coregl_tracepath.c b/src/modules/tracepath/coregl_tracepath.c
index aad4a44..15226f3 100644 (file)
--- a/src/modules/tracepath/coregl_tracepath.c
+++ b/src/modules/tracepath/coregl_tracepath.c
@@ -116,6 +116,7 @@ init_modules_tracepath()
 #ifdef COREGL_TRACEPATH_TRACE_APICALL_INFO
        trace_api_flag = atoi(get_env_setting("COREGL_TRACE_API"));
        trace_api_all_flag = atoi(get_env_setting("COREGL_TRACE_API_ALL"));
+       trace_api_frame_flag = atoi(get_env_setting("COREGL_TRACE_API_FRAME"));
 #endif
 #ifdef COREGL_TRACEPATH_TRACE_MEMUSE_INFO
        trace_mem_flag = atoi(get_env_setting("COREGL_TRACE_MEM"));
@@ -217,6 +218,7 @@ init_modules_tracepath()
                {
                        COREGL_LOG("\E[40;31;1m(API)\E[0m ");
                        if (trace_api_all_flag == 1) COREGL_LOG("\E[40;31;1m(API-ALL)\E[0m ");
+                       if (trace_api_frame_flag == 1) COREGL_LOG("\E[40;31;1m(API-FRAME)\E[0m ");
                }
                if (trace_ctx_flag == 1) {
                        COREGL_LOG("\E[40;33;1m(CONTEXT)\E[0m ");
@@ -236,7 +238,7 @@ init_modules_tracepath()
                                COREGL_LOG("\E[40;36;1m(SURFACE-PERIOD:%d~%d)\E[0m ", trace_surface_filter_period_begin, trace_surface_filter_period_end);
                        if (trace_surface_filter_type == 1) COREGL_LOG("\E[40;36;1m(SURFACE-TYPE:EGL)\E[0m ");
                        if (trace_surface_filter_type == 2) COREGL_LOG("\E[40;36;1m(SURFACE-TYPE:FBO)\E[0m ");
-                       if (trace_surface_filter_handle != 0) COREGL_LOG("\E[40;36;1m(SURFACE-HANDLE:%p(%d))\E[0m ", trace_surface_filter_handle, trace_surface_filter_handle);
+                       if (trace_surface_filter_handle != 0) COREGL_LOG("\E[40;36;1m(SURFACE-HANDLE:0x%x(%d))\E[0m ", trace_surface_filter_handle, trace_surface_filter_handle);
                        if (trace_surface_filter_size_w > 0 && trace_surface_filter_size_h > 0)
                                COREGL_LOG("\E[40;36;1m(SURFACE-SIZE:%dx%d)\E[0m ", trace_surface_filter_size_w, trace_surface_filter_size_h);
                }
@@ -728,10 +730,10 @@ tracepath_api_trace_output(int force_output)
        }
 
        GET_MY_TSTATE(tstate_tm, tstate);
-       if (tstate_tm == NULL) return;
+       if (tstate_tm == NULL) goto finish;
 
        ftd_table = tstate_tm->ftd_table;
-       if (ftd_table == NULL) return;
+       if (ftd_table == NULL) goto finish;
 
        {
                static Apicall_Data *trace_hint_swap = NULL;
@@ -747,7 +749,7 @@ tracepath_api_trace_output(int force_output)
 
        TRACE("\n");
        TRACE("\E[40;34m========================================================================================================================\E[0m\n");
-       TRACE("\E[40;32;1m  API call info \E[1;37;1m: <PID = %d> Thread ID = %d  [Swaps per Second(P) = %7.2f]\E[0m\n", getpid(), tstate->thread_id, swaps_per_sec);
+       TRACE("\E[40;32;1m  API call info \E[1;37;1m: <PID = %d> Thread ID = 0x%x  [Swaps per Second(P) = %7.2f]\E[0m\n", getpid(), tstate->thread_id, swaps_per_sec);
        TRACE("\E[40;34m========================================================================================================================\E[0m\n");
 
        // highlighted
@@ -803,7 +805,7 @@ tracepath_api_trace_output(int force_output)
 
                                        while (current != NULL)
                                        {
-                                               if (current->traced == 0)
+                                               if (current->traced == 0 && current->call_count > 0)
                                                {
                                                        double elapsed_time = _get_timeval(current->elapsed_time);
                                                        double elapsed_time_per_call = elapsed_time / current->call_count;
@@ -825,36 +827,39 @@ tracepath_api_trace_output(int force_output)
 
        TRACE("\E[40;34m========================================================================================================================\E[0m\n");
 
-       TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
-             "TOTAL elapsed Time",
-             total_elapsed_time,
-             100.0,
-             total_elapsed_time_period,
-             100.0);
-
-
-       TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
-             "OpenGL elapsed Time",
-             total_opengl_elapsed_time,
-             total_opengl_elapsed_time * 100.0 / total_elapsed_time,
-             total_opengl_elapsed_time_period,
-             total_opengl_elapsed_time_period * 100.0 / total_elapsed_time_period);
-
-       TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
-             "Out of OpenGL elapsed time",
-             total_other_elapsed_time,
-             total_other_elapsed_time * 100.0 / total_elapsed_time,
-             total_other_elapsed_time_period,
-             total_other_elapsed_time_period * 100.0 / total_elapsed_time_period);
-
-       TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
-             "CoreGL API tracing overhead",
-             total_elapsed_time - total_opengl_elapsed_time - total_other_elapsed_time,
-             (total_elapsed_time - total_opengl_elapsed_time - total_other_elapsed_time) * 100.0 / total_elapsed_time,
-             total_elapsed_time_period - total_opengl_elapsed_time_period - total_other_elapsed_time_period,
-             (total_elapsed_time_period - total_opengl_elapsed_time_period - total_other_elapsed_time_period) * 100.0 / total_elapsed_time_period);
-
-       TRACE("\E[40;34m========================================================================================================================\E[0m\n");
+       if (trace_api_frame_flag == 0)
+       {
+               TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
+                     "TOTAL elapsed Time",
+                     total_elapsed_time,
+                     100.0,
+                     total_elapsed_time_period,
+                     100.0);
+
+
+               TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
+                     "OpenGL elapsed Time",
+                     total_opengl_elapsed_time,
+                     total_opengl_elapsed_time * 100.0 / total_elapsed_time,
+                     total_opengl_elapsed_time_period,
+                     total_opengl_elapsed_time_period * 100.0 / total_elapsed_time_period);
+
+               TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
+                     "Out of OpenGL elapsed time",
+                     total_other_elapsed_time,
+                     total_other_elapsed_time * 100.0 / total_elapsed_time,
+                     total_other_elapsed_time_period,
+                     total_other_elapsed_time_period * 100.0 / total_elapsed_time_period);
+
+               TRACE("\E[40;36;1m %-39.39s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
+                     "CoreGL API tracing overhead",
+                     total_elapsed_time - total_opengl_elapsed_time - total_other_elapsed_time,
+                     (total_elapsed_time - total_opengl_elapsed_time - total_other_elapsed_time) * 100.0 / total_elapsed_time,
+                     total_elapsed_time_period - total_opengl_elapsed_time_period - total_other_elapsed_time_period,
+                     (total_elapsed_time_period - total_opengl_elapsed_time_period - total_other_elapsed_time_period) * 100.0 / total_elapsed_time_period);
+
+               TRACE("\E[40;34m========================================================================================================================\E[0m\n");
+       }
        TRACE("\n");
 
        for (i = 0; i < MAX_TRACE_TABLE_SIZE; i++)
@@ -882,6 +887,65 @@ finish:
 }
 
 void
+tracepath_api_trace_reset_frame()
+{
+       GLThreadState *tstate = NULL;
+       MY_MODULE_TSTATE *tstate_tm = NULL;
+       Apicall_Data **ftd_table = NULL;
+
+       int i;
+
+       if (trace_api_flag != 1)
+       {
+               goto finish;
+       }
+
+       tstate = get_current_thread_state();
+
+       if (tstate == NULL)
+       {
+               init_new_thread_state();
+
+               tstate = get_current_thread_state();
+               AST(tstate != NULL);
+       }
+
+       GET_MY_TSTATE(tstate_tm, tstate);
+       if (tstate_tm == NULL) goto finish;
+
+       ftd_table = tstate_tm->ftd_table;
+       if (ftd_table == NULL) goto finish;
+
+       for (i = 0; i < MAX_TRACE_TABLE_SIZE; i++)
+       {
+               if (ftd_table[i] != NULL)
+               {
+                       Apicall_Data *current = ftd_table[i];
+
+                       while (current != NULL)
+                       {
+                               current->call_count = 0;
+                               current->last_call_count = 0;
+                               current->elapsed_time.tv_sec = 0;
+                               current->elapsed_time.tv_usec = 0;
+                               current->last_elapsed_time.tv_sec = 0;
+                               current->last_elapsed_time.tv_usec = 0;
+                               current->last_total_elapsed_time.tv_sec = 0;
+                               current->last_total_elapsed_time.tv_usec = 0;
+                               current->total_elapsed_time.tv_sec = 0;
+                               current->total_elapsed_time.tv_usec = 0;
+                               current = (Apicall_Data *)current->trace_data.next;
+                       }
+               }
+       }
+       AST(gettimeofday(&last_initial_time, NULL) == 0);
+
+finish:
+       return;
+
+}
+
+void
 tracepath_mem_trace_output(int force_output)
 {
        static struct timeval tv_last = TIMEVAL_INIT;

diff --git a/src/modules/tracepath/coregl_tracepath.h b/src/modules/tracepath/coregl_tracepath.h
index 61b05d8..a649c58 100644 (file)
--- a/src/modules/tracepath/coregl_tracepath.h
+++ b/src/modules/tracepath/coregl_tracepath.h
@@ -30,7 +30,7 @@
 #ifdef COREGL_TRACEPATH_TRACE_ALL\r
 #define COREGL_TRACEPATH_TRACE_CONTEXT_INFO   // Context state & thread state & Glue-context info\r
 #define COREGL_TRACEPATH_TRACE_STATE_INFO     // Glue-context state info\r
-#define COREGL_TRACEPATH_TRACE_APICALL_INFO   // API call frequency info\r
+#define COREGL_TRACEPATH_TRACE_APICALL_INFO   // API call frequency & each frame call info\r
 #define COREGL_TRACEPATH_TRACE_MEMUSE_INFO   // Memory usage info\r
 #define COREGL_TRACEPATH_TRACE_SURFACE_INFO  // Surface dump info\r
 #endif
@@ -42,10 +42,13 @@
    tracepath_api_trace_end(api, hint, trace_total_time);\r
 # define _COREGL_TRACE_API_OUTPUT(force_output) \
    tracepath_api_trace_output(force_output);\r
+# define _COREGL_TRACE_API_RESET_FRAME() \\r
+   tracepath_api_trace_reset_frame();\r
 #else
 # define _COREGL_TRACE_API_BEGIN(api, hint, trace_total_time) NULL;
 # define _COREGL_TRACE_API_END(api, hint, trace_total_time)
 # define _COREGL_TRACE_API_OUTPUT(force_output)
+# define _COREGL_TRACE_API_RESET_FRAME()\r
 #endif
 \r
 #ifdef COREGL_TRACEPATH_TRACE_MEMUSE_INFO\r
@@ -132,6 +135,7 @@ extern void                tracepath_dump_context_states(int force_output);
 extern void               *tracepath_api_trace_begin(const char *name, void *hint, int trace_total_time);\r
 extern void               *tracepath_api_trace_end(const char *name, void *hint, int trace_total_time);\r
 extern void                tracepath_api_trace_output(int force_output);\r
+extern void                tracepath_api_trace_reset_frame();\r
 \r
 extern void                tracepath_mem_trace_add(const char *desc, int alloc_size);\r
 extern void                tracepath_mem_trace_remove(const char *desc, int alloc_size);\r

diff --git a/src/modules/tracepath/coregl_tracepath_egl.c b/src/modules/tracepath/coregl_tracepath_egl.c
index 1bc186c..efc542c 100644 (file)
--- a/src/modules/tracepath/coregl_tracepath_egl.c
+++ b/src/modules/tracepath/coregl_tracepath_egl.c
@@ -75,7 +75,7 @@ _dump_context_info(const char *ment, int force_output)
                        GET_MY_TSTATE(cur_tstate_tm, cur_tstate);
                        AST(cur_tstate_tm != NULL);
 
-                       TRACE(" %c Thread  [%12d] : Surf <D=[%12p] R=[%12p]>",
+                       TRACE(" %c Thread  [0x%12x] : Surf <D=[%12p] R=[%12p]>",
                              (tstate == cur_tstate_tm) ? '*' : ' ',
                              cur_tstate->thread_id,
                              cur_tstate_tm->surf_draw,
@@ -826,7 +826,22 @@ tracepath_eglSwapBuffers(EGLDisplay dpy, EGLSurface surface)
 
 finish:
        _COREGL_TRACEPATH_FUNC_END();
-       _COREGL_TRACE_API_OUTPUT(0);
+       if (unlikely(trace_api_frame_flag == 1))
+       {
+               if (unlikely(trace_api_all_flag == 1))
+               {
+                       _COREGL_TRACE_API_OUTPUT(1);
+               }
+               else
+               {
+                       _COREGL_TRACE_API_OUTPUT(0);
+               }
+               _COREGL_TRACE_API_RESET_FRAME();
+       }
+       else
+       {
+               _COREGL_TRACE_API_OUTPUT(0);
+       }
        _COREGL_TRACE_MEM_OUTPUT(0);
        return ret;
 }