print time for debugging init time

Change-Id: Id67f9fbbc90074e5163872b6ce699b3911d10e59

diff --git a/src/tdm.c b/src/tdm.c
index e4a3b7ca0f365f3d91561545bb14285b14a3a05d..74ebcb2ce1db672df5d6990684b13f87bb05f2c8 100644 (file)
--- a/src/tdm.c
+++ b/src/tdm.c
@@ -292,13 +292,17 @@ _tdm_display_update_caps_output(tdm_private_display *private_display, int pipe,
        tdm_func_output *func_output = &private_display->func_output;
        char temp[TDM_NAME_LEN];
        tdm_error ret;
+       double stamp;
 
        if (!func_output->output_get_capability) {
                TDM_ERR("no output_get_capability()");
                return TDM_ERROR_BAD_MODULE;
        }
 
+       stamp = tdm_helper_get_time();
        ret = func_output->output_get_capability(output_backend, caps);
+       TDM_DBG("backend output_get_capability() time: %.3f ms", (tdm_helper_get_time() - stamp) * 1000.0);
+
        if (ret != TDM_ERROR_NONE) {
                TDM_ERR("output_get_capability() failed");
                return TDM_ERROR_BAD_MODULE;
@@ -740,9 +744,11 @@ _tdm_display_load_module_with_file(tdm_private_display *private_display,
        tdm_backend_module *module_data;
        void *module;
        tdm_error ret;
+       double stamp;
 
        snprintf(path, sizeof(path), TDM_MODULE_PATH "/%s", file);
 
+       stamp = tdm_helper_get_time();
        TDM_TRACE_BEGIN(Load_Backend);
 
        module = dlopen(path, RTLD_LAZY);
@@ -760,6 +766,8 @@ _tdm_display_load_module_with_file(tdm_private_display *private_display,
                goto failed_load;
        }
 
+       TDM_DBG("dlopen, dlsym time: %.3f ms", (tdm_helper_get_time() - stamp) * 1000.0);
+
        private_display->module_data = module_data;
        private_display->module = module;
 
@@ -772,8 +780,11 @@ _tdm_display_load_module_with_file(tdm_private_display *private_display,
 
        /* We don't care if backend_data is NULL or not. It's up to backend. */
        TDM_TRACE_BEGIN(Init_Backend);
+       stamp = tdm_helper_get_time();
        private_display->bdata = module_data->init((tdm_display *)private_display, &ret);
+       TDM_DBG("backend init() time: %.3f ms", (tdm_helper_get_time() - stamp) * 1000.0);
        TDM_TRACE_END();
+
        if (ret != TDM_ERROR_NONE) {
                TDM_ERR("failed to init '%s' module", module_data->name);
                goto failed_load;
@@ -851,7 +862,7 @@ tdm_display_init(tdm_error *error)
        tdm_private_display *private_display = NULL;
        const char *debug;
        tdm_error ret;
-       double start;
+       double stamp1, stamp2, start;
 
        _pthread_mutex_lock(&gLock);
 
@@ -863,7 +874,7 @@ tdm_display_init(tdm_error *error)
                return g_private_display;
        }
 
-       start = tdm_helper_get_time();
+       start = stamp1 = tdm_helper_get_time();
 
        private_display = calloc(1, sizeof(tdm_private_display));
        if (!private_display) {
@@ -892,14 +903,26 @@ tdm_display_init(tdm_error *error)
 
        _pthread_mutex_lock(&private_display->lock);
 
+       stamp2 = tdm_helper_get_time();
+       TDM_DBG("prepare init time: %.3f ms", (stamp2 - stamp1) * 1000.0);
+       stamp1 = stamp2;
+
        ret = tdm_event_loop_init(private_display);
        if (ret != TDM_ERROR_NONE)
                goto failed_event;
 
+       stamp2 = tdm_helper_get_time();
+       TDM_DBG("creating event loop time: %.3f ms", (stamp2 - stamp1) * 1000.0);
+       stamp1 = stamp2;
+
        ret = _tdm_display_load_module(private_display);
        if (ret != TDM_ERROR_NONE)
                goto failed_load;
 
+       stamp2 = tdm_helper_get_time();
+       TDM_DBG("loading backend time: %.3f ms", (stamp2 - stamp1) * 1000.0);
+       stamp1 = stamp2;
+
 #ifdef INIT_BUFMGR
        int tdm_drm_fd = tdm_helper_get_fd("TDM_DRM_MASTER_FD");
        if (tdm_drm_fd >= 0) {
@@ -911,6 +934,10 @@ tdm_display_init(tdm_error *error)
                } else {
                        TDM_INFO("tbm_bufmgr_init successed");
                }
+
+               stamp2 = tdm_helper_get_time();
+               TDM_DBG("initializing bufmgr time: %.3f ms", (stamp2 - stamp1) * 1000.0);
+               stamp1 = stamp2;
        }
 #endif
 
@@ -920,6 +947,10 @@ tdm_display_init(tdm_error *error)
        if (ret != TDM_ERROR_NONE)
                goto failed_update;
 
+       stamp2 = tdm_helper_get_time();
+       TDM_DBG("updating display time: %.3f ms", (stamp2 - stamp1) * 1000.0);
+       stamp1 = stamp2;
+
        tdm_event_loop_create_backend_source(private_display);
 
        private_display->init_count = 1;