[pulseaudio-discuss] [PATCH 2/2] Log feature: optimize log data format before writing to target

Becker, VincentX vincentx.becker at intel.com
Tue Mar 8 08:38:43 PST 2011


>-----Original Message-----
>From: pulseaudio-discuss-bounces at mail.0pointer.de [mailto:pulseaudio-
>discuss-bounces at mail.0pointer.de] On Behalf Of Vincent Becker
>Sent: Tuesday, March 08, 2011 5:15 PM
>To: pulseaudio-discuss at mail.0pointer.de
>Subject: [pulseaudio-discuss] [PATCH 2/2] Log feature: optimize log data
>format before writing to target
>

Note that this patch would need to be discussed on the list. Its main purpose is to avoid multiple calls to write, which can be the case when writing to a file descriptor. Indeed, the patch applied before did 2 calls to write as the metadata needed to be formatted in a new buffer and written apart of the text log message. Making only 1 call to write instead of 2 can be precious in embedded environments. It was easier and clearer to apply this change to all the log targets : 'char *t' now contains in order 'metadata - text - append_data' (append_data is not used in every case though). It also has the advantage to clarify a bit which data in which case is logged..

Vincent


>Format data appended and prepended to the log message so that only one
>call to write is necessary
>
>Signed-off-by: Vincent Becker <vincentx.becker at intel.com>
>---
> src/pulsecore/log.c |  160 ++++++++++++++++++++++++++++++--------------
>-------
> 1 files changed, 95 insertions(+), 65 deletions(-)
>
>diff --git a/src/pulsecore/log.c b/src/pulsecore/log.c
>index a5e26c8..abb9066 100644
>--- a/src/pulsecore/log.c
>+++ b/src/pulsecore/log.c
>@@ -277,10 +277,12 @@ void pa_log_levelv_meta(
>     pa_log_level_t _maximum_level;
>     unsigned _show_backtrace;
>     pa_log_flags_t _flags;
>+    char *local_t;
>+    int metadata_length;
>
>     /* We don't use dynamic memory allocation here to minimize the hit
>      * in RT threads */
>-    char text[16*1024], location[128], timestamp[32];
>+    char text[16*1024], location[128], timestamp[32], metadata[256],
>append_data[256];
>
>     pa_assert(level < PA_LOG_LEVEL_MAX);
>     pa_assert(format);
>@@ -297,8 +299,6 @@ void pa_log_levelv_meta(
>         return;
>     }
>
>-    pa_vsnprintf(text, sizeof(text), format, ap);
>-
>     if ((_flags & PA_LOG_PRINT_META) && file && line > 0 && func)
>         pa_snprintf(location, sizeof(location), "[%s:%i %s()] ", file,
>line, func);
>     else if ((_flags & (PA_LOG_PRINT_META|PA_LOG_PRINT_FILE)) && file)
>@@ -338,90 +338,120 @@ void pa_log_levelv_meta(
>         bt = get_backtrace(_show_backtrace);
> #endif
>
>-    if (!pa_utf8_valid(text))
>+    switch (_target) {
>+
>+    case PA_LOG_STDERR: {
>+        const char *prefix = "", *suffix = "", *grey = "";
>+
>+#ifndef OS_IS_WIN32
>+	/* Yes indeed. Useless, but fun! */
>+	if ((_flags & PA_LOG_COLORS) && isatty(STDERR_FILENO)) {
>+	    if (level <= PA_LOG_ERROR)
>+	        prefix = "\x1B[1;31m";
>+	    else if (level <= PA_LOG_WARN)
>+	        prefix = "\x1B[1m";
>+
>+	    if (bt)
>+	        grey = "\x1B[2m";
>+
>+	    if (grey[0] || prefix[0])
>+	        suffix = "\x1B[0m";
>+	}
>+#endif
>+        if (_flags & PA_LOG_PRINT_LEVEL)
>+            pa_snprintf(metadata, sizeof(metadata), "%s%c: %s%s",
>timestamp, level_to_char[level], location, prefix);
>+	else
>+            pa_snprintf(metadata, sizeof(metadata), "%s%s%s",
>timestamp, location, prefix);
>+
>+	pa_snprintf(append_data, sizeof(append_data), "%s%s%s", grey,
>pa_strempty(bt), suffix);
>+
>+	break;
>+    }
>+
>+#ifdef HAVE_SYSLOG_H
>+    case PA_LOG_SYSLOG: {
>+        pa_snprintf(metadata, sizeof(metadata), "%s%s", timestamp,
>location);
>+	pa_snprintf(append_data, sizeof(append_data) ,"%s",
>pa_strempty(bt));
>+
>+        break;
>+    }
>+#endif
>+
>+    case PA_LOG_FD: {
>+	pa_snprintf(metadata, sizeof(metadata), "\n%c %s%s",
>level_to_char[level], timestamp, location);
>+
>+        append_data[0] = 0;
>+
>+        break;
>+    }
>+
>+    default:
>+        metadata[0] = 0;
>+	append_data[0] = 0;
>+
>+        break;
>+    }
>+
>+    metadata_length = strlen(metadata);
>+
>+    /* Format text at metadata_length position */
>+    pa_vsnprintf(&text[metadata_length], sizeof(text) -
>metadata_length, format, ap);
>+
>+    if (!pa_utf8_valid(&text[metadata_length]))
>         pa_logl(level, "Invalid UTF-8 string following below:");
>
>-    for (t = text; t; t = n) {
>-        if ((n = strchr(t, '\n'))) {
>-            *n = 0;
>-            n++;
>-        }
>+    /* We shouldn't be using dynamic allocation here to
>+     * minimize the hit in RT threads */
>+    if ((local_t = pa_utf8_to_locale(&text[metadata_length]))) {
>+	strcpy(&text[metadata_length], local_t);
>+	pa_xfree(local_t);
>+    }
>+
>+    for (t = &text[metadata_length]; t; t = n) {
>+	if ((n = strchr(t, '\n'))) {
>+	    *n = 0;
>+	    n++;
>+	}
>
>         /* We ignore strings only made out of whitespace */
>         if (t[strspn(t, "\t ")] == 0)
>             continue;
>
>-        switch (_target) {
>+	/* Rewind to the start of the t buffer */
>+	t -= metadata_length;
>
>-            case PA_LOG_STDERR: {
>-                const char *prefix = "", *suffix = "", *grey = "";
>-                char *local_t;
>+	/* Prepend metadata into t */
>+	memcpy(t, metadata, metadata_length);
>
>-#ifndef OS_IS_WIN32
>-                /* Yes indeed. Useless, but fun! */
>-                if ((_flags & PA_LOG_COLORS) && isatty(STDERR_FILENO))
>{
>-                    if (level <= PA_LOG_ERROR)
>-                        prefix = "\x1B[1;31m";
>-                    else if (level <= PA_LOG_WARN)
>-                        prefix = "\x1B[1m";
>-
>-                    if (bt)
>-                        grey = "\x1B[2m";
>-
>-                    if (grey[0] || prefix[0])
>-                        suffix = "\x1B[0m";
>-                }
>-#endif
>-
>-                /* We shouldn't be using dynamic allocation here to
>-                 * minimize the hit in RT threads */
>-                if ((local_t = pa_utf8_to_locale(t)))
>-                    t = local_t;
>-
>-                if (_flags & PA_LOG_PRINT_LEVEL)
>-                    fprintf(stderr, "%s%c: %s%s%s%s%s%s\n", timestamp,
>level_to_char[level], location, prefix, t, grey, pa_strempty(bt),
>suffix);
>-                else
>-                    fprintf(stderr, "%s%s%s%s%s%s%s\n", timestamp,
>location, prefix, t, grey, pa_strempty(bt), suffix);
>-#ifdef OS_IS_WIN32
>-                fflush(stderr);
>-#endif
>+        switch (_target) {
>
>-                pa_xfree(local_t);
>+            case PA_LOG_STDERR: {
>+		fprintf(stderr, "%s%s\n", t, append_data);
>
>-                break;
>+		break;
>             }
>
> #ifdef HAVE_SYSLOG_H
>             case PA_LOG_SYSLOG: {
>-                char *local_t;
>-
>                 openlog(ident, LOG_PID, LOG_USER);
>
>-                if ((local_t = pa_utf8_to_locale(t)))
>-                    t = local_t;
>-
>-                syslog(level_to_syslog[level], "%s%s%s%s", timestamp,
>location, t, pa_strempty(bt));
>-                pa_xfree(local_t);
>+                syslog(level_to_syslog[level], "%s%s", t, append_data);
>
>                 break;
>             }
> #endif
>
>-            case PA_LOG_FD: {
>-                if (fdlog != -1) {
>-                    char metadata[256];
>-
>-                    pa_snprintf(metadata, sizeof(metadata), "\n%c
>%s%s", level_to_char[level], timestamp, location);
>-
>-                    if ((write(fdlog, metadata, strlen(metadata)) < 0)
>|| (write(fdlog, t, strlen(t)) < 0)) {
>-                        saved_errno = errno;
>-                        pa_close(fdlog);
>-                        fdlog = -1;
>-                    }
>-                }
>-
>-                break;
>-            }
>+	    case PA_LOG_FD: {
>+		if (fdlog != -1) {
>+		    if (write(fdlog, t, strlen(t)) < 0) {
>+			saved_errno = errno;
>+			pa_close(fdlog);
>+			fdlog = -1;
>+		    }
>+		}
>+
>+		break;
>+	    }
>
>             case PA_LOG_NULL:
>             default:
>--
>1.7.2.3
>
>---------------------------------------------------------------------
>Intel Corporation SAS (French simplified joint stock company)
>Registered headquarters: "Les Montalets"- 2, rue de Paris,
>92196 Meudon Cedex, France
>Registration Number:  302 456 199 R.C.S. NANTERRE
>Capital: 4,572,000 Euros
>
>This e-mail and any attachments may contain confidential material for
>the sole use of the intended recipient(s). Any review or distribution
>by others is strictly prohibited. If you are not the intended
>recipient, please contact the sender and delete all copies.
>
>_______________________________________________
>pulseaudio-discuss mailing list
>pulseaudio-discuss at mail.0pointer.de
>https://tango.0pointer.de/mailman/listinfo/pulseaudio-discuss
---------------------------------------------------------------------
Intel Corporation SAS (French simplified joint stock company)
Registered headquarters: "Les Montalets"- 2, rue de Paris, 
92196 Meudon Cedex, France
Registration Number:  302 456 199 R.C.S. NANTERRE
Capital: 4,572,000 Euros

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.




More information about the pulseaudio-discuss mailing list