[Trace] Add 'MAX elapsed time' at API tracing module
authorHaegeun Park <haegeun.park@samsung.com>
Thu, 28 Jun 2012 13:27:31 +0000 (06:27 -0700)
committerHaegeun Park <haegeun.park@samsung.com>
Thu, 28 Jun 2012 13:27:31 +0000 (06:27 -0700)
- Minor bug fixes (STATE tracing module)

src/modules/fastpath/coregl_fastpath.c
src/modules/fastpath/coregl_fastpath.h
src/modules/tracepath/coregl_tracepath.c
src/modules/tracepath/coregl_tracepath_egl.c

index cd0103d..e4cb861 100644 (file)
@@ -1263,10 +1263,10 @@ fastpath_make_context_current(GLGlueContext *oldctx, GLGlueContext *newctx)
 
 finish:
 
-#ifdef COREGL_TRACE_STATE_INFO
+#ifdef COREGL_FASTPATH_TRACE_STATE_INFO
        if (unlikely(trace_state_flag == 1))
                fastpath_dump_context_states(newctx, 0);
-#endif // COREGL_TRACE_STATE_INFO
+#endif // COREGL_FASTPATH_TRACE_STATE_INFO
        return;
 #undef STATE_COMPARE
 #undef STATES_COMPARE
index 7c45eba..09f9d9c 100644 (file)
@@ -210,9 +210,9 @@ extern void                fastpath_apply_overrides_gl(int enable);
 extern int                 fastpath_init_context_states(GLGlueContext *ctx);
 extern void                fastpath_make_context_current(GLGlueContext *oldctx, GLGlueContext *newctx);
 
-#ifdef COREGL_TRACE_STATE_INFO
+#ifdef COREGL_FASTPATH_TRACE_STATE_INFO
 extern void                fastpath_dump_context_states(GLGlueContext *ctx, int force_output);
-#endif
+#endif // COREGL_FASTPATH_TRACE_STATE_INFO
 
 // Context state functions
 extern int                 fastpath_add_context_state_to_list(const void *data, const int datalen, GLContextState *cstate, Mutex *mtx);
index e1fb75a..ed09df7 100644 (file)
@@ -19,6 +19,7 @@ struct _Trace_Data
        int                          call_count;
        int                          last_call_count;
        struct timeval              elapsed_time;
+       struct timeval              elapsed_time_max;
        struct timeval              last_elapsed_time;
        struct timeval              total_elapsed_time;
        struct timeval              last_total_elapsed_time;
@@ -451,6 +452,12 @@ tracepath_api_trace_end(const char *funcname, void *hint, int trace_total_time)
 
                _add_timeval(&ftd->elapsed_time, elapsed_time);
 
+               if (elapsed_time.tv_sec >= ftd->elapsed_time_max.tv_sec &&
+                       elapsed_time.tv_usec > ftd->elapsed_time_max.tv_usec)
+               {
+                       ftd->elapsed_time_max.tv_sec = elapsed_time.tv_sec;
+                       ftd->elapsed_time_max.tv_usec = elapsed_time.tv_usec;
+               }
 
                ftd->last_time.tv_sec = 0;
 
@@ -572,6 +579,7 @@ tracepath_api_trace_output(int force_output)
                                if (current->call_count > current->last_call_count)
                                {
                                        double elapsed_time_period = _get_timeval_period(current->elapsed_time, current->last_elapsed_time);
+                                       double elapsed_time_max = _get_timeval(current->elapsed_time_max);
                                        double elapsed_time_per_call_period = elapsed_time_period / (current->call_count - current->last_call_count);
                                        char *fname = current->name;
 
@@ -580,8 +588,8 @@ tracepath_api_trace_output(int force_output)
 
                                        if (elapsed_time_per_call_period >= 0.01 || current->call_count - current->last_call_count > 1000)
                                        {
-                                               TRACE("\E[40;37;1m %-42.42s : %10d call(s), %10.2f ms, %9.3f ms/API, %9.3f ms/API(P) \E[0m\n",
-                                                     fname, current->call_count, elapsed_time, elapsed_time_per_call, elapsed_time_per_call_period);
+                                               TRACE("\E[40;37;1m %-39.39s : %10d call(s), %9.3f ms/API, %9.2f ms(MAX), %9.3f ms/API(P)\E[0m\n",
+                                                     fname, current->call_count, elapsed_time_per_call, elapsed_time_max, elapsed_time_per_call_period);
                                                current->traced = 1;
                                        }
                                }
@@ -608,13 +616,14 @@ tracepath_api_trace_output(int force_output)
                                                {
                                                        double elapsed_time = _get_timeval(current->elapsed_time);
                                                        double elapsed_time_per_call = elapsed_time / current->call_count;
+                                                       double elapsed_time_max = _get_timeval(current->elapsed_time_max);
                                                        char *fname = current->name;
 
                                                        if (!strncmp(fname, "tracepath_", 10))
                                                                fname = &current->name[10];
 
-                                                       TRACE(" %-42.42s : %10d call(s), %10.2f ms, %9.3f ms/API\n",
-                                                             fname, current->call_count, elapsed_time, elapsed_time_per_call);
+                                                       TRACE(" %-39.39s : %10d call(s), %9.3f ms/API, %9.2f ms(MAX)\n",
+                                                             fname, current->call_count, elapsed_time_per_call, elapsed_time_max);
                                                }
                                                current = current->next;
                                        }
@@ -625,7 +634,7 @@ tracepath_api_trace_output(int force_output)
 
        TRACE("\E[40;34m========================================================================================================================\E[0m\n");
 
-       TRACE("\E[40;36;1m %-42.42s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\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,
@@ -633,21 +642,21 @@ tracepath_api_trace_output(int force_output)
              100.0);
 
 
-       TRACE("\E[40;36;1m %-42.42s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
+       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 %-42.42s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
+       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 %-42.42s : %13.2f ms[%6.2f%%], %13.2f ms(P)[%6.2f%%]\E[0m\n",
+       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,
index bd7d478..2482d21 100644 (file)
@@ -333,13 +333,13 @@ tracepath_eglMakeCurrent(EGLDisplay dpy, EGLSurface draw, EGLSurface read, EGLCo
 
 finish:
        _COREGL_TRACEPATH_FUNC_END();
-#ifdef COREGL_TRACE_STATE_INFO
+#ifdef COREGL_TRACEPATH_TRACE_STATE_INFO
        if (unlikely(trace_state_flag == 1))
        {
                if (_orig_tracepath_eglMakeCurrent == _sym_eglMakeCurrent)
                        tracepath_dump_context_states(0);
        }
-#endif // COREGL_TRACE_STATE_INFO
+#endif // COREGL_TRACEPATH_TRACE_STATE_INFO
        return ret;
 }