[weston,v5,10/14] compositor: protocol logger

Submitted by Ucan, Emre (ADITG/ESB) on July 30, 2018, 9:17 a.m.

Details

Message ID AF835182DB40564F805CF05008AAFCA168F51975@HI2EXCH01.adit-jv.com
State Superseded
Headers show
Series "weston-debug API and tool" ( rev: 2 ) in Wayland

Not browsing as part of any series.

Commit Message

Ucan, Emre (ADITG/ESB) July 30, 2018, 9:17 a.m.
Hi Daniel,

We found an issue with this patch. I am adding a patch to this email to fix this issue. Please check:

Subject: [PATCH] main: copy va_list for second use

we are using va_list once for debug protocol and
once for local logging to stdout. After first use
the list is invalidated. Therefore, we have to copy
it for the second use.

Signed-off-by: Emre Ucan <eucan@de.adit-jv.com>

---
 compositor/main.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

-- 
2.7.4
> -----Original Message-----

> From: wayland-devel [mailto:wayland-devel-

> bounces@lists.freedesktop.org] On Behalf Of Daniel Stone

> Sent: Freitag, 20. Juli 2018 21:07

> To: wayland-devel@lists.freedesktop.org

> Cc: pekka.paalanen@collabora.co.uk; emre.ucan@de.adit-jv.com;

> Maniraj.Devadoss@in.bosch.com

> Subject: [PATCH weston v5 10/14] compositor: protocol logger

> 

> From: Pekka Paalanen <pq@iki.fi>

> 

> This is better than running Weston with WAYLAND_DEBUG=server:

> - It is enabled on demand, no unnecessary flooding and no need to

>   restart the compositor if debug was enabled.

> - It prints client pointers so that messages with different clients can

>   be seen apart.

> 

> Signed-off-by: Pekka Paalanen <pq@iki.fi>

> 

> parse and print message arguments in protocol_log_fn

> 

> Signed-off-by: Maniraj Devadoss <Maniraj.Devadoss@in.bosch.com>

> Reviewed-by: Pekka Paalanen <pekka.paalanen@collabora.co.uk>

> Reviewed-by: Daniel Stone <daniels@collabora.com>

> ---

>  compositor/main.c | 129

> +++++++++++++++++++++++++++++++++++++++++++++-

>  1 file changed, 127 insertions(+), 2 deletions(-)

> 

> diff --git a/compositor/main.c b/compositor/main.c

> index eaf4cf381..3cb791384 100644

> --- a/compositor/main.c

> +++ b/compositor/main.c

> @@ -120,6 +120,7 @@ struct wet_compositor {

> 

>  static FILE *weston_logfile = NULL;

>  static struct weston_debug_scope *log_scope;

> +static struct weston_debug_scope *protocol_scope;

> 

>  static int cached_tm_mday = -1;

> 

> @@ -214,6 +215,116 @@ vlog_continue(const char *fmt, va_list argp)

>  	return vfprintf(weston_logfile, fmt, argp);

>  }

> 

> +static const char *

> +get_next_argument(const char *signature, char* type)

> +{

> +	for(; *signature; ++signature) {

> +		switch(*signature) {

> +		case 'i':

> +		case 'u':

> +		case 'f':

> +		case 's':

> +		case 'o':

> +		case 'n':

> +		case 'a':

> +		case 'h':

> +			*type = *signature;

> +			return signature + 1;

> +		}

> +	}

> +	*type = '\0';

> +	return signature;

> +}

> +

> +static void

> +protocol_log_fn(void *user_data,

> +		enum wl_protocol_logger_type direction,

> +		const struct wl_protocol_logger_message *message)

> +{

> +	FILE *fp;

> +	char *logstr;

> +	size_t logsize;

> +	char timestr[128];

> +	struct wl_resource *res = message->resource;

> +	const char *signature = message->message->signature;

> +	int i;

> +	char type;

> +

> +	if (!weston_debug_scope_is_enabled(protocol_scope))

> +		return;

> +

> +	fp = open_memstream(&logstr, &logsize);

> +	if (!fp)

> +		return;

> +

> +	weston_debug_scope_timestamp(protocol_scope,

> +			timestr, sizeof timestr);

> +	fprintf(fp, "%s ", timestr);

> +	fprintf(fp, "client %p %s ", wl_resource_get_client(res),

> +		direction == WL_PROTOCOL_LOGGER_REQUEST ? "rq" :

> "ev");

> +	fprintf(fp, "%s@%u.%s(",

> +		wl_resource_get_class(res),

> +		wl_resource_get_id(res),

> +		message->message->name);

> +

> +	for (i = 0; i < message->arguments_count; i++) {

> +		signature = get_next_argument(signature, &type);

> +

> +		if (i > 0)

> +			fprintf(fp, ", ");

> +

> +		switch (type) {

> +		case 'u':

> +			fprintf(fp, "%u", message->arguments[i].u);

> +			break;

> +		case 'i':

> +			fprintf(fp, "%d", message->arguments[i].i);

> +			break;

> +		case 'f':

> +			fprintf(fp, "%f",

> +				wl_fixed_to_double(message-

> >arguments[i].f));

> +			break;

> +		case 's':

> +			fprintf(fp, "\"%s\"", message->arguments[i].s);

> +			break;

> +		case 'o':

> +			if (message->arguments[i].o) {

> +				struct wl_resource* resource;

> +				resource = (struct wl_resource*) message-

> >arguments[i].o;

> +				fprintf(fp, "%s@%u",

> +					wl_resource_get_class(resource),

> +					wl_resource_get_id(resource));

> +			}

> +			else

> +				fprintf(fp, "nil");

> +			break;

> +		case 'n':

> +			fprintf(fp, "new id %s@",

> +				(message->message->types[i]) ?

> +				message->message->types[i]->name :

> +				"[unknown]");

> +			if (message->arguments[i].n != 0)

> +				fprintf(fp, "%u", message->arguments[i].n);

> +			else

> +				fprintf(fp, "nil");

> +			break;

> +		case 'a':

> +			fprintf(fp, "array");

> +			break;

> +		case 'h':

> +			fprintf(fp, "fd %d", message->arguments[i].h);

> +			break;

> +		}

> +	}

> +

> +	fprintf(fp, ")\n");

> +

> +	if (fclose(fp) == 0)

> +		weston_debug_scope_write(protocol_scope, logstr,

> logsize);

> +

> +	free(logstr);

> +}

> +

>  static struct wl_list child_process_list;

>  static struct weston_compositor *segv_compositor;

> 

> @@ -2406,6 +2517,7 @@ int main(int argc, char *argv[])

>  	struct wet_compositor wet = { 0 };

>  	int require_input;

>  	int32_t wait_for_debugger = 0;

> +	struct wl_protocol_logger *protologger = NULL;

> 

>  	const struct weston_option core_options[] = {

>  		{ WESTON_OPTION_STRING, "backend", 'B', &backend },

> @@ -2510,9 +2622,18 @@ int main(int argc, char *argv[])

> 

>  	log_scope =

> weston_compositor_add_debug_scope(wet.compositor, "log",

>  			"Weston and Wayland log\n", NULL, NULL);

> -

> -	if (debug_protocol)

> +	protocol_scope =

> +		weston_compositor_add_debug_scope(wet.compositor,

> +			"proto",

> +			"Wayland protocol dump for all clients.\n",

> +			NULL, NULL);

> +

> +	if (debug_protocol) {

> +		protologger = wl_display_add_protocol_logger(display,

> +							     protocol_log_fn,

> +							     NULL);

> 

> 	weston_compositor_enable_debug_protocol(wet.compositor);

> +	}

> 

>  	if (weston_compositor_init_config(wet.compositor, config) < 0)

>  		goto out;

> @@ -2623,6 +2744,10 @@ out:

>  	/* free(NULL) is valid, and it won't be NULL if it's used */

>  	free(wet.parsed_options);

> 

> +	if (protologger)

> +		wl_protocol_logger_destroy(protologger);

> +

> +	weston_debug_scope_destroy(protocol_scope);

>  	weston_debug_scope_destroy(log_scope);

>  	weston_compositor_destroy(wet.compositor);

> 

> --

> 2.17.1

> 

> _______________________________________________

> wayland-devel mailing list

> wayland-devel@lists.freedesktop.org

> https://lists.freedesktop.org/mailman/listinfo/wayland-devel

Patch hide | download patch | download mbox

diff --git a/compositor/main.c b/compositor/main.c
index 3333147..7975af0 100644
--- a/compositor/main.c
+++ b/compositor/main.c
@@ -193,6 +193,9 @@  vlog(const char *fmt, va_list ap)
 {
 	int l;
 	char timestr[128];
+	va_list ap2;
+
+	va_copy(ap2, ap);
 
 	if (weston_debug_scope_is_enabled(log_scope)) {
 		weston_debug_scope_printf(log_scope, "%s ",
@@ -202,7 +205,8 @@  vlog(const char *fmt, va_list ap)
 	}
 
 	l = weston_log_timestamp();
-	l += vfprintf(weston_logfile, fmt, ap);
+	l += vfprintf(weston_logfile, fmt, ap2);
+	va_end(ap2);
 
 	return l;
 }

Comments

On Mon, 30 Jul 2018 09:17:27 +0000
"Ucan, Emre (ADITG/ESB)" <eucan@de.adit-jv.com> wrote:

> Hi Daniel,
> 
> We found an issue with this patch. I am adding a patch to this email to fix this issue. Please check:
> 
> Subject: [PATCH] main: copy va_list for second use
> 
> we are using va_list once for debug protocol and
> once for local logging to stdout. After first use
> the list is invalidated. Therefore, we have to copy
> it for the second use.
> 
> Signed-off-by: Emre Ucan <eucan@de.adit-jv.com>
> ---
>  compositor/main.c | 6 +++++-
>  1 file changed, 5 insertions(+), 1 deletion(-)
> 
> diff --git a/compositor/main.c b/compositor/main.c
> index 3333147..7975af0 100644
> --- a/compositor/main.c
> +++ b/compositor/main.c
> @@ -193,6 +193,9 @@ vlog(const char *fmt, va_list ap)
>  {
>  	int l;
>  	char timestr[128];
> +	va_list ap2;
> +
> +	va_copy(ap2, ap);
>  
>  	if (weston_debug_scope_is_enabled(log_scope)) {
>  		weston_debug_scope_printf(log_scope, "%s ",
> @@ -202,7 +205,8 @@ vlog(const char *fmt, va_list ap)
>  	}
>  
>  	l = weston_log_timestamp();
> -	l += vfprintf(weston_logfile, fmt, ap);
> +	l += vfprintf(weston_logfile, fmt, ap2);
> +	va_end(ap2);
>  
>  	return l;
>  }

Hi Emre,

nice, I wonder if this was the thing causing those crashes that IIRC
Maniraj was seeing and worked around them by having
weston_debug_scope_timestamp() return void.

Reading the manual, you are correct and this is needed.

Squashing this into the appropriate commit (patch 6) retains:
Reviewed-by: Pekka Paalanen <pekka.paalanen@collabora.co.uk>

custom_handler() and vlog_continue() seem to need the same fix.


Thanks,
pq