weston: Weston Log Mechanism Development [1/1]

PD#SWPL-198933

Problem:
Weston Log Mechanism Development.

Solution:
Weston Log Mechanism Development.

Verify:
s7d

Change-Id: I1c7e83ed981a1b1077947b9c9a83635f8255920b
Signed-off-by: limin.tian <limin.tian@amlogic.com>
diff --git a/libweston/backend-drm/drm.c b/libweston/backend-drm/drm.c
index 2f4729b..a98de08 100644
--- a/libweston/backend-drm/drm.c
+++ b/libweston/backend-drm/drm.c
@@ -67,6 +67,7 @@
 #include "linux-explicit-synchronization.h"
 
 #include "aml-weston/aml-backend.h"
+#include "aml-weston/aml-util.h"
 
 static const char default_seat[] = "seat0";
 
@@ -548,7 +549,7 @@
 		.request.signal = 0,
 	};
 
-	weston_log("disable_pending:%d destroy_pending:%d fb%p state_invalid:%d hdmitx_hdcppwr:%d display_enable:%d\n",
+	WESTON_LOGT(COMMON_LOG, "disable_pending:%d destroy_pending:%d fb%p state_invalid:%d hdmitx_hdcppwr:%d display_enable:%d\n",
 		 output->disable_pending, output->destroy_pending, scanout_plane->state_cur->fb,
 		backend->state_invalid, backend->hdmitx_hdcppwr, backend->display_enable);
 
@@ -556,7 +557,7 @@
 		return 0;
 
 	if (!backend->display_enable) {
-		weston_log("\n :%s %d hdmitx_hdcppwr:%d display_enable:%d REPAINT_NOT_SCHEDULED\n",__FUNCTION__,__LINE__,
+		WESTON_LOGI(COMMON_LOG, "\n :%s %d hdmitx_hdcppwr:%d display_enable:%d REPAINT_NOT_SCHEDULED\n",__FUNCTION__,__LINE__,
 			backend->hdmitx_hdcppwr, backend->display_enable);
 		output_base->repaint_status = REPAINT_NOT_SCHEDULED;
 		return 0;
diff --git a/libweston/backend-drm/fb.c b/libweston/backend-drm/fb.c
index 0f63119..5dfff98 100644
--- a/libweston/backend-drm/fb.c
+++ b/libweston/backend-drm/fb.c
@@ -219,8 +219,10 @@
 {
 	/* We deliberately do not close the GEM handles here; GBM manages
 	 * their lifetime through the BO. */
-	if (fb->bo)
+	if (fb->bo) {
+		WESTON_LOGD(COMMON_LOG, "fb:%p,fb->bo:%p\n", fb, fb->bo);
 		gbm_bo_destroy(fb->bo);
+	}
 	drm_fb_destroy(fb);
 }
 
@@ -286,6 +288,8 @@
 			       &import_mod, GBM_BO_USE_SCANOUT);
 	if (!fb->bo)
 		goto err_free;
+	WESTON_LOGD(COMMON_LOG, "fb:%p,fb->bo:%p,fd(%d %d)\n",
+		fb, fb->bo, dmabuf->attributes.fd[0], dmabuf->attributes.fd[1]);
 
 	fb->width = dmabuf->attributes.width;
 	fb->height = dmabuf->attributes.height;
diff --git a/libweston/backend-drm/kms.c b/libweston/backend-drm/kms.c
index bb563c0..53863c7 100644
--- a/libweston/backend-drm/kms.c
+++ b/libweston/backend-drm/kms.c
@@ -807,6 +807,10 @@
 		  (unsigned long) crtc->crtc_id,
 		  (unsigned long) info->prop_id, info->name,
 		  (unsigned long long) val, (unsigned long long) val);
+	WESTON_LOGT(COMMON_LOG, "[CRTC:%lu] %lu (%s) -> %llu (0x%llx)\n",
+		  (unsigned long) crtc->crtc_id,
+		  (unsigned long) info->prop_id, info->name,
+		  (unsigned long long) val, (unsigned long long) val);
 	return (ret <= 0) ? -1 : 0;
 }
 
@@ -826,6 +830,11 @@
 		  (unsigned long) connector_id,
 		  (unsigned long) info->prop_id, info->name,
 		  (unsigned long long) val, (unsigned long long) val);
+	WESTON_LOGT(COMMON_LOG, "[CONN:%lu] %lu (%s) -> %llu (0x%llx)\n",
+		  (unsigned long) connector_id,
+		  (unsigned long) info->prop_id, info->name,
+		  (unsigned long long) val, (unsigned long long) val);
+
 	return (ret <= 0) ? -1 : 0;
 }
 
@@ -845,6 +854,10 @@
 		  (unsigned long) plane->plane_id,
 		  (unsigned long) info->prop_id, info->name,
 		  (unsigned long long) val, (unsigned long long) val);
+	WESTON_LOGT(COMMON_LOG, "[PLANE:%lu] %lu (%s) -> %llu (0x%llx)\n",
+		  (unsigned long) plane->plane_id,
+		  (unsigned long) info->prop_id, info->name,
+		  (unsigned long long) val, (unsigned long long) val);
 	return (ret <= 0) ? -1 : 0;
 }
 
@@ -947,6 +960,10 @@
 		  (*flags & DRM_MODE_ATOMIC_TEST_ONLY) ? "testing" : "applying",
 		  (unsigned long) output->base.id, output->base.name);
 
+	WESTON_LOGT(COMMON_LOG, "[atomic] %s output %lu (%s) state\n",
+		  (*flags & DRM_MODE_ATOMIC_TEST_ONLY) ? "testing" : "applying",
+		  (unsigned long) output->base.id, output->base.name);
+
 	if (state->dpms != output->state_cur->dpms) {
 		drm_debug(b, "\t\t\t[atomic] DPMS state differs, modeset OK\n");
 		*flags |= DRM_MODE_ATOMIC_ALLOW_MODESET;
@@ -1125,6 +1142,7 @@
 
 		drm_debug(b, "\t\t[atomic] previous state invalid; "
 			     "starting with fresh state\n");
+		WESTON_LOGI(COMMON_LOG," [atomic] state invalid \n");
 
 		/* If we need to reset all our state (e.g. because we've
 		 * just started, or just been VT-switched in), explicitly
@@ -1205,7 +1223,7 @@
 		if (b->allow_modeset) {
 			flags |= DRM_MODE_ATOMIC_ALLOW_MODESET;
 			mode_changed = true;
-			weston_log("\n allow_modeset:%d\n", b->allow_modeset);
+			weston_log("allow_modeset:%d\n", b->allow_modeset);
 		}
 	}
 
@@ -1229,12 +1247,13 @@
 	if (mode != DRM_STATE_TEST_ONLY &&
 		mode_policy_add_prop(req, mode_changed) > 0) {
 		flags |= DRM_MODE_ATOMIC_ALLOW_MODESET;
-		weston_log("\n add prop, allow_modeset:%d\n", b->allow_modeset);
+		WESTON_LOGI(COMMON_LOG,"add prop, allow_modeset:%d\n", b->allow_modeset);
 	}
 #endif
 
 	ret = drmModeAtomicCommit(b->drm.fd, req, flags, b);
-	drm_debug(b, "[atomic] drmModeAtomicCommit\n");
+	if (mode != DRM_STATE_TEST_ONLY)
+		WESTON_LOGD(COMMON_LOG, "Commit flags %x\n", flags);
 
 	drm_update_buffer_commit_result(ret, pending_state);
 
@@ -1505,13 +1524,13 @@
 
 	weston_compositor_get_time(&ts3);
 	if ( (timespec_to_usec(&ts3) - timespec_to_usec(&ts1)) > 10000 )
-		weston_log("\n %s %d take:(%lld %lld %lld)\n",
+		weston_log("%s %d take:(%lld %lld %lld)\n",
 		__FUNCTION__,__LINE__,
 		(timespec_to_usec(&ts3) - timespec_to_usec(&ts1)),
 		(timespec_to_usec(&ts2) - timespec_to_usec(&ts1)),
 		(timespec_to_usec(&ts3) - timespec_to_usec(&ts2))
 		);
-	atomic_flip_handler_time(b);
+	atomic_flip_handler_time(b, sec, usec);
 }
 
 int
@@ -1533,7 +1552,7 @@
 	drmHandleEvent(fd, &evctx);
 	weston_compositor_get_time(&ts3);
 	if ( (timespec_to_usec(&ts3) - timespec_to_usec(&ts1)) > 10000 )
-			weston_log("\n %s %d  %lld %lld,take:(%lld %lld %lld)\n",
+			weston_log("%s %d  %lld %lld,take:(%lld %lld %lld)\n",
 			__FUNCTION__,__LINE__, timespec_to_usec(&ts1), timespec_to_usec(&ts3),
 			(timespec_to_usec(&ts3) - timespec_to_usec(&ts1)),
 			(timespec_to_usec(&ts2) - timespec_to_usec(&ts1)),
diff --git a/libweston/compositor.c b/libweston/compositor.c
index f011f55..2c87f2d 100644
--- a/libweston/compositor.c
+++ b/libweston/compositor.c
@@ -631,6 +631,7 @@
 	surface->protection_mode = WESTON_SURFACE_PROTECTION_MODE_RELAXED;
 
 	weston_init_video_surface_info(surface);
+	WESTON_LOGI(COMMON_LOG, "%p \n", surface);
 
 	return surface;
 }
@@ -2361,7 +2362,7 @@
 	weston_set_appstate_by_appname(surface->compositor, surface->name, 0);
 	weston_clear_video_surface_info(surface);
 	weston_surface_destroy_info_for_surface(surface);
-	weston_log("\n weston_surface_destroy :%p output:%p name :%s \n", surface, surface->output, surface->name);
+	weston_log("weston_surface_destroy :%p output:%p name :%s \n", surface, surface->output, surface->name);
 
 	free(surface);
 }
@@ -2395,7 +2396,7 @@
 	struct weston_buffer *buffer =
 		container_of(listener, struct weston_buffer, destroy_listener);
 
-	weston_log("\n weston_buffer_destroy_handler buffer:%p\n",buffer);
+	weston_log("weston_buffer_destroy_handler buffer:%p\n",buffer);
 	weston_signal_emit_mutable(&buffer->destroy_signal, buffer);
 	free(buffer);
 }
@@ -2985,12 +2986,7 @@
 	weston_compositor_repick(ec);
 
 	frame_time_msec = timespec_to_msec(&output->frame_time);
-	if (ec->enable_video_debug) {
-		struct timespec time;
-
-		weston_compositor_get_time(&time);
-		weston_log("%llu repaint send done\n", timespec_to_usec(&time));
-	}
+	WESTON_LOGD(COMMON_LOG, "send callback\n");
 	wl_resource_for_each_safe(cb, cnext, &frame_callback_list) {
 		wl_callback_send_done(cb, frame_time_msec);
 		wl_resource_destroy(cb);
@@ -3028,8 +3024,7 @@
 
 	msec_to_repaint = timespec_sub_to_msec(&output->next_repaint, now);
 	if (msec_to_repaint > 1) {
-		if (compositor->enable_video_debug)
-			weston_log("\n %s %d return ret:%d\n", __FUNCTION__,__LINE__,ret);
+		WESTON_LOGD(COMMON_LOG, "msec_to_repaint > 1\n");
 		return ret;
 	}
 
@@ -3037,15 +3032,13 @@
 	 * explicitly repaint all outputs when we come back. */
 	if (compositor->state == WESTON_COMPOSITOR_SLEEPING ||
 		compositor->state == WESTON_COMPOSITOR_OFFSCREEN) {
-		if (compositor->enable_video_debug)
-			weston_log("\n %s %d return ret:%d\n", __FUNCTION__,__LINE__,ret);
+		WESTON_LOGD(COMMON_LOG, "state:%d\n", compositor->state);
 		goto err;
 		}
 	/* We don't actually need to repaint this output; drop it from
 	 * repaint until something causes damage. */
 	if (!output->repaint_needed) {
-		if (compositor->enable_video_debug)
-			weston_log("\n %s %d return ret:%d\n", __FUNCTION__,__LINE__,ret);
+		WESTON_LOGD(COMMON_LOG, "repaint not needed\n");
 		goto err;
 	}
 
@@ -3057,8 +3050,7 @@
 	ret = weston_output_repaint(output, repaint_data);
 	weston_compositor_read_presentation_clock(compositor, now);
 	if (ret != 0) {
-		if (compositor->enable_video_debug)
-			weston_log("\n %s %d return ret:%d\n", __FUNCTION__,__LINE__,ret);
+		WESTON_LOGD(COMMON_LOG, "fail\n");
 		goto err;
 	}
 	output->repainted = true;
@@ -4066,7 +4058,7 @@
 
 	surface->pending.buffer_viewport.buffer.transform = transform;
 	surface->pending.buffer_viewport.changed = 1;
-	weston_log("\n %s %d transform:%d\n", __FUNCTION__,__LINE__,transform);
+	weston_log("%s %d transform:%d\n", __FUNCTION__,__LINE__,transform);
 	surface->video_transform = transform;
 }
 
@@ -4654,7 +4646,7 @@
 
 	if (!sub)
 		return;
-
+	WESTON_LOGI(VIDEO_LOG, "x:%d, y:%d\n", x,y);
 	sub->position.x = x;
 	sub->position.y = y;
 	sub->position.set = 1;
@@ -7333,7 +7325,7 @@
 			"wl_surface for this viewport no longer exists");
 		return;
 	}
-
+	WESTON_LOGI(COMMON_LOG, "w:%d h:%d\n", dst_width, dst_height);
 	assert(surface->viewport_resource == resource);
 
 	if (dst_width == -1 && dst_height == -1) {
diff --git a/libweston/input.c b/libweston/input.c
index 958f685..46b6d62 100644
--- a/libweston/input.c
+++ b/libweston/input.c
@@ -1560,7 +1560,7 @@
 			keyboard->focus != surface ) {
 		enter = true;
 	}
-	weston_log("\n %s %d, enter surface:%p, enter:%d222\n", __FUNCTION__,__LINE__, surface, enter);
+	weston_log("%s %d, enter surface:%p, enter:%d\n", __FUNCTION__,__LINE__, surface, enter);
 	return enter;
 }
 WL_EXPORT void
@@ -1593,7 +1593,7 @@
 			wl_resource_for_each(resource, focus_resource_list) {
 				if (keyboard && keyboard->focus)
 					keyboard->focus->compositor->last_keyboard_focus = keyboard->focus;
-				weston_log("\n %s %d, leave surface:%p\n", __FUNCTION__,__LINE__, keyboard->focus);
+				weston_log(" %s %d, leave surface:%p\n", __FUNCTION__,__LINE__, keyboard->focus);
 				wl_keyboard_send_leave(resource, serial,
 						keyboard->focus->resource);
 			}
@@ -1603,7 +1603,7 @@
 			surface = last_keyboard_focus;
 			if (surface == keyboard->focus)
 				surface = NULL;
-			weston_log("\n %s %d, need	back to  surface:%p\n", __FUNCTION__,__LINE__, surface);
+			weston_log(" %s %d, need	back to  surface:%p\n", __FUNCTION__,__LINE__, surface);
 		}
 
 		if (find_resource_for_surface(&keyboard->resource_list, surface) &&
diff --git a/libweston/linux-dmabuf.c b/libweston/linux-dmabuf.c
index 083f4e7..e964361 100644
--- a/libweston/linux-dmabuf.c
+++ b/libweston/linux-dmabuf.c
@@ -204,6 +204,9 @@
 	buffer->attributes.format = format;
 	buffer->attributes.flags = flags;
 
+	WESTON_LOGD(COMMON_LOG, "dmabuf:%p fd(%d %d) wxh(%dx%d) format:%u", buffer,
+		buffer->attributes.fd[0], buffer->attributes.fd[1], width, height, format);
+
 	if (width < 1 || height < 1) {
 		wl_resource_post_error(params_resource,
 			ZWP_LINUX_BUFFER_PARAMS_V1_ERROR_INVALID_DIMENSIONS,
@@ -233,7 +236,7 @@
 		/* Don't report an error as it might be caused
 		 * by the kernel not supporting seeking on dmabuf */
 		if (buffer->direct_display) {
-			weston_log("\n direct_display. remove parameter check and gpu import \n");
+			weston_log("direct_display. remove parameter check and gpu import \n");
 			goto avoid_gpu_import;
 		}
 
diff --git a/libweston/meson.build b/libweston/meson.build
index ceaf24b..ae783ba 100644
--- a/libweston/meson.build
+++ b/libweston/meson.build
@@ -5,7 +5,8 @@
 	dep_libdl,
 	dep_libdrm,
 	dep_xkbcommon,
-	dep_matrix_c
+	dep_matrix_c,
+	dep_liblog
 ]
 srcs_libweston = [
 	git_version_h,
@@ -40,6 +41,7 @@
 	'../aml-weston/aml_config.c',
 	'../aml-weston/aml-util.c',
 	'../aml-weston/aml-drm-config.c',
+	'../aml-weston/aml-util.c',
 	linux_dmabuf_unstable_v1_protocol_c,
 	linux_dmabuf_unstable_v1_server_protocol_h,
 	linux_explicit_synchronization_unstable_v1_protocol_c,
diff --git a/libweston/renderer-gl/gl-renderer.c b/libweston/renderer-gl/gl-renderer.c
index 062f6e5..079e6d1 100644
--- a/libweston/renderer-gl/gl-renderer.c
+++ b/libweston/renderer-gl/gl-renderer.c
@@ -1783,8 +1783,8 @@
 
 	weston_compositor_get_time(&time);
 	diff = timespec_to_usec(&time) - start;
-	if ( diff > 8000 && compositor->enable_video_debug )
-		weston_log("\n %s %d take:%lld(us)\n", __FUNCTION__, __LINE__, diff);
+	if ( diff > 8000 )
+		WESTON_LOGD(COMMON_LOG, "take %lld(us)\n", diff);
 }
 
 static int