1:23 p.m.
This patch set adds structured syslog support to libvirt.
In short, the idea is to embed JSON in a syslog record. This format
is used in a new log output type called "syslog/json".
Example "syslog/json" record (line-wrapped for readability):
Sep 20 19:59:40 kulicka libvirt: @cee: {"msg":"libvirt version:
0.10.1",
"category":"../../src/test/test_driver.c","priority":"info",
"funcname":"virLogVMessage","line":769,
"timestamp":"2012-09-20 17:59:40.853+0000"}
compared with existing "syslog" record format:
Sep 20 20:02:24 kulicka libvirt: 5896: info : libvirt version: 0.10.1
This JSON embedding format is defined by the Lumberjack project led
by the major Open Source syslog implementations
(https://fedorahosted.org/lumberjack/). The format is also a base
for a future MITRE CEE standard. Some of the fields are specified
at https://fedorahosted.org/lumberjack/wiki/FieldList , but applications
are free to use whatever fields make sense for them.
The JSON structure makes easy to process logs by programs without writing
code that understands the specific format used by each application,
or using unreliable regexps (https://fedorahosted.org/ceelog/ is a
companion project that allows processing such logs).
Current systems will store and these records unmodified and present them
to users unmodified, but tools (and probably /var/log/messages) will
be able to show only the "msg" field; this allows us to add more detailed
information without worsening the user experience (the example above
already shows added information that is currently being thrown away when
logging to syslog).
The patch set, aside from building the required infrastructure, has two
main components:
* Add the "syslog/json" output type, and use it to record all information
passed to virLogMessage. The example result is shown above. This primarily
makes it easier to parse the message.
* Allow callers of virLogMessage to add arbitrary additional JSON fields,
and use it in virRaiseErrorFull and its callers. Because the additional
fields for errors include virErrorDomain and virErrorNumber, this allows
_programs_ to _automatically_ detect the event and react to it, perhaps
alerting the user about a situation that requires immediate attention,
or automatically suggesting a solution.
This has not been possible until now because the current logs contain
only a translated error message, so the log record doesn't contain
anything stable that could be detected by a program.
It is assumed that other parts of libvirt may add more event-specific
JSON fields in the future, based on demand by applications that process
the logs; I have, however, no immediate plans to add more.
Miloslav Trmač (12):
Drop unused return value of virLogOutputFunc
Add JSON API for preallocated objects.
Split yajl_gen allocation into a separate function.
Split adding object properties from virJSONValueToStringOne
Add a JSON generator API.
Pass the "raw" log message to each virLogOutputFunc
Split priority conversion from virLogOutputToSyslog
Add "syslog/json" log output format.
Add a JSON properties parameter to virLog{,V}Message
Add a JSON properties parameter to virLogOutputFunc
Add detailed error information to JSON syslog
Add a test for the new error reporting mechanism.
docs/logging.html.in | 3 +
src/libvirt_private.syms | 4 +
src/uml/uml_conf.c | 2 +-
src/util/json.c | 232 +++++++++++++++++++++++++++++++++++++++++-----
src/util/json.h | 26 ++++++
src/util/logging.c | 233 ++++++++++++++++++++++++++++++++++-------------
src/util/logging.h | 35 +++----
src/util/viraudit.c | 4 +-
src/util/virterror.c | 32 ++++++-
tests/Makefile.am | 6 +-
tests/errorjsontest.c | 211 ++++++++++++++++++++++++++++++++++++++++++
tests/testutils.c | 7 +-
12 files changed, 684 insertions(+), 111 deletions(-)
create mode 100644 tests/errorjsontest.c
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 01/12] Drop unused return value of virLogOutputFunc
Nothing uses the return value, and creating it requries otherwise
unnecessary strlen () calls.
This cleanup is conceptually independent from the rest of the series
(although the later patches won't apply without it). This just seems
a good opportunity to clean this up, instead of entrenching the unnecessary
return value in the virLogOutputFunc instance that will be added in this
series.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 56 +++++++++++++++++++++++++-----------------------------
src/util/logging.h | 14 ++++++--------
tests/testutils.c | 5 ++---
3 files changed, 34 insertions(+), 41 deletions(-)
diff --git a/src/util/logging.c b/src/util/logging.c
index 6048151..537c764 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -98,12 +98,12 @@ static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT;
static int virLogResetFilters(void);
static int virLogResetOutputs(void);
-static int virLogOutputToFd(const char *category, int priority,
- const char *funcname, long long linenr,
- const char *timestamp,
- unsigned int flags,
- const char *str,
- void *data);
+static void virLogOutputToFd(const char *category, int priority,
+ const char *funcname, long long linenr,
+ const char *timestamp,
+ unsigned int flags,
+ const char *str,
+ void *data);
/*
* Logs accesses must be serialized though a mutex
@@ -807,32 +807,29 @@ static void virLogStackTraceToFd(int fd)
#undef STRIP_DEPTH
}
-static int virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
- int priority ATTRIBUTE_UNUSED,
- const char *funcname ATTRIBUTE_UNUSED,
- long long linenr ATTRIBUTE_UNUSED,
- const char *timestamp,
- unsigned int flags,
- const char *str,
- void *data)
+static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
+ int priority ATTRIBUTE_UNUSED,
+ const char *funcname ATTRIBUTE_UNUSED,
+ long long linenr ATTRIBUTE_UNUSED,
+ const char *timestamp,
+ unsigned int flags,
+ const char *str,
+ void *data)
{
int fd = (intptr_t) data;
- int ret;
char *msg;
if (fd < 0)
- return -1;
+ return;
if (virAsprintf(&msg, "%s: %s", timestamp, str) < 0)
- return -1;
+ return;
- ret = safewrite(fd, msg, strlen(msg));
+ ignore_value(safewrite(fd, msg, strlen(msg)));
VIR_FREE(msg);
if (flags & VIR_LOG_STACK_TRACE)
virLogStackTraceToFd(fd);
-
- return ret;
}
static void virLogCloseFd(void *data)
@@ -865,18 +862,18 @@ static int virLogAddOutputToFile(int priority, const char *file) {
}
#if HAVE_SYSLOG_H
-static int virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED,
- int priority,
- const char *funcname ATTRIBUTE_UNUSED,
- long long linenr ATTRIBUTE_UNUSED,
- const char *timestamp ATTRIBUTE_UNUSED,
- unsigned int flags,
- const char *str,
- void *data ATTRIBUTE_UNUSED)
+static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED,
+ int priority,
+ const char *funcname ATTRIBUTE_UNUSED,
+ long long linenr ATTRIBUTE_UNUSED,
+ const char *timestamp ATTRIBUTE_UNUSED,
+ unsigned int flags,
+ const char *str,
+ void *data ATTRIBUTE_UNUSED)
{
int prio;
- virCheckFlags(VIR_LOG_STACK_TRACE, -1);
+ virCheckFlags(VIR_LOG_STACK_TRACE,);
switch (priority) {
case VIR_LOG_DEBUG:
@@ -895,7 +892,6 @@ static int virLogOutputToSyslog(const char *category
ATTRIBUTE_UNUSED,
prio = LOG_ERR;
}
syslog(prio, "%s", str);
- return strlen(str);
}
static char *current_ident = NULL;
diff --git a/src/util/logging.h b/src/util/logging.h
index 137bad2..1c484bb 100644
--- a/src/util/logging.h
+++ b/src/util/logging.h
@@ -94,15 +94,13 @@ typedef enum {
* @data: extra output logging data
*
* Callback function used to output messages
- *
- * Returns the number of bytes written or -1 in case of error
*/
-typedef int (*virLogOutputFunc) (const char *category, int priority,
- const char *funcname, long long linenr,
- const char *timestamp,
- unsigned int flags,
- const char *str,
- void *data);
+typedef void (*virLogOutputFunc) (const char *category, int priority,
+ const char *funcname, long long linenr,
+ const char *timestamp,
+ unsigned int flags,
+ const char *str,
+ void *data);
/**
* virLogCloseFunc:
diff --git a/tests/testutils.c b/tests/testutils.c
index ecd3d2d..5c32f14 100644
--- a/tests/testutils.c
+++ b/tests/testutils.c
@@ -478,7 +478,7 @@ struct virtTestLogData {
static struct virtTestLogData testLog = { VIR_BUFFER_INITIALIZER };
-static int
+static void
virtTestLogOutput(const char *category ATTRIBUTE_UNUSED,
int priority ATTRIBUTE_UNUSED,
const char *funcname ATTRIBUTE_UNUSED,
@@ -489,9 +489,8 @@ virtTestLogOutput(const char *category ATTRIBUTE_UNUSED,
void *data)
{
struct virtTestLogData *log = data;
- virCheckFlags(VIR_LOG_STACK_TRACE, -1);
+ virCheckFlags(VIR_LOG_STACK_TRACE,);
virBufferAsprintf(&log->buf, "%s: %s", timestamp, str);
- return strlen(timestamp) + 2 + strlen(str);
}
static void
--
1.7.11.4
3:39 a.m.
New subject: [libvirt] [PATCH 01/12] Drop unused return value of virLogOutputFunc
On Thu, Sep 20, 2012 at 08:24:00PM +0200, Miloslav Trmač wrote:
Nothing uses the return value, and creating it requries otherwise
unnecessary strlen () calls.
This cleanup is conceptually independent from the rest of the series
(although the later patches won't apply without it). This just seems
a good opportunity to clean this up, instead of entrenching the unnecessary
return value in the virLogOutputFunc instance that will be added in this
series.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 56 +++++++++++++++++++++++++-----------------------------
src/util/logging.h | 14 ++++++--------
tests/testutils.c | 5 ++---
3 files changed, 34 insertions(+), 41 deletions(-)
ACK
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
2:14 p.m.
New subject: [libvirt] [PATCH 01/12] Drop unused return value of virLogOutputFunc
On 09/21/2012 02:39 AM, Daniel P. Berrange wrote:
On Thu, Sep 20, 2012 at 08:24:00PM +0200, Miloslav Trmač wrote:
> Nothing uses the return value, and creating it requries otherwise
> unnecessary strlen () calls.
>
> This cleanup is conceptually independent from the rest of the series
> (although the later patches won't apply without it). This just seems
> a good opportunity to clean this up, instead of entrenching the unnecessary
> return value in the virLogOutputFunc instance that will be added in this
> series.
>
> Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
> ---
> src/util/logging.c | 56 +++++++++++++++++++++++++-----------------------------
> src/util/logging.h | 14 ++++++--------
> tests/testutils.c | 5 ++---
> 3 files changed, 34 insertions(+), 41 deletions(-)
ACK
I've pushed this one. The rest of the series is big enough that it is
probably worth deferring to post-0.10.2 release.
--
Eric Blake eblake(a)redhat.com +1-919-301-3266
Libvirt virtualization library http://libvirt.org
1:24 p.m.
New subject: [libvirt] [PATCH 02/12] Add JSON API for preallocated objects.
Add a JSON API that allows creating a JSON data structure within
variables preallocated on the stack, without allocating memory in the
heap.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/json.c | 82 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++
src/util/json.h | 11 ++++++++
2 files changed, 93 insertions(+)
diff --git a/src/util/json.c b/src/util/json.c
index 0507244..8529b5f 100644
--- a/src/util/json.c
+++ b/src/util/json.c
@@ -23,6 +23,8 @@
#include <config.h>
+#include <stdio.h>
+
#include "json.h"
#include "memory.h"
#include "virterror_internal.h"
@@ -659,6 +661,86 @@ int virJSONValueObjectIsNull(virJSONValuePtr object, const char
*key)
}
+/**
+ * virJSONStaticObjectInitialize:
+ * @object: destination object
+ * @pairs_buf: a buffer for storing property pairs.
+ *
+ * Initialize a pre-allocated object so that virJSONStaticObjectAppend* can
+ * be called on it.
+ *
+ * The caller is responsible for sizing @pairs_buf appropriately, one entry
+ * per virJSONStaticObjectAppend* call.
+ */
+void virJSONStaticObjectInitialize(virJSONObjectPtr object,
+ virJSONObjectPairPtr pairs_buf)
+{
+ object->npairs = 0;
+ object->pairs = pairs_buf;
+}
+
+/**
+ * virJSONStaticObjectAppendString:
+ * @object: destination object
+ * @key: property key
+ * @value_dest: a preallocated object for storing the JSON value
+ * @value: value of the property
+ *
+ * Add a string value to @object. Does not make any copies, so it is not
+ * necessary to free anything, but the caller is responsible for keeping
+ * @key, @value_dest and @value valid until it stops using @object.
+ */
+void virJSONStaticObjectAppendString(virJSONObjectPtr object, const char *key,
+ virJSONValuePtr value_dest,
+ const char *value)
+{
+ virJSONObjectPairPtr pair;
+
+ value_dest->type = VIR_JSON_TYPE_STRING;
+ value_dest->protect = 0;
+ value_dest->data.string = (char *)value;
+
+ pair = object->pairs + object->npairs;
+ pair->key = (char *)key;
+ pair->value = value_dest;
+ object->npairs++;
+}
+
+/**
+ * virJSONStaticObjectAppendNumberInt:
+ * @object: destination object
+ * @key: property key
+ * @value_dest: a preallocated object for storing the JSON value
+ * @buf: a preallocated buffer for storing the string representation of @value
+ * @buf_size: size of @buf
+ * @value: value of the property
+ *
+ * Add an integer value to @object. Does not make any copies, so it is not
+ * necessary to free anything, but the caller is responsible for keeping
+ * @key, @value_dest, @buf and @value valid until it stops using @object.
+ *
+ * @buf_size should be at least INT_BUFSIZE_BOUND(@value).
+ */
+void virJSONStaticObjectAppendNumberInt(virJSONObjectPtr object,
+ const char *key,
+ virJSONValuePtr value_dest,
+ char *buf, size_t buf_size,
+ int value)
+{
+ virJSONObjectPairPtr pair;
+
+ snprintf(buf, buf_size, "%d", value);
+ value_dest->type = VIR_JSON_TYPE_NUMBER;
+ value_dest->protect = 0;
+ value_dest->data.number = buf;
+
+ pair = object->pairs + object->npairs;
+ pair->key = (char *)key;
+ pair->value = value_dest;
+ object->npairs++;
+}
+
+
#if HAVE_YAJL
static int virJSONParserInsertValue(virJSONParserPtr parser,
virJSONValuePtr value)
diff --git a/src/util/json.h b/src/util/json.h
index bdba3dd..e2cfe6a 100644
--- a/src/util/json.h
+++ b/src/util/json.h
@@ -131,6 +131,17 @@ int virJSONValueObjectAppendNumberDouble(virJSONValuePtr object,
const char *key
int virJSONValueObjectAppendBoolean(virJSONValuePtr object, const char *key, int
boolean);
int virJSONValueObjectAppendNull(virJSONValuePtr object, const char *key);
+void virJSONStaticObjectInitialize(virJSONObjectPtr object,
+ virJSONObjectPairPtr pairs_buf);
+void virJSONStaticObjectAppendString(virJSONObjectPtr object, const char *key,
+ virJSONValuePtr value_dest,
+ const char *value);
+void virJSONStaticObjectAppendNumberInt(virJSONObjectPtr object,
+ const char *key,
+ virJSONValuePtr value_dest,
+ char *buf, size_t buf_size,
+ int value);
+
virJSONValuePtr virJSONValueFromString(const char *jsonstring);
char *virJSONValueToString(virJSONValuePtr object,
bool pretty);
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 03/12] Split yajl_gen allocation into a separate function.
Split yajl_gen (and handling of the yajl version differences) into
virYAJLInit().
No functionality changed; the function will be used in a later patch.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/json.c | 35 ++++++++++++++++++++++-------------
1 file changed, 22 insertions(+), 13 deletions(-)
diff --git a/src/util/json.c b/src/util/json.c
index 8529b5f..1accde9 100644
--- a/src/util/json.c
+++ b/src/util/json.c
@@ -1073,6 +1073,27 @@ cleanup:
}
+static yajl_gen virYAJLInit(bool pretty)
+{
+ yajl_gen g;
+# ifndef HAVE_YAJL2
+ yajl_gen_config conf = { pretty ? 1 : 0, pretty ? " " : " "};
+# endif
+
+# ifdef HAVE_YAJL2
+ g = yajl_gen_alloc(NULL);
+ if (g) {
+ yajl_gen_config(g, yajl_gen_beautify, pretty ? 1 : 0);
+ yajl_gen_config(g, yajl_gen_indent_string, pretty ? " " : "
");
+ yajl_gen_config(g, yajl_gen_validate_utf8, 1);
+ }
+# else
+ g = yajl_gen_alloc(&conf, NULL);
+# endif
+
+ return g;
+}
+
static int virJSONValueToStringOne(virJSONValuePtr object,
yajl_gen g)
{
@@ -1143,22 +1164,10 @@ char *virJSONValueToString(virJSONValuePtr object,
const unsigned char *str;
char *ret = NULL;
yajl_size_t len;
-# ifndef HAVE_YAJL2
- yajl_gen_config conf = { pretty ? 1 : 0, pretty ? " " : " "};
-# endif
VIR_DEBUG("object=%p", object);
-# ifdef HAVE_YAJL2
- g = yajl_gen_alloc(NULL);
- if (g) {
- yajl_gen_config(g, yajl_gen_beautify, pretty ? 1 : 0);
- yajl_gen_config(g, yajl_gen_indent_string, pretty ? " " : "
");
- yajl_gen_config(g, yajl_gen_validate_utf8, 1);
- }
-# else
- g = yajl_gen_alloc(&conf, NULL);
-# endif
+ g = virYAJLInit(pretty);
if (!g) {
virReportError(VIR_ERR_INTERNAL_ERROR, "%s",
_("Unable to create JSON formatter"));
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 04/12] Split adding object properties from virJSONValueToStringOne
No functionality change (well, the index is now a size_t instead of int),
the function will be used later.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/json.c | 35 ++++++++++++++++++++++++++---------
src/util/json.h | 12 ++++++++++++
2 files changed, 38 insertions(+), 9 deletions(-)
diff --git a/src/util/json.c b/src/util/json.c
index 1accde9..9b0a6dd 100644
--- a/src/util/json.c
+++ b/src/util/json.c
@@ -1105,15 +1105,8 @@ static int virJSONValueToStringOne(virJSONValuePtr object,
case VIR_JSON_TYPE_OBJECT:
if (yajl_gen_map_open(g) != yajl_gen_status_ok)
return -1;
- for (i = 0; i < object->data.object.npairs ; i++) {
- if (yajl_gen_string(g,
- (unsigned char *)object->data.object.pairs[i].key,
- strlen(object->data.object.pairs[i].key))
- != yajl_gen_status_ok)
- return -1;
- if (virJSONValueToStringOne(object->data.object.pairs[i].value, g) <
0)
- return -1;
- }
+ if (virJSONStringGeneratorAddProperties(g, &object->data.object) != 0)
+ return -1;
if (yajl_gen_map_close(g) != yajl_gen_status_ok)
return -1;
break;
@@ -1157,6 +1150,30 @@ static int virJSONValueToStringOne(virJSONValuePtr object,
return 0;
}
+/**
+ * virJSONStringGeneratorAddProperties:
+ * @gen: the destination generator
+ * @object: a JSON object
+ *
+ * Add properties contained in @object into the string generated by @gen.
+ * Note that this adds each property into the "current" object, it does not
+ * add a subobject.
+ */
+int virJSONStringGeneratorAddProperties(virJSONStringGeneratorPtr gen,
+ virJSONObjectPtr object)
+{
+ size_t i;
+
+ for (i = 0; i < object->npairs ; i++) {
+ if (yajl_gen_string(gen, (unsigned char *)object->pairs[i].key,
+ strlen(object->pairs[i].key)) != yajl_gen_status_ok)
+ return -1;
+ if (virJSONValueToStringOne(object->pairs[i].value, gen) < 0)
+ return -1;
+ }
+ return 0;
+}
+
char *virJSONValueToString(virJSONValuePtr object,
bool pretty)
{
diff --git a/src/util/json.h b/src/util/json.h
index e2cfe6a..390e68d 100644
--- a/src/util/json.h
+++ b/src/util/json.h
@@ -26,6 +26,9 @@
# include "internal.h"
+# if HAVE_YAJL
+# include <yajl/yajl_gen.h>
+# endif
typedef enum {
VIR_JSON_TYPE_OBJECT,
@@ -77,6 +80,12 @@ struct _virJSONValue {
} data;
};
+# if HAVE_YAJL
+typedef yajl_gen virJSONStringGeneratorPtr;
+# else
+typedef void *virJSONStringGeneratorPtr;
+# endif
+
void virJSONValueFree(virJSONValuePtr value);
virJSONValuePtr virJSONValueNewString(const char *data);
@@ -142,6 +151,9 @@ void virJSONStaticObjectAppendNumberInt(virJSONObjectPtr object,
char *buf, size_t buf_size,
int value);
+int virJSONStringGeneratorAddProperties(virJSONStringGeneratorPtr gen,
+ virJSONObjectPtr object);
+
virJSONValuePtr virJSONValueFromString(const char *jsonstring);
char *virJSONValueToString(virJSONValuePtr object,
bool pretty);
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 05/12] Add a JSON generator API.
This allows incremental use of virJSONStringGeneratorAddProperties
without constructing a full object first, while isolating the rest of
libvirt from the yajl dependency.
Will be used later.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/json.c | 60 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++
src/util/json.h | 3 +++
2 files changed, 63 insertions(+)
diff --git a/src/util/json.c b/src/util/json.c
index 9b0a6dd..03362c4 100644
--- a/src/util/json.c
+++ b/src/util/json.c
@@ -1094,6 +1094,66 @@ static yajl_gen virYAJLInit(bool pretty)
return g;
}
+/**
+ * virJSONStringGeneratorInitObject:
+ *
+ * Allocate a generator for creating a string representation of an object using
+ * one or more calls to virJSONStringGeneratorAddProperties().
+ *
+ * Returns the generator on success, NULL on error.
+ */
+virJSONStringGeneratorPtr virJSONStringGeneratorInitObject(void)
+{
+ yajl_gen g;
+
+ g = virYAJLInit(false);
+ if (g == NULL)
+ goto error;
+ if (yajl_gen_map_open(g) != yajl_gen_status_ok)
+ goto error;
+ return g;
+
+ error:
+ if (g != NULL)
+ yajl_gen_free(g);
+ return NULL;
+}
+
+/**
+ * virJSONStringGeneratorFinishObject:
+ * @gen: the destination generator
+ *
+ * Terminate the object being generated in @gen, and return its string value
+ * (or NULL on error). The value is valid until @gen is freed.
+ */
+const char *virJSONStringGeneratorFinishObject(virJSONStringGeneratorPtr gen)
+{
+ const unsigned char *res;
+ yajl_size_t len;
+
+ if (yajl_gen_map_close(gen) != yajl_gen_status_ok)
+ goto error;
+ if (yajl_gen_get_buf(gen, &res, &len) != yajl_gen_status_ok)
+ goto error;
+ return (const char *)res;
+
+ error:
+ return NULL;
+}
+
+/**
+ * virJSONStringGeneratorFree:
+ * @gen: the generator
+ *
+ * Free @gen if it is not NULL. Invalidates the result of
+ * virJSONStringGeneratorFinishObject().
+ */
+void virJSONStringGeneratorFree(virJSONStringGeneratorPtr gen)
+{
+ if (gen != NULL)
+ yajl_gen_free(gen);
+}
+
static int virJSONValueToStringOne(virJSONValuePtr object,
yajl_gen g)
{
diff --git a/src/util/json.h b/src/util/json.h
index 390e68d..80041eb 100644
--- a/src/util/json.h
+++ b/src/util/json.h
@@ -151,8 +151,11 @@ void virJSONStaticObjectAppendNumberInt(virJSONObjectPtr object,
char *buf, size_t buf_size,
int value);
+virJSONStringGeneratorPtr virJSONStringGeneratorInitObject(void);
int virJSONStringGeneratorAddProperties(virJSONStringGeneratorPtr gen,
virJSONObjectPtr object);
+const char *virJSONStringGeneratorFinishObject(virJSONStringGeneratorPtr gen);
+void virJSONStringGeneratorFree(virJSONStringGeneratorPtr gen);
virJSONValuePtr virJSONValueFromString(const char *jsonstring);
char *virJSONValueToString(virJSONValuePtr object,
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 06/12] Pass the "raw" log message to each virLogOutputFunc
In addition to the preformatted text line, pass the raw message as well,
to allow the output functions to use a different output format.
This patch only changes the interface and callers, an output function
that takes advantage of this will follow.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 23 ++++++++++++++---------
src/util/logging.h | 3 ++-
tests/testutils.c | 1 +
3 files changed, 17 insertions(+), 10 deletions(-)
diff --git a/src/util/logging.c b/src/util/logging.c
index 537c764..5471552 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -102,7 +102,7 @@ static void virLogOutputToFd(const char *category, int priority,
const char *funcname, long long linenr,
const char *timestamp,
unsigned int flags,
- const char *str,
+ const char *rawstr, const char *str,
void *data);
/*
@@ -631,7 +631,7 @@ virLogFormatString(char **msg,
}
static int
-virLogVersionString(char **msg)
+virLogVersionString(const char **rawmsg, char **msg)
{
#ifdef PACKAGER_VERSION
# ifdef PACKAGER
@@ -646,6 +646,7 @@ virLogVersionString(char **msg)
"libvirt version: " VERSION
#endif
+ *rawmsg = LOG_VERSION_STRING;
return virLogFormatString(msg, NULL, 0, VIR_LOG_INFO, LOG_VERSION_STRING);
}
@@ -725,7 +726,6 @@ void virLogVMessage(const char *category, int priority, const char
*funcname,
}
ret = virLogFormatString(&msg, funcname, linenr, priority, str);
- VIR_FREE(str);
if (ret < 0)
goto cleanup;
@@ -751,38 +751,41 @@ void virLogVMessage(const char *category, int priority, const char
*funcname,
for (i = 0; i < virLogNbOutputs; i++) {
if (priority >= virLogOutputs[i].priority) {
if (virLogOutputs[i].logVersion) {
+ const char *rawver;
char *ver = NULL;
- if (virLogVersionString(&ver) >= 0)
+ if (virLogVersionString(&rawver, &ver) >= 0)
virLogOutputs[i].f(category, VIR_LOG_INFO,
__func__, __LINE__,
- timestamp, 0, ver,
+ timestamp, 0, rawver, ver,
virLogOutputs[i].data);
VIR_FREE(ver);
virLogOutputs[i].logVersion = false;
}
virLogOutputs[i].f(category, priority, funcname, linenr,
timestamp, filterflags,
- msg, virLogOutputs[i].data);
+ str, msg, virLogOutputs[i].data);
}
}
if ((virLogNbOutputs == 0) && (flags != 1)) {
if (logVersionStderr) {
+ const char *rawver;
char *ver = NULL;
- if (virLogVersionString(&ver) >= 0)
+ if (virLogVersionString(&rawver, &ver) >= 0)
virLogOutputToFd(category, VIR_LOG_INFO,
__func__, __LINE__,
- timestamp, 0, ver,
+ timestamp, 0, rawver, ver,
(void *) STDERR_FILENO);
VIR_FREE(ver);
logVersionStderr = false;
}
virLogOutputToFd(category, priority, funcname, linenr,
timestamp, filterflags,
- msg, (void *) STDERR_FILENO);
+ str, msg, (void *) STDERR_FILENO);
}
virLogUnlock();
cleanup:
+ VIR_FREE(str);
VIR_FREE(msg);
errno = saved_errno;
}
@@ -813,6 +816,7 @@ static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
long long linenr ATTRIBUTE_UNUSED,
const char *timestamp,
unsigned int flags,
+ const char *rawstr ATTRIBUTE_UNUSED,
const char *str,
void *data)
{
@@ -868,6 +872,7 @@ static void virLogOutputToSyslog(const char *category
ATTRIBUTE_UNUSED,
long long linenr ATTRIBUTE_UNUSED,
const char *timestamp ATTRIBUTE_UNUSED,
unsigned int flags,
+ const char *rawstr ATTRIBUTE_UNUSED,
const char *str,
void *data ATTRIBUTE_UNUSED)
{
diff --git a/src/util/logging.h b/src/util/logging.h
index 1c484bb..10ff6c9 100644
--- a/src/util/logging.h
+++ b/src/util/logging.h
@@ -90,6 +90,7 @@ typedef enum {
* @linenr: line where the message was emitted
* @timestamp: zero terminated string with timestamp of the message
* @flags: flags associated with the message
+ * @rawstr: the unformatted message to log, zero terminated
* @str: the message to log, preformatted and zero terminated
* @data: extra output logging data
*
@@ -99,7 +100,7 @@ typedef void (*virLogOutputFunc) (const char *category, int priority,
const char *funcname, long long linenr,
const char *timestamp,
unsigned int flags,
- const char *str,
+ const char *rawstr, const char *str,
void *data);
/**
diff --git a/tests/testutils.c b/tests/testutils.c
index 5c32f14..6978020 100644
--- a/tests/testutils.c
+++ b/tests/testutils.c
@@ -485,6 +485,7 @@ virtTestLogOutput(const char *category ATTRIBUTE_UNUSED,
long long lineno ATTRIBUTE_UNUSED,
const char *timestamp,
unsigned int flags,
+ const char *rawstr ATTRIBUTE_UNUSED,
const char *str,
void *data)
{
--
1.7.11.4
9:09 a.m.
New subject: [libvirt] [PATCH 06/12] Pass the "raw" log message to each virLogOutputFunc
On Thu, Sep 20, 2012 at 08:24:05PM +0200, Miloslav Trmač wrote:
In addition to the preformatted text line, pass the raw message as
well,
to allow the output functions to use a different output format.
This patch only changes the interface and callers, an output function
that takes advantage of this will follow.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 23 ++++++++++++++---------
src/util/logging.h | 3 ++-
tests/testutils.c | 1 +
3 files changed, 17 insertions(+), 10 deletions(-)
Independantly of my opinion of the patch series in general,
I think something like this patch is worthwhile. I would
take a slightly different approach though. Instead of passing
the rawstr + str into the output functions, I'd only pass the
rawstr, and actually move the virLogFormatString() call down
into the output functions, instead of virLogVMessage
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
7:17 a.m.
New subject: [libvirt] [PATCH 06/12] Pass the "raw" log message to each virLogOutputFunc
On Tue, Sep 25, 2012 at 03:09:22PM +0100, Daniel P. Berrange wrote:
On Thu, Sep 20, 2012 at 08:24:05PM +0200, Miloslav Trmač wrote:
> In addition to the preformatted text line, pass the raw message as well,
> to allow the output functions to use a different output format.
>
> This patch only changes the interface and callers, an output function
> that takes advantage of this will follow.
>
> Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
> ---
> src/util/logging.c | 23 ++++++++++++++---------
> src/util/logging.h | 3 ++-
> tests/testutils.c | 1 +
> 3 files changed, 17 insertions(+), 10 deletions(-)
Independantly of my opinion of the patch series in general,
I think something like this patch is worthwhile. I would
take a slightly different approach though. Instead of passing
the rawstr + str into the output functions, I'd only pass the
rawstr, and actually move the virLogFormatString() call down
into the output functions, instead of virLogVMessage
Urgh, sadly this turns out to not be practical because we need to populate
the in memory log buffer with the data.
So ACK to this patch - I'll apply it now.
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
1:24 p.m.
New subject: [libvirt] [PATCH 07/12] Split priority conversion from virLogOutputToSyslog
No change in functionality; the newly separated virLogPrioritySyslog
function will be used by the next patch.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 36 +++++++++++++++++-------------------
1 file changed, 17 insertions(+), 19 deletions(-)
diff --git a/src/util/logging.c b/src/util/logging.c
index 5471552..b71eacc 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -866,6 +866,22 @@ static int virLogAddOutputToFile(int priority, const char *file) {
}
#if HAVE_SYSLOG_H
+static int virLogPrioritySyslog(virLogPriority priority)
+{
+ switch (priority) {
+ case VIR_LOG_DEBUG:
+ return LOG_DEBUG;
+ case VIR_LOG_INFO:
+ return LOG_INFO;
+ case VIR_LOG_WARN:
+ return LOG_WARNING;
+ case VIR_LOG_ERROR:
+ return LOG_ERR;
+ default:
+ return LOG_ERR;
+ }
+}
+
static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED,
int priority,
const char *funcname ATTRIBUTE_UNUSED,
@@ -876,27 +892,9 @@ static void virLogOutputToSyslog(const char *category
ATTRIBUTE_UNUSED,
const char *str,
void *data ATTRIBUTE_UNUSED)
{
- int prio;
-
virCheckFlags(VIR_LOG_STACK_TRACE,);
- switch (priority) {
- case VIR_LOG_DEBUG:
- prio = LOG_DEBUG;
- break;
- case VIR_LOG_INFO:
- prio = LOG_INFO;
- break;
- case VIR_LOG_WARN:
- prio = LOG_WARNING;
- break;
- case VIR_LOG_ERROR:
- prio = LOG_ERR;
- break;
- default:
- prio = LOG_ERR;
- }
- syslog(prio, "%s", str);
+ syslog(virLogPrioritySyslog(priority), "%s", str);
}
static char *current_ident = NULL;
--
1.7.11.4
8:13 a.m.
New subject: [libvirt] [PATCH 07/12] Split priority conversion from virLogOutputToSyslog
On Thu, Sep 20, 2012 at 08:24:06PM +0200, Miloslav Trmač wrote:
No change in functionality; the newly separated virLogPrioritySyslog
function will be used by the next patch.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 36 +++++++++++++++++-------------------
1 file changed, 17 insertions(+), 19 deletions(-)
diff --git a/src/util/logging.c b/src/util/logging.c
index 5471552..b71eacc 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -866,6 +866,22 @@ static int virLogAddOutputToFile(int priority, const char *file) {
}
#if HAVE_SYSLOG_H
+static int virLogPrioritySyslog(virLogPriority priority)
+{
+ switch (priority) {
+ case VIR_LOG_DEBUG:
+ return LOG_DEBUG;
+ case VIR_LOG_INFO:
+ return LOG_INFO;
+ case VIR_LOG_WARN:
+ return LOG_WARNING;
+ case VIR_LOG_ERROR:
+ return LOG_ERR;
+ default:
+ return LOG_ERR;
+ }
+}
+
static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED,
int priority,
const char *funcname ATTRIBUTE_UNUSED,
@@ -876,27 +892,9 @@ static void virLogOutputToSyslog(const char *category
ATTRIBUTE_UNUSED,
const char *str,
void *data ATTRIBUTE_UNUSED)
{
- int prio;
-
virCheckFlags(VIR_LOG_STACK_TRACE,);
- switch (priority) {
- case VIR_LOG_DEBUG:
- prio = LOG_DEBUG;
- break;
- case VIR_LOG_INFO:
- prio = LOG_INFO;
- break;
- case VIR_LOG_WARN:
- prio = LOG_WARNING;
- break;
- case VIR_LOG_ERROR:
- prio = LOG_ERR;
- break;
- default:
- prio = LOG_ERR;
- }
- syslog(prio, "%s", str);
+ syslog(virLogPrioritySyslog(priority), "%s", str);
}
ACK, useful refactoring independant of the rest of the code
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
1:24 p.m.
New subject: [libvirt] [PATCH 08/12] Add "syslog/json" log output format.
Add a "syslog/json" output format, which uses a JSON representation
(as specified in Lumberjack project, and planned for the CEE standard)
to format individual components, making the result easy to parse without
writing custom code or using unreliable regexps.
Example message (line-wrapped for readability, the actual output is a
single line):
Sep 17 21:47:22 kulicka libvirt: @cee: {"msg":"Domain not found",
"category":"../../src/test/test_driver.c","libvirt_priority":"error",
"funcname":"testLookupDomainByName","line":1403,
"timestamp":"2012-09-17 19:47:22.731+0000"}
None of the existing log output formats (e.g. "syslog" or "file") is
affected.
The JSON objects are allocated on the stack, which is a little less
convenient than allocating them from the heap, but we don't have to care
about the allocations failing, calling virReportOOMError and deadlocking
on virLogMutex.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
docs/logging.html.in | 3 ++
src/util/json.c | 20 +++++++++-
src/util/logging.c | 110 +++++++++++++++++++++++++++++++++++++++++++++++++--
src/util/logging.h | 1 +
4 files changed, 128 insertions(+), 6 deletions(-)
diff --git a/docs/logging.html.in b/docs/logging.html.in
index a95f7bc..4f8ad87 100644
--- a/docs/logging.html.in
+++ b/docs/logging.html.in
@@ -143,6 +143,9 @@
<li><code>x:stderr</code> output goes to stderr</li>
<li><code>x:syslog:name</code> use syslog for the output and use
the
given <code>name</code> as the ident</li>
+ <li><code>x:syslog/json:name</code> use JSON-formatted syslog
(also
+ called the CEE format or Lumberjack) for the output and use the given
+ <code>name</code> as the ident</li>
<li><code>x:file:file_path</code> output to a file, with the
given
filepath</li>
</ul>
diff --git a/src/util/json.c b/src/util/json.c
index 03362c4..96786c8 100644
--- a/src/util/json.c
+++ b/src/util/json.c
@@ -672,6 +672,8 @@ int virJSONValueObjectIsNull(virJSONValuePtr object, const char *key)
* The caller is responsible for sizing @pairs_buf appropriately, one entry
* per virJSONStaticObjectAppend* call.
*/
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
void virJSONStaticObjectInitialize(virJSONObjectPtr object,
virJSONObjectPairPtr pairs_buf)
{
@@ -690,6 +692,8 @@ void virJSONStaticObjectInitialize(virJSONObjectPtr object,
* necessary to free anything, but the caller is responsible for keeping
* @key, @value_dest and @value valid until it stops using @object.
*/
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
void virJSONStaticObjectAppendString(virJSONObjectPtr object, const char *key,
virJSONValuePtr value_dest,
const char *value)
@@ -721,6 +725,8 @@ void virJSONStaticObjectAppendString(virJSONObjectPtr object, const
char *key,
*
* @buf_size should be at least INT_BUFSIZE_BOUND(@value).
*/
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
void virJSONStaticObjectAppendNumberInt(virJSONObjectPtr object,
const char *key,
virJSONValuePtr value_dest,
@@ -1073,6 +1079,8 @@ cleanup:
}
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
static yajl_gen virYAJLInit(bool pretty)
{
yajl_gen g;
@@ -1102,6 +1110,8 @@ static yajl_gen virYAJLInit(bool pretty)
*
* Returns the generator on success, NULL on error.
*/
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
virJSONStringGeneratorPtr virJSONStringGeneratorInitObject(void)
{
yajl_gen g;
@@ -1126,6 +1136,8 @@ virJSONStringGeneratorPtr virJSONStringGeneratorInitObject(void)
* Terminate the object being generated in @gen, and return its string value
* (or NULL on error). The value is valid until @gen is freed.
*/
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
const char *virJSONStringGeneratorFinishObject(virJSONStringGeneratorPtr gen)
{
const unsigned char *res;
@@ -1148,19 +1160,21 @@ const char
*virJSONStringGeneratorFinishObject(virJSONStringGeneratorPtr gen)
* Free @gen if it is not NULL. Invalidates the result of
* virJSONStringGeneratorFinishObject().
*/
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
void virJSONStringGeneratorFree(virJSONStringGeneratorPtr gen)
{
if (gen != NULL)
yajl_gen_free(gen);
}
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
static int virJSONValueToStringOne(virJSONValuePtr object,
yajl_gen g)
{
int i;
- VIR_DEBUG("object=%p type=%d gen=%p", object, object->type, g);
-
switch (object->type) {
case VIR_JSON_TYPE_OBJECT:
if (yajl_gen_map_open(g) != yajl_gen_status_ok)
@@ -1219,6 +1233,8 @@ static int virJSONValueToStringOne(virJSONValuePtr object,
* Note that this adds each property into the "current" object, it does not
* add a subobject.
*/
+/* Don't call any error reporting or logging functions from this function,
+ the error loging mechanism may use this! */
int virJSONStringGeneratorAddProperties(virJSONStringGeneratorPtr gen,
virJSONObjectPtr object)
{
diff --git a/src/util/logging.c b/src/util/logging.c
index b71eacc..97431b2 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -21,6 +21,7 @@
#include <config.h>
+#include <stdbool.h>
#include <stdio.h>
#include <stdarg.h>
#include <stdlib.h>
@@ -39,12 +40,15 @@
#include "virterror_internal.h"
#include "logging.h"
#include "memory.h"
+#include "json.h"
#include "util.h"
#include "buf.h"
#include "threads.h"
#include "virfile.h"
#include "virtime.h"
+#include "intprops.h"
+
#define VIR_FROM_THIS VIR_FROM_NONE
/*
@@ -127,6 +131,8 @@ static const char *virLogOutputString(virLogDestination ldest) {
return "syslog";
case VIR_LOG_TO_FILE:
return "file";
+ case VIR_LOG_TO_SYSLOG_JSON:
+ return "syslog/json";
}
return "unknown";
}
@@ -575,7 +581,8 @@ int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void
*data,
if (f == NULL)
return -1;
- if (dest == VIR_LOG_TO_SYSLOG || dest == VIR_LOG_TO_FILE) {
+ if (dest == VIR_LOG_TO_SYSLOG || dest == VIR_LOG_TO_SYSLOG_JSON
+ || dest == VIR_LOG_TO_FILE) {
if (name == NULL)
return -1;
ndup = strdup(name);
@@ -897,6 +904,82 @@ static void virLogOutputToSyslog(const char *category
ATTRIBUTE_UNUSED,
syslog(virLogPrioritySyslog(priority), "%s", str);
}
+#if HAVE_YAJL
+static const char *virLogPriorityJSONString(virLogPriority lvl) {
+ /* This follows "prioritynames" from <sys/syslog.h> */
+ switch (virLogPrioritySyslog(lvl)) {
+ case LOG_DEBUG:
+ return "debug";
+ case LOG_INFO:
+ return "info";
+ case LOG_WARNING:
+ return "warn";
+ case LOG_ERR:
+ return "err";
+ }
+ return "unknown";
+}
+
+static void virLogOutputToSyslogJSON(const char *category, int priority,
+ const char *funcname, long long linenr,
+ const char *timestamp,
+ unsigned int flags,
+ const char *rawstr, const char *str,
+ void *data ATTRIBUTE_UNUSED)
+{
+ /* This can't use virJSONValueToString because that function can create log
+ messages, which would lead to infinite recursion. */
+ virJSONStringGeneratorPtr g = NULL;
+ virJSONObject json;
+ virJSONObjectPair json_pairs[6];
+ virJSONValue json_msg, json_category, json_priority, json_funcname;
+ virJSONValue json_line, json_timestamp;
+ char line_buf[INT_BUFSIZE_BOUND(linenr)];
+ const char *json_string;
+
+ virCheckFlags(VIR_LOG_STACK_TRACE,);
+
+ /* The field names follow https://fedorahosted.org/lumberjack/wiki/FieldList
+ - use the same field names when the purpose and type matches, use a
+ different field name otherwise.
+
+ msg goes first, so that the most important information is in a fixed
+ position on the screen (= easy to find); the metadata comes later (or
+ perhaps does not fit into the terminal/log viewer window). */
+ virJSONStaticObjectInitialize(&json, json_pairs);
+ virJSONStaticObjectAppendString(&json, "msg", &json_msg, rawstr);
+ virJSONStaticObjectAppendString(&json, "category", &json_category,
+ category);
+ virJSONStaticObjectAppendString(&json, "priority", &json_priority,
+ virLogPriorityJSONString(priority));
+ if (funcname != NULL)
+ virJSONStaticObjectAppendString(&json, "funcname",
&json_funcname,
+ funcname);
+ virJSONStaticObjectAppendNumberInt(&json, "line", &json_line,
+ line_buf, sizeof(line_buf), linenr);
+ virJSONStaticObjectAppendString(&json, "timestamp",
&json_timestamp,
+ timestamp);
+
+ g = virJSONStringGeneratorInitObject();
+ if (g == NULL)
+ goto error;
+ if (virJSONStringGeneratorAddProperties(g, &json) != 0)
+ goto error;
+ json_string = virJSONStringGeneratorFinishObject(g);
+ if (json_string == NULL)
+ goto error;
+
+ syslog(virLogPrioritySyslog(priority), "@cee: %s", json_string);
+ virJSONStringGeneratorFree(g);
+ return;
+
+ error:
+ virJSONStringGeneratorFree(g);
+ virLogOutputToSyslog(category, priority, funcname, linenr, timestamp, flags,
+ rawstr, str, NULL);
+}
+#endif
+
static char *current_ident = NULL;
static void virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) {
@@ -904,7 +987,17 @@ static void virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) {
VIR_FREE(current_ident);
}
-static int virLogAddOutputToSyslog(int priority, const char *ident) {
+static int virLogAddOutputToSyslog(int priority, const char *ident,
+ bool is_json) {
+ virLogOutputFunc f;
+
+#ifdef HAVE_YAJL
+ if (is_json)
+ f = virLogOutputToSyslogJSON;
+ else
+#endif
+ f = virLogOutputToSyslog;
+
/*
* ident needs to be kept around on Solaris
*/
@@ -914,7 +1007,7 @@ static int virLogAddOutputToSyslog(int priority, const char *ident)
{
return -1;
openlog(current_ident, 0, 0);
- if (virLogDefineOutput(virLogOutputToSyslog, virLogCloseSyslog, NULL,
+ if (virLogDefineOutput(f, virLogCloseSyslog, NULL,
priority, VIR_LOG_TO_SYSLOG, ident, 0) < 0) {
closelog();
VIR_FREE(current_ident);
@@ -975,7 +1068,16 @@ int virLogParseOutputs(const char *outputs) {
if (virLogAddOutputToStderr(prio) == 0)
count++;
} else if (STREQLEN(cur, "syslog", 6)) {
+ bool is_json;
+
cur += 6;
+ if (*cur == ':')
+ is_json = false;
+ else if (STREQLEN(cur, "/json", 5)) {
+ is_json = true;
+ cur += 5;
+ } else
+ goto cleanup;
if (*cur != ':')
goto cleanup;
cur++;
@@ -988,7 +1090,7 @@ int virLogParseOutputs(const char *outputs) {
name = strndup(str, cur - str);
if (name == NULL)
goto cleanup;
- if (virLogAddOutputToSyslog(prio, name) == 0)
+ if (virLogAddOutputToSyslog(prio, name, is_json) == 0)
count++;
VIR_FREE(name);
#endif /* HAVE_SYSLOG_H */
diff --git a/src/util/logging.h b/src/util/logging.h
index 10ff6c9..a66f5dc 100644
--- a/src/util/logging.h
+++ b/src/util/logging.h
@@ -80,6 +80,7 @@ typedef enum {
VIR_LOG_TO_STDERR = 1,
VIR_LOG_TO_SYSLOG,
VIR_LOG_TO_FILE,
+ VIR_LOG_TO_SYSLOG_JSON,
} virLogDestination;
/**
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 09/12] Add a JSON properties parameter to virLog{, V}Message
... and update all users. No change in functionality, the parameter
will be used in later patches.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/uml/uml_conf.c | 2 +-
src/util/logging.c | 13 +++++++++----
src/util/logging.h | 17 +++++++++--------
src/util/viraudit.c | 4 ++--
src/util/virterror.c | 2 +-
5 files changed, 22 insertions(+), 16 deletions(-)
diff --git a/src/uml/uml_conf.c b/src/uml/uml_conf.c
index 410f3e2..6ad7a7b 100644
--- a/src/uml/uml_conf.c
+++ b/src/uml/uml_conf.c
@@ -53,7 +53,7 @@
#define VIR_FROM_THIS VIR_FROM_UML
#define umlLog(level, msg, ...) \
- virLogMessage(__FILE__, level, 0, msg, __VA_ARGS__)
+ virLogMessage(__FILE__, level, NULL, 0, msg, __VA_ARGS__)
static int umlDefaultConsoleType(const char *ostype ATTRIBUTE_UNUSED)
diff --git a/src/util/logging.c b/src/util/logging.c
index 97431b2..feef711 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -663,6 +663,7 @@ virLogVersionString(const char **rawmsg, char **msg)
* @priority: the priority level
* @funcname: the function emitting the (debug) message
* @linenr: line where the message was emitted
+ * @properties: additional JSON properties to add to the log object, or NULL
* @flags: extra flags, 1 if coming from the error handler
* @fmt: the string format
* @...: the arguments
@@ -671,11 +672,13 @@ virLogVersionString(const char **rawmsg, char **msg)
* the message may be stored, sent to output or just discarded
*/
void virLogMessage(const char *category, int priority, const char *funcname,
- long long linenr, unsigned int flags, const char *fmt, ...)
+ long long linenr, virJSONObjectPtr properties,
+ unsigned int flags, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
- virLogVMessage(category, priority, funcname, linenr, flags, fmt, ap);
+ virLogVMessage(category, priority, funcname, linenr, properties, flags, fmt,
+ ap);
va_end(ap);
}
@@ -685,6 +688,7 @@ void virLogMessage(const char *category, int priority, const char
*funcname,
* @priority: the priority level
* @funcname: the function emitting the (debug) message
* @linenr: line where the message was emitted
+ * @properties: additional JSON properties to add to the log object, or NULL
* @flags: extra flags, 1 if coming from the error handler
* @fmt: the string format
* @vargs: format args
@@ -693,8 +697,9 @@ void virLogMessage(const char *category, int priority, const char
*funcname,
* the message may be stored, sent to output or just discarded
*/
void virLogVMessage(const char *category, int priority, const char *funcname,
- long long linenr, unsigned int flags, const char *fmt,
- va_list vargs)
+ long long linenr,
+ virJSONObjectPtr properties ATTRIBUTE_UNUSED,
+ unsigned int flags, const char *fmt, va_list vargs)
{
static bool logVersionStderr = true;
char *str = NULL;
diff --git a/src/util/logging.h b/src/util/logging.h
index a66f5dc..14b7b7c 100644
--- a/src/util/logging.h
+++ b/src/util/logging.h
@@ -24,6 +24,7 @@
# include "internal.h"
# include "buf.h"
+# include "json.h"
/*
* If configured with --enable-debug=yes then library calls
@@ -32,7 +33,7 @@
*/
# ifdef ENABLE_DEBUG
# define VIR_DEBUG_INT(category, f, l, ...) \
- virLogMessage(category, VIR_LOG_DEBUG, f, l, 0, __VA_ARGS__)
+ virLogMessage(category, VIR_LOG_DEBUG, f, l, NULL, 0, __VA_ARGS__)
# else
/**
* virLogEatParams:
@@ -49,11 +50,11 @@ static inline void virLogEatParams(const char *unused, ...)
# endif /* !ENABLE_DEBUG */
# define VIR_INFO_INT(category, f, l, ...) \
- virLogMessage(category, VIR_LOG_INFO, f, l, 0, __VA_ARGS__)
+ virLogMessage(category, VIR_LOG_INFO, f, l, NULL, 0, __VA_ARGS__)
# define VIR_WARN_INT(category, f, l, ...) \
- virLogMessage(category, VIR_LOG_WARN, f, l, 0, __VA_ARGS__)
+ virLogMessage(category, VIR_LOG_WARN, f, l, NULL, 0, __VA_ARGS__)
# define VIR_ERROR_INT(category, f, l, ...) \
- virLogMessage(category, VIR_LOG_ERROR, f, l, 0, __VA_ARGS__)
+ virLogMessage(category, VIR_LOG_ERROR, f, l, NULL, 0, __VA_ARGS__)
# define VIR_DEBUG(...) \
VIR_DEBUG_INT("file." __FILE__, __func__, __LINE__, __VA_ARGS__)
@@ -141,13 +142,13 @@ extern int virLogParseFilters(const char *filters);
extern int virLogParseOutputs(const char *output);
extern void virLogMessage(const char *category, int priority,
const char *funcname, long long linenr,
- unsigned int flags,
- const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(6, 7);
+ virJSONObjectPtr properties, unsigned int flags,
+ const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(7, 8);
extern void virLogVMessage(const char *category, int priority,
const char *funcname, long long linenr,
- unsigned int flags,
+ virJSONObjectPtr properties, unsigned int flags,
const char *fmt,
- va_list vargs) ATTRIBUTE_FMT_PRINTF(6, 0);
+ va_list vargs) ATTRIBUTE_FMT_PRINTF(7, 0);
extern int virLogSetBufferSize(int size);
extern void virLogEmergencyDumpAll(int signum);
#endif
diff --git a/src/util/viraudit.c b/src/util/viraudit.c
index 691d2f1..9437155 100644
--- a/src/util/viraudit.c
+++ b/src/util/viraudit.c
@@ -103,10 +103,10 @@ void virAuditSend(const char *file ATTRIBUTE_UNUSED, const char
*func,
if (auditlog && str) {
if (success)
- virLogMessage("audit", VIR_LOG_INFO, func, linenr, 0,
+ virLogMessage("audit", VIR_LOG_INFO, func, linenr, NULL, 0,
"success=yes %s", str);
else
- virLogMessage("audit", VIR_LOG_WARN, func, linenr, 0,
+ virLogMessage("audit", VIR_LOG_WARN, func, linenr, NULL, 0,
"success=no %s", str);
}
diff --git a/src/util/virterror.c b/src/util/virterror.c
index 7caa69e..f93b9f6 100644
--- a/src/util/virterror.c
+++ b/src/util/virterror.c
@@ -677,7 +677,7 @@ virRaiseErrorFull(const char *filename ATTRIBUTE_UNUSED,
if (virErrorLogPriorityFilter)
priority = virErrorLogPriorityFilter(to, priority);
virLogMessage(filename, priority,
- funcname, linenr,
+ funcname, linenr, NULL,
virErrorLogPriorityFilter ? 0 : 1,
"%s", str);
--
1.7.11.4
9:17 a.m.
New subject: [libvirt] [PATCH 09/12] Add a JSON properties parameter to virLog{, V}Message
On Thu, Sep 20, 2012 at 08:24:08PM +0200, Miloslav Trmač wrote:
... and update all users. No change in functionality, the parameter
will be used in later patches.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/uml/uml_conf.c | 2 +-
src/util/logging.c | 13 +++++++++----
src/util/logging.h | 17 +++++++++--------
src/util/viraudit.c | 4 ++--
src/util/virterror.c | 2 +-
5 files changed, 22 insertions(+), 16 deletions(-)
diff --git a/src/util/logging.h b/src/util/logging.h
index a66f5dc..14b7b7c 100644
--- a/src/util/logging.h
+++ b/src/util/logging.h
@@ -141,13 +142,13 @@ extern int virLogParseFilters(const char *filters);
extern int virLogParseOutputs(const char *output);
extern void virLogMessage(const char *category, int priority,
const char *funcname, long long linenr,
- unsigned int flags,
- const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(6, 7);
+ virJSONObjectPtr properties, unsigned int flags,
+ const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(7, 8);
extern void virLogVMessage(const char *category, int priority,
const char *funcname, long long linenr,
- unsigned int flags,
+ virJSONObjectPtr properties, unsigned int flags,
const char *fmt,
- va_list vargs) ATTRIBUTE_FMT_PRINTF(6, 0);
+ va_list vargs) ATTRIBUTE_FMT_PRINTF(7, 0);
extern int virLogSetBufferSize(int size);
extern void virLogEmergencyDumpAll(int signum);
#endif
Definite NACK to this change, since it is exposing the impl details
of the Lumberjack log output function to all users of the libvirt
logging API, not to mention the general unpleasant usability aspects
of having to build up JSON objects simply to pass a few extra metadata
fields.
I'm all for allowing more metadata properties to be passed into the
logging functions, but we need a simpler API along the lines of the
systemd journal sd_journal_send() style which allows for a set of
key=value pairs to be passed in. I'd not try to shoe-horn it into
the existing virLogMessage() APIs. In the same way that there is
sd_journal_print() for simple string messages, vis sd_journal_send()
for arbitrary key=value pair log messages, I'd create a new API
for this called virLogMetadata and virLogVMetadata. eg to allow
sending a message with an error no
virLogMetadata(__FILE__, VIR_LOG_WARN,
__FUNC__, __LINE__,
0,
"MESSAGE=Unable to open file %s: %s", "/some/file",
strerror(errno),
"ERRNO=%d", errno,
NULL);
Regards,
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
2:07 p.m.
New subject: [libvirt] [PATCH 09/12] Add a JSON properties parameter to virLog{, V}Message
Thanks for the review.
----- Original Message -----
On Thu, Sep 20, 2012 at 08:24:08PM +0200, Miloslav Trmač wrote:
> ... and update all users. No change in functionality, the parameter
> will be used in later patches.
>
> diff --git a/src/util/logging.h b/src/util/logging.h
> index a66f5dc..14b7b7c 100644
> --- a/src/util/logging.h
> +++ b/src/util/logging.h
> @@ -141,13 +142,13 @@ extern int virLogParseFilters(const char
> *filters);
> extern int virLogParseOutputs(const char *output);
> extern void virLogMessage(const char *category, int priority,
> const char *funcname, long long linenr,
> - unsigned int flags,
> - const char *fmt, ...)
> ATTRIBUTE_FMT_PRINTF(6, 7);
> + virJSONObjectPtr properties, unsigned
> int flags,
> + const char *fmt, ...)
Definite NACK to this change, since it is exposing the impl details
of the Lumberjack log output function to all users of the libvirt
logging API, not to mention the general unpleasant usability aspects
of having to build up JSON objects simply to pass a few extra metadata
fields.
I didn't think adding an abstraction for a single user was worth it, but you're
right, the result did end up rather uglier than I expected.
I'm all for allowing more metadata properties to be passed into
the
logging functions, but we need a simpler API along the lines of the
systemd journal sd_journal_send() style which allows for a set of
key=value pairs to be passed in. I'd not try to shoe-horn it into
the existing virLogMessage() APIs. In the same way that there is
sd_journal_print() for simple string messages, vis sd_journal_send()
for arbitrary key=value pair log messages, I'd create a new API
for this called virLogMetadata and virLogVMetadata. eg to allow
sending a message with an error no
virLogMetadata(__FILE__, VIR_LOG_WARN,
__FUNC__, __LINE__,
0,
"MESSAGE=Unable to open file %s: %s",
"/some/file",
strerror(errno),
"ERRNO=%d", errno,
NULL);
I'm afraid this is not possible to implement portably and reliably without
reimplementing 50% of sprintf(), especially in the presence of translations and the
associated %5$s formats.[1][2]
One problem with the above is that it is possible to send a log event without the MESSAGE
field, which would leave non-structured formats with nothing to log. I can see three
options:
1) as proposed above, silently failing if the MESSAGE field is missing (or if there is a
typo in the field name); with type fields added to represent JSON integers as integers.
2) MESSAGE is mandatory, everything pre-formatted
virAsprintf(&msg, "Unable to open file %s: %s", "/some/file",
strerror(errno));
virLogMetadata(... __LINE__, msg,
"ERRNO", VIR_LOG_INT, errno,
NULL)
3) MESSAGE is printf-like, everything else in an array.
struct virLogMetadata meta[2] = { { "ERRNO", VIR_LOG_INT, .i = errno }, {
NULL, } };
virLogMetadata(... __LINE__, meta,
"Unable to open file %s: %s", "/some/file",
strerror(errno));
or equivalently:
virLogMetadata(... __LINE__,
&(struct virLogMetadata []) {
{ "ERRNO", VIR_LOG_INT, .i = errno },
{ NULL, }
},
"Unable to open file %s: %s", "/some/file",
strerror(errno));
which could be hidden by macros:
virLogMetadata(VIR_LOG_INT("ERRNO", errno"),
VIR_LOG_END,
"Unable to open file %s: %s", "/some/file",
strerror(errno));
Do you have any preference? I'm leaning towards the first variant of 3) for now, we
can add fancy macros later when/if more callers of virLogMetadata are added.
Thanks again,
Mirek
[1] The unportable way to do this is to use parse_printf_format() from glibc.
[2] The logging API could implement only a subset of the printf formats, but it would be
rather difficult to notice if a newly added caller used an unsupported format a few years
later, especially when translators can use different formats than the original string.
1:24 p.m.
New subject: [libvirt] [PATCH 10/12] Add a JSON properties parameter to virLogOutputFunc
... and update all users. No change in functionality, the parameter
will be used in the next patch.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 20 +++++++++++---------
src/util/logging.h | 2 ++
tests/testutils.c | 1 +
3 files changed, 14 insertions(+), 9 deletions(-)
diff --git a/src/util/logging.c b/src/util/logging.c
index feef711..987dffc 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -104,7 +104,7 @@ static int virLogResetFilters(void);
static int virLogResetOutputs(void);
static void virLogOutputToFd(const char *category, int priority,
const char *funcname, long long linenr,
- const char *timestamp,
+ const char *timestamp, virJSONObjectPtr properties,
unsigned int flags,
const char *rawstr, const char *str,
void *data);
@@ -697,8 +697,7 @@ void virLogMessage(const char *category, int priority, const char
*funcname,
* the message may be stored, sent to output or just discarded
*/
void virLogVMessage(const char *category, int priority, const char *funcname,
- long long linenr,
- virJSONObjectPtr properties ATTRIBUTE_UNUSED,
+ long long linenr, virJSONObjectPtr properties,
unsigned int flags, const char *fmt, va_list vargs)
{
static bool logVersionStderr = true;
@@ -768,13 +767,13 @@ void virLogVMessage(const char *category, int priority, const char
*funcname,
if (virLogVersionString(&rawver, &ver) >= 0)
virLogOutputs[i].f(category, VIR_LOG_INFO,
__func__, __LINE__,
- timestamp, 0, rawver, ver,
+ timestamp, NULL, 0, rawver, ver,
virLogOutputs[i].data);
VIR_FREE(ver);
virLogOutputs[i].logVersion = false;
}
virLogOutputs[i].f(category, priority, funcname, linenr,
- timestamp, filterflags,
+ timestamp, properties, filterflags,
str, msg, virLogOutputs[i].data);
}
}
@@ -785,13 +784,13 @@ void virLogVMessage(const char *category, int priority, const char
*funcname,
if (virLogVersionString(&rawver, &ver) >= 0)
virLogOutputToFd(category, VIR_LOG_INFO,
__func__, __LINE__,
- timestamp, 0, rawver, ver,
+ timestamp, NULL, 0, rawver, ver,
(void *) STDERR_FILENO);
VIR_FREE(ver);
logVersionStderr = false;
}
virLogOutputToFd(category, priority, funcname, linenr,
- timestamp, filterflags,
+ timestamp, properties, filterflags,
str, msg, (void *) STDERR_FILENO);
}
virLogUnlock();
@@ -827,6 +826,7 @@ static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
const char *funcname ATTRIBUTE_UNUSED,
long long linenr ATTRIBUTE_UNUSED,
const char *timestamp,
+ virJSONObjectPtr properties ATTRIBUTE_UNUSED,
unsigned int flags,
const char *rawstr ATTRIBUTE_UNUSED,
const char *str,
@@ -899,6 +899,7 @@ static void virLogOutputToSyslog(const char *category
ATTRIBUTE_UNUSED,
const char *funcname ATTRIBUTE_UNUSED,
long long linenr ATTRIBUTE_UNUSED,
const char *timestamp ATTRIBUTE_UNUSED,
+ virJSONObjectPtr properties ATTRIBUTE_UNUSED,
unsigned int flags,
const char *rawstr ATTRIBUTE_UNUSED,
const char *str,
@@ -928,6 +929,7 @@ static const char *virLogPriorityJSONString(virLogPriority lvl) {
static void virLogOutputToSyslogJSON(const char *category, int priority,
const char *funcname, long long linenr,
const char *timestamp,
+ virJSONObjectPtr properties,
unsigned int flags,
const char *rawstr, const char *str,
void *data ATTRIBUTE_UNUSED)
@@ -980,8 +982,8 @@ static void virLogOutputToSyslogJSON(const char *category, int
priority,
error:
virJSONStringGeneratorFree(g);
- virLogOutputToSyslog(category, priority, funcname, linenr, timestamp, flags,
- rawstr, str, NULL);
+ virLogOutputToSyslog(category, priority, funcname, linenr, timestamp,
+ properties, flags, rawstr, str, NULL);
}
#endif
diff --git a/src/util/logging.h b/src/util/logging.h
index 14b7b7c..c1431ec 100644
--- a/src/util/logging.h
+++ b/src/util/logging.h
@@ -90,6 +90,7 @@ typedef enum {
* @priority: the priority for the message
* @funcname: the function emitting the message
* @linenr: line where the message was emitted
+ * @properties: additional JSON properties to add to the log object, or NULL
* @timestamp: zero terminated string with timestamp of the message
* @flags: flags associated with the message
* @rawstr: the unformatted message to log, zero terminated
@@ -101,6 +102,7 @@ typedef enum {
typedef void (*virLogOutputFunc) (const char *category, int priority,
const char *funcname, long long linenr,
const char *timestamp,
+ virJSONObjectPtr properties,
unsigned int flags,
const char *rawstr, const char *str,
void *data);
diff --git a/tests/testutils.c b/tests/testutils.c
index 6978020..abd8424 100644
--- a/tests/testutils.c
+++ b/tests/testutils.c
@@ -484,6 +484,7 @@ virtTestLogOutput(const char *category ATTRIBUTE_UNUSED,
const char *funcname ATTRIBUTE_UNUSED,
long long lineno ATTRIBUTE_UNUSED,
const char *timestamp,
+ virJSONObjectPtr properties ATTRIBUTE_UNUSED,
unsigned int flags,
const char *rawstr ATTRIBUTE_UNUSED,
const char *str,
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 11/12] Add detailed error information to JSON syslog
When logging an error, don't throw away the detailed information.
Example record when using the syslog/json output (line-wrapped for
readability):
Sep 18 17:03:24 kulicka libvirt: @cee: {"msg":"Domain not found",
"category":"../../src/test/test_driver.c","priority":"err",
"funcname":"testLookupDomainByName","line":1405,
"timestamp":"2012-09-18
15:03:24.314+0000","domain":12,"code":42,
"str1":"Domain not found","str2":""}
The format used in other output destinations (e.g. "syslog", "file")
is
still unchanged.
The "domain" and "code" numbers are part of the libvirt ABI in
<libvirt/virterror.h>; therefore log processing tools can rely on them,
unlike the text log string (which is translated depending on locale,
and may be modified for other reasons as well).
Alternatively, the "domain" and "code" fields could contain strings
instead of numbers, but it's not clear that it's worth it:
Advantages of numbers:
* the numbers are shorter
* the ABI guarantees that the numbers won't change
Disadvantages of strings:
* adding a ABI-stable string mapping for virErrorNumber would result
in additional work each time a new error number is added
(note that virErrorMsg cannot be used for this because it is
translated)
* a change in the string mapping would be less likely to be noticed
The advantage of using strings is more readability, but note that the
"msg" field above already contains a readable description of the
error.
The JSON object is again allocated on the stack to avoid the risk of
allocations falling, and for similarity with
virLogOutputToSyslogJSON().
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/util/logging.c | 3 +++
src/util/virterror.c | 32 +++++++++++++++++++++++++++++---
2 files changed, 32 insertions(+), 3 deletions(-)
diff --git a/src/util/logging.c b/src/util/logging.c
index 987dffc..642d410 100644
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -972,6 +972,9 @@ static void virLogOutputToSyslogJSON(const char *category, int
priority,
goto error;
if (virJSONStringGeneratorAddProperties(g, &json) != 0)
goto error;
+ if (properties != NULL
+ && virJSONStringGeneratorAddProperties(g, properties) != 0)
+ goto error;
json_string = virJSONStringGeneratorFinishObject(g);
if (json_string == NULL)
goto error;
diff --git a/src/util/virterror.c b/src/util/virterror.c
index f93b9f6..9fb60e3 100644
--- a/src/util/virterror.c
+++ b/src/util/virterror.c
@@ -32,8 +32,11 @@
#include "logging.h"
#include "memory.h"
#include "threads.h"
+#include "json.h"
#include "util.h"
+#include "intprops.h"
+
virThreadLocal virLastErr;
virErrorFunc virErrorHandler = NULL; /* global error handler */
@@ -579,8 +582,6 @@ virDispatchError(virConnectPtr conn)
}
}
-
-
/**
* virRaiseErrorFull:
* @filename: filename where error was raised
@@ -614,6 +615,14 @@ virRaiseErrorFull(const char *filename ATTRIBUTE_UNUSED,
int int2,
const char *fmt, ...)
{
+ virJSONObject json;
+ virJSONObjectPair json_pairs[7];
+ virJSONValue json_domain, json_code, json_str1, json_str2, json_str3;
+ virJSONValue json_int1, json_int2;
+ char domain_buf[INT_BUFSIZE_BOUND(domain)];
+ char code_buf[INT_BUFSIZE_BOUND(code)];
+ char int1_buf[INT_BUFSIZE_BOUND(int1)];
+ char int2_buf[INT_BUFSIZE_BOUND(int2)];
int save_errno = errno;
virErrorPtr to;
char *str;
@@ -676,8 +685,25 @@ virRaiseErrorFull(const char *filename ATTRIBUTE_UNUSED,
priority = virErrorLevelPriority(level);
if (virErrorLogPriorityFilter)
priority = virErrorLogPriorityFilter(to, priority);
+ virJSONStaticObjectInitialize (&json, json_pairs);
+ virJSONStaticObjectAppendNumberInt(&json, "domain", &json_domain,
+ domain_buf, sizeof(domain_buf), domain);
+ virJSONStaticObjectAppendNumberInt(&json, "code", &json_code,
+ code_buf, sizeof(code_buf), code);
+ if (str1 != NULL)
+ virJSONStaticObjectAppendString(&json, "str1", &json_str1,
str1);
+ if (str1 != NULL)
+ virJSONStaticObjectAppendString(&json, "str2", &json_str2,
str2);
+ if (str3 != NULL)
+ virJSONStaticObjectAppendString(&json, "str3", &json_str3,
str3);
+ if (int1 != -1)
+ virJSONStaticObjectAppendNumberInt(&json, "int1", &json_int1,
+ int1_buf, sizeof(int1_buf), int1);
+ if (int2 != -1)
+ virJSONStaticObjectAppendNumberInt(&json, "int2", &json_int2,
+ int2_buf, sizeof(int2_buf), int2);
virLogMessage(filename, priority,
- funcname, linenr, NULL,
+ funcname, linenr, &json,
virErrorLogPriorityFilter ? 0 : 1,
"%s", str);
--
1.7.11.4
1:24 p.m.
New subject: [libvirt] [PATCH 12/12] Add a test for the new error reporting mechanism.
Signed-off-by: Miloslav Trmač <mitr(a)redhat.com>
---
src/libvirt_private.syms | 4 +
tests/Makefile.am | 6 +-
tests/errorjsontest.c | 211 +++++++++++++++++++++++++++++++++++++++++++++++
3 files changed, 220 insertions(+), 1 deletion(-)
create mode 100644 tests/errorjsontest.c
diff --git a/src/libvirt_private.syms b/src/libvirt_private.syms
index 0b6068d..1f24de2 100644
--- a/src/libvirt_private.syms
+++ b/src/libvirt_private.syms
@@ -704,6 +704,10 @@ iptablesRemoveUdpInput;
# json.h
+virJSONStringGeneratorAddProperties;
+virJSONStringGeneratorFinishObject;
+virJSONStringGeneratorFree;
+virJSONStringGeneratorInitObject;
virJSONValueArrayAppend;
virJSONValueArrayGet;
virJSONValueArraySize;
diff --git a/tests/Makefile.am b/tests/Makefile.am
index 8dbad97..a46502b 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -138,7 +138,7 @@ test_programs += object-locking
endif
if HAVE_YAJL
-test_programs += jsontest
+test_programs += jsontest errorjsontest
endif
test_programs += networkxml2xmltest
@@ -598,6 +598,10 @@ jsontest_SOURCES = \
jsontest.c testutils.h testutils.c
jsontest_LDADD = $(LDADDS)
+errorjsontest_SOURCES = \
+ errorjsontest.c testutils.h testutils.c
+errorjsontest_LDADD = $(LDADDS)
+
utiltest_SOURCES = \
utiltest.c testutils.h testutils.c
utiltest_LDADD = $(LDADDS)
diff --git a/tests/errorjsontest.c b/tests/errorjsontest.c
new file mode 100644
index 0000000..491306b
--- /dev/null
+++ b/tests/errorjsontest.c
@@ -0,0 +1,211 @@
+#include <config.h>
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+
+#include "internal.h"
+#include "json.h"
+#include "logging.h"
+#include "testutils.h"
+#include "virterror_internal.h"
+
+#define VIR_FROM_THIS VIR_FROM_NONE
+
+/* Ideally we should test the syslog/json output, this tests only the inputs to
+ the logging function. */
+
+struct lastMessage
+{
+ int priority;
+ char *properties;
+};
+
+static void
+lmReset(struct lastMessage *lm)
+{
+ lm->priority = -1;
+ VIR_FREE(lm->properties);
+}
+
+static void
+logOutputToLM(const char *category ATTRIBUTE_UNUSED, int priority,
+ const char *funcname ATTRIBUTE_UNUSED,
+ long long linenr ATTRIBUTE_UNUSED,
+ const char *timestamp ATTRIBUTE_UNUSED,
+ virJSONObjectPtr properties, unsigned int flags,
+ const char *rawstr ATTRIBUTE_UNUSED,
+ const char *str ATTRIBUTE_UNUSED, void *data)
+{
+ struct lastMessage *lm;
+ virJSONStringGeneratorPtr g = NULL;
+ const char *json_string;
+
+ virCheckFlags(VIR_LOG_STACK_TRACE,);
+
+ lm = data;
+ lmReset(lm);
+ /* category (== file name) is not expected to be stable */
+ lm->priority = priority;
+ /* funcname, linenr, timestamp, rawstr, str are not expected to be stable */
+
+ g = virJSONStringGeneratorInitObject();
+ if (g == NULL)
+ goto cleanup;
+ if (properties != NULL
+ && virJSONStringGeneratorAddProperties(g, properties) != 0)
+ goto cleanup;
+ json_string = strdup(virJSONStringGeneratorFinishObject(g));
+ if (json_string == NULL)
+ goto cleanup;
+ lm->properties = strdup(json_string);
+ cleanup:
+ virJSONStringGeneratorFree(g);
+}
+
+static int
+testBasicMessage(const void *data)
+{
+ struct lastMessage *lm;
+ virConnectPtr conn = NULL;
+ virDomainPtr dom = NULL;
+ int ret = -1;
+
+ lm = (struct lastMessage *)data;
+ conn = virConnectOpen("test:///default");
+ if (conn == NULL) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "Could not connect to test URI\n");
+ goto cleanup;
+ }
+
+ dom = virDomainLookupByName(conn, "this_doesnt_exist");
+ if (dom != NULL) {
+ if (virTestGetVerbose())
+ fprintf(stderr,
+ "Should not have connected to nonexistent domain\n");
+ goto cleanup;
+ }
+
+ if (lm->priority != VIR_LOG_ERROR) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "Unexpected priority\n");
+ goto cleanup;
+ }
+
+ ret = 0;
+
+ cleanup:
+ if (dom != NULL)
+ virDomainFree(dom);
+ if (conn != NULL)
+ virConnectClose(conn);
+ return ret;
+}
+
+static int
+testJSONError(const void *data)
+{
+ struct lastMessage *lm;
+ virConnectPtr conn = NULL;
+ virDomainPtr dom = NULL;
+ virJSONValuePtr json = NULL;
+ int ret = -1, val;
+
+ lm = (struct lastMessage *)data;
+ conn = virConnectOpen("test:///default");
+ if (conn == NULL) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "Could not connect to test URI\n");
+ goto cleanup;
+ }
+
+ dom = virDomainLookupByName(conn, "this_doesnt_exist");
+ if (dom != NULL) {
+ if (virTestGetVerbose())
+ fprintf(stderr,
+ "Should not have connected to nonexistent domain\n");
+ goto cleanup;
+ }
+
+ if (lm->properties == NULL) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "Properties missing\n");
+ goto cleanup;
+ }
+ json = virJSONValueFromString(lm->properties);
+ if (json == NULL) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "Error parsing properties\n");
+ goto cleanup;
+ }
+ if (json->type != VIR_JSON_TYPE_OBJECT) {
+ if (virTestGetVerbose())
+ /* logOutputToLM did create an object for us */
+ fprintf(stderr, "Didn't get an object?!\n");
+ goto cleanup;
+ }
+
+ if (virJSONValueObjectGetNumberInt(json, "domain", &val) != 0) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "\"domain\" missing\n");
+ goto cleanup;
+ }
+ if (val != VIR_FROM_TEST) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "Unexpected domain %d (wanted %d)\n", val,
+ VIR_FROM_TEST);
+ goto cleanup;
+ }
+
+ if (virJSONValueObjectGetNumberInt(json, "code", &val) != 0) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "\"code\" missing\n");
+ goto cleanup;
+ }
+ if (val != VIR_ERR_NO_DOMAIN) {
+ if (virTestGetVerbose())
+ fprintf(stderr, "Unexpected code %d (wanted %d)\n", val,
+ VIR_ERR_NO_DOMAIN);
+ goto cleanup;
+ }
+
+ ret = 0;
+
+ cleanup:
+ virJSONValueFree(json);
+ if (dom != NULL)
+ virDomainFree(dom);
+ if (conn != NULL)
+ virConnectClose(conn);
+ return ret;
+}
+
+static void
+testQuietError(void *userData ATTRIBUTE_UNUSED,
+ virErrorPtr error ATTRIBUTE_UNUSED)
+{
+ /* nothing */
+}
+
+static int
+mymain(void)
+{
+ struct lastMessage lm;
+ int ret = 0;
+
+ memset(&lm, 0, sizeof(lm));
+ if (virLogReset() < 0)
+ return EXIT_FAILURE;
+ if (virLogDefineOutput(logOutputToLM, NULL, &lm, 0, 0, NULL, 0) < 0)
+ return EXIT_FAILURE;
+ virSetErrorFunc(NULL, testQuietError);
+ if (virtTestRun("Basic message details", 1, testBasicMessage, &lm) !=
0)
+ ret = -1;
+ if (virtTestRun("JSON error details", 1, testJSONError, &lm) != 0)
+ ret = -1;
+ lmReset(&lm);
+ return (ret == 0) ? EXIT_SUCCESS : EXIT_FAILURE;
+}
+
+VIRT_TEST_MAIN(mymain)
--
1.7.11.4
8:55 a.m.
On Thu, Sep 20, 2012 at 08:23:59PM +0200, Miloslav Trmač wrote:
This patch set adds structured syslog support to libvirt.
In short, the idea is to embed JSON in a syslog record. This format
is used in a new log output type called "syslog/json".
Example "syslog/json" record (line-wrapped for readability):
Sep 20 19:59:40 kulicka libvirt: @cee: {"msg":"libvirt version:
0.10.1",
"category":"../../src/test/test_driver.c","priority":"info",
"funcname":"virLogVMessage","line":769,
"timestamp":"2012-09-20 17:59:40.853+0000"}
compared with existing "syslog" record format:
Sep 20 20:02:24 kulicka libvirt: 5896: info : libvirt version: 0.10.1
This JSON embedding format is defined by the Lumberjack project led
by the major Open Source syslog implementations
(https://fedorahosted.org/lumberjack/). The format is also a base
for a future MITRE CEE standard. Some of the fields are specified
at https://fedorahosted.org/lumberjack/wiki/FieldList , but applications
are free to use whatever fields make sense for them.
The JSON structure makes easy to process logs by programs without writing
code that understands the specific format used by each application,
or using unreliable regexps (https://fedorahosted.org/ceelog/ is a
companion project that allows processing such logs).
Current systems will store and these records unmodified and present them
to users unmodified, but tools (and probably /var/log/messages) will
be able to show only the "msg" field; this allows us to add more detailed
information without worsening the user experience (the example above
already shows added information that is currently being thrown away when
logging to syslog).
While I agree with the effort to try to standardize on metadata to
be collected with log messages, I can't say I like the Lumberjack
design, or this proposed usage in libvirt.
First it is not possible for libvirt to detect whether messages it
sends to syslog() are going to be processed by a syslog daemon which
actually understands the JSON format. This means we can't turn on
use of this JSON format automatically, without causing all existing
distros to get their logs filled with JSON data.
I also don't like the use of JSON for this purpose in the first place.
Application logging facilities really need to be simple, reliable, and
safe to use in any context. For example in between a fork() and execve()
where POSIX requires only use of async signal safe functions. Now I know
that technically speaking syslog() itself is not async signal safe in
general, but the way libvirt uses it for logging makes it safe(ish) in
our case. We can not, however, imagine that JSON (or really any general
JSON library) is going to be async signal safe.
Note, I don't care what data format is used server side for storing
the logs - if syslogd wants to use JSON format, that's fine. Pushing
this format into client applications is what I dislike.
I can see the appeal of JSON in that it allows applications to send
arbitrarily complex nested data structures into the logs, but that
kind of generality for what is IMHO niche usage, really compromises
the common case. What makes it worse is that the standard field list
quoted above actually demonstrates that you don't actually even need
the nesting in many cases, because it shows use of
{"user!name":"bob"}
as an alternative to {"user":{"name":"bob"}}
This patch series goes to great lengths to introduce a whole series of
new JSON APIs in libvirt, to avoid memory allocation from the heap, but
this work is negated by the fact that the YAJL APIs used at the end all
allocate from the heap anyway.
Finally alot of the metadata items listed in the "standard fields" doc
above would be better filled in by the server (from SCM_RIGHTS), than
the client, so that the server can prevent an application from lying
about its uid/gid/pid etc.
By way of comparison the systemd journal APIs deal with all theses
issues.
The actual journald client side logging API is possible to implement
and use without doing any memory allocation at all, in a completely
async signal safe manner, using only socket() + sendmsg() with a
stack allocated iovec[] for storing individual metadata fields to be
sent. The API is soooo simple to use too, for example, a traditional
syslog() call, can be replaced with something like:
sd_journal_send("MESSAGE=%s", str,
"PRIORITY=%d", prio,
"CODE_LINE=%lld", linenr,
"CODE_FUNC=%s", funcname,
...arbirary other key=value metadata...
NULL);
The journald communication uses a new UNIX socket, so apps can automatically
determine whether journald is available and if not, fallback to plain
syslog for old systems. It uses SCM_RIGHTS to automatically fill in a
number of key fields in an unspoofable way. The way the data is transferred
using sendmsg + iovec means there is no need for client applications to
do any kind of magic escaping of special characters in strings.
The journald log processing tools can easily output the log data in many
different formats, including JSON, without the apps having to get involved
in dealing with JSON themselves.
As I mentioned right at the start, I think it is good to have structured
standardized metadata associated with log messages. I just don't think
that the way applications/libraries like libvirt are being asked to
implement this is a good idea. It would be entirely practical for rsyslog
or syslog-ng to provide a client/daemon protocol (+library) that worked
in exactly the same way systemd's journal protocol (+library) do, and then
turn the received raw data into their preferred JSON format on the server.
FYI, I already have a local patch which adds support for journald to
libvirt logging which I am yet to submit, but is so much simpler than
this lumberjack support.
Regards,
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
1:44 p.m.
Hello,
Thanks for the review, and I'm sorry about the late response.
----- Original Message -----
While I agree with the effort to try to standardize on metadata to
be collected with log messages, I can't say I like the Lumberjack
design, or this proposed usage in libvirt.
First it is not possible for libvirt to detect whether messages it
sends to syslog() are going to be processed by a syslog daemon which
actually understands the JSON format. This means we can't turn on
use of this JSON format automatically, without causing all existing
distros to get their logs filled with JSON data.
True, but that's an inevitable consequence of being compatible with the syslog
protocol.[1]
Yes, it does make the question of a default awkward. However, considering that journal
has been switched on by default, and MESSAGE= of everything sent to journal goes to
syslog, is there still a chance of enabling a syslog output by default at the same time?
Doing so would cause each message to appear in syslog twice on systems that have
journald.
I also don't like the use of JSON for this purpose in the first
place.
I'm afraid this is not really open to a change, however I'll try to
explain why I don't see JSON as a problem.
Application logging facilities really need to be simple, reliable,
and
safe to use in any context. For example in between a fork() and execve()
where POSIX requires only use of async signal safe functions. Now I know
that technically speaking syslog() itself is not async signal safe in
general, but the way libvirt uses it for logging makes it safe(ish) in
our case. We can not, however, imagine that JSON (or really any general
JSON library) is going to be async signal safe.
You can also view JSON syntax as a sequence of (fixed field identifier string, field value
with some characters escaped) pairs, which is pretty much the minimum standard for _any_
representation of data in a text format. Choosing JSON was just simpler than trying to
committee-invent something new.[2]
The journal protocol has a similarly inconvenient case of handling \n - it's only not
as noticeable because there are fewer characters to escape, and \n is rarer.
Re: async-signal-safe use: Yes, using a JSON library is more convenient and generally
preferred to writing a yet another JSON encoder, and yes, a typical JSON library will not
be async-signal-safe. However, applications are not required to use all JSON facilities.
An application that wants to log a static string between fork() and execve() can just as
easily log a static JSON string.
If the multi-threaded application wanted to log something dynamic at that inconvenient
time, the application author would have to write string formatting code manually in any
case (sprintf() is also not async signal safe) - and I don't think JSON escaping is
really difficult. Sure, it is more difficult than no escaping, but there needs to be
_some_ escaping if we want to keep the existing syslog transport.
Regarding libvirt specifically, virLogVMessage is rather far from async-signal-safe (e.g.
virVasprintf(), virLogLock()), so this doesn't seem to be a concern for libvirt.
This patch series goes to great lengths to introduce a whole series
of
new JSON APIs in libvirt, to avoid memory allocation from the heap, but
this work is negated by the fact that the YAJL APIs used at the end all
allocate from the heap anyway.
The major problem here was not memory allocation itself (as noted above, other parts of
the log path allocate memory), but possible recursion through virReportOOMError() ->
virLogMessage() and deadlock on virLogMutex. Alocating data on the stack is primarily a
way to avoid OOM, not signal safety.
In retrospect, the virJSON* data structure is unnecessarily complex for the simple list of
key-type-value triples that libvirt actually needs for logging, making the code rather
more complex than necessary. I'll replace that, see the other reply.
Finally alot of the metadata items listed in the "standard
fields" doc
above would be better filled in by the server (from SCM_RIGHTS), than
the client, so that the server can prevent an application from lying
about its uid/gid/pid etc.
rsyslog does add these fields automatically, and the patch set does not add them manually.
This is a bug in the FieldList wiki page, I'll get it fixed.
By way of comparison the systemd journal APIs deal with all theses
issues.
The actual journald client side logging API is possible to implement
and use without doing any memory allocation at all,
virLogOutputToJournald can be implemented like that, but not the libsystemd-journal API:
you'll find a fairly liberal use of alloca() in journal-send.c. If alloca() is
allowed, a JSON formatting API can be implemented without "memory allocation" as
well.
in a completely
async signal safe manner, using only socket() + sendmsg() with a
stack allocated iovec[] for storing individual metadata fields to be
sent.
Looking at how libvirt currently sends journal data, is the /run/systemd/journal/socket
protocol a stable ABI? I can't find anything documenting it within the systemd git
tree, and it is not mentioned at
http://www.freedesktop.org/wiki/Software/systemd/InterfaceStabilityPromise .
The API is soooo simple to use too, for example, a traditional
syslog() call, can be replaced with something like:
sd_journal_send("MESSAGE=%s", str,
"PRIORITY=%d", prio,
"CODE_LINE=%lld", linenr,
"CODE_FUNC=%s", funcname,
...arbirary other key=value metadata...
NULL);
There actually is a library (libumberlog) providing just such a simple API. A
corresponding call is
ul_syslog(prio, str,
"code_line", "%s", service,
"code_func", "%s", auth_method,
... arbitrary other metadata...
NULL);
However, I thought that libvirt would prefer not adding yet another dependency, especially
when the extensions for virRaiseErrorFull require a per-field data structure in any
case.[3]
Mirek
[1] Whether JSON is desired or not also ultimately depends on the final recipient of the
data, not on the system that generates it - an "old" system could generate JSON
that will be forwarded to a log aggregation server.
[2] Especially because the major syslog implementations already supported the JSON format
for other reasons.
[3] And, to be honest, the library does not nicely support the case of virRaiseErrorFull
adding more data. It would be possible, but ugly - we'll make it easier in the
future.
4:47 a.m.
On Mon, Oct 08, 2012 at 02:44:04PM -0400, Miloslav Trmac wrote:
Hello,
Thanks for the review, and I'm sorry about the late response.
----- Original Message -----
> While I agree with the effort to try to standardize on metadata to
> be collected with log messages, I can't say I like the Lumberjack
> design, or this proposed usage in libvirt.
>
> First it is not possible for libvirt to detect whether messages it
> sends to syslog() are going to be processed by a syslog daemon which
> actually understands the JSON format. This means we can't turn on
> use of this JSON format automatically, without causing all existing
> distros to get their logs filled with JSON data.
True, but that's an inevitable consequence of being compatible
with the syslog protocol.[1]
IMHO this is the first of many design flaws in - given that you have
to write all this new code in applications to support the structured
logging, and ideally want new syslog server to get tools to process
the data, it would have been easy to also define a new protocol to
send the data, isntead of trying to hang onto the syslog() API call
or protocol.
Yes, it does make the question of a default awkward. However,
considering that journal has been switched on by default, and
MESSAGE= of everything sent to journal goes to syslog, is there
still a chance of enabling a syslog output by default at the same
time? Doing so would cause each message to appear in syslog twice
on systems that have journald.
Given systemd's fast adoption across a wide range of Linux distros,
in particular the enterprise distros from Red Hat & SUSE, we're
going to have journald support in places where structured logging
really matters, likely expanding to all Linux distros in a reasonably
short period. As such I don't really have a desire to also support
Lumberjack format in libvirt natively. IMHO, system services should
just log to journald and either journald can forward plain messages
to syslog, or a tool can be created which pulls structured log data
out of the journal and formats it in Lumberjack format.
> I also don't like the use of JSON for this purpose in the
first place.
I'm afraid this is not really open to a change, however I'll try to
explain why I don't see JSON as a problem.
> Application logging facilities really need to be simple, reliable, and
> safe to use in any context. For example in between a fork() and execve()
> where POSIX requires only use of async signal safe functions. Now I know
> that technically speaking syslog() itself is not async signal safe in
> general, but the way libvirt uses it for logging makes it safe(ish) in
> our case. We can not, however, imagine that JSON (or really any general
> JSON library) is going to be async signal safe.
You can also view JSON syntax as a sequence of (fixed field identifier string, field
value with some characters escaped) pairs, which is pretty much the minimum standard for
_any_ representation of data in a text format. Choosing JSON was just simpler than trying
to committee-invent something new.[2]
The journal protocol has a similarly inconvenient case of handling \n
it's only not as noticeable because there are fewer characters to escape,
and \n is rarer.
Actually the difference is more significant than that. While, \n is special,
you do not actually have todo any escaping of the \n when sending the data
to the journald. The wire protocol has special handling where you just
specify the length of the string to be sent, and any newlines in it will be
ignored for the purposes of identifying structured field boundaries. Not
having todo any escaping in this way is very good because it means you do
not need to further copy the data to be logged - you can just fill out the
iovec structs in the write way and get zero-copy logging.
Re: async-signal-safe use: Yes, using a JSON library is more
convenien
and generally preferred to writing a yet another JSON encoder, and yes,
a typical JSON library will not be async-signal-safe. However,
applications are not required to use all JSON facilities. An application
that wants to log a static string between fork() and execve() can just as
easily log a static JSON string.
I don't really see logging preformatted static JSON strings as a
satisfactory approach, especially when compared to the way you can
use journald.
Regarding libvirt specifically, virLogVMessage is rather far from
async-signal-safe (e.g. virVasprintf(), virLogLock()), so this doesn't
seem to be a concern for libvirt.
It actually *is* very much a concern for libvirt.
The virLogLock() is in fact designed so that we can safely use it in
between fork+exec(). ALl our code which runs external programs uses our
virCommand/virRun wrappers which synchronize on the logging mutex, so we
can avoid the deadlock issues with mutexes here. Before we did this we
did indeed have problems with deadlocks in our logging code.
We also have also hit problems with the locatime() function not being
async signal safe, so we had to re-write our log message formatting code
to avoid using gmtime/localtime, to avoid deadlocks.
While there are some functions still used which are not technically
async signal safe, this does not mean we don't care. In practice the
reason by asprintf() and friends are not declared safe by POSIX is
that they can malloc() and malloc() is not declared safe. We are
however fortunate that GLibc's malloc is safe. We do still, however,
have a goal to eliminate use of these unsafe functions in the future,
but it is not immediately pressing.
We certainly do *not* want to introduce new code that causes us
further complication in this area.
> By way of comparison the systemd journal APIs deal with all
theses
> issues.
>
> The actual journald client side logging API is possible to implement
> and use without doing any memory allocation at all,
virLogOutputToJournald can be implemented like that, but not the
libsystemd-journal API: you'll find a fairly liberal use of alloca()
in journal-send.c. If alloca() is allowed, a JSON formatting API
can be implemented without "memory allocation" as well.
Yes, that is one of the reasons I ended up writing to the journald
protocol directly. While the current APIs in libsystemd-journal
do require alloca(), it would actually be possible to make add some
functions which avoided this need. This is something I intend to
pursue with systemd devs when I have more free time.
> in a completely
> async signal safe manner, using only socket() + sendmsg() with a
> stack allocated iovec[] for storing individual metadata fields to be
> sent.
Looking at how libvirt currently sends journal data, is the
/run/systemd/journal/socket protocol a stable ABI? I can't
find anything documenting it within the systemd git tree, and
it is not mentioned at
http://www.freedesktop.org/wiki/Software/systemd/InterfaceStabilityPromise .
Hmm, that's a good point actually, I must confirm that.
> The API is soooo simple to use too, for example, a traditional
> syslog() call, can be replaced with something like:
>
> sd_journal_send("MESSAGE=%s", str,
> "PRIORITY=%d", prio,
> "CODE_LINE=%lld", linenr,
> "CODE_FUNC=%s", funcname,
> ...arbirary other key=value metadata...
> NULL);
There actually is a library (libumberlog) providing just such a simple API. A
corresponding call is
> ul_syslog(prio, str,
> "code_line", "%s", service,
> "code_func", "%s", auth_method,
> ... arbitrary other metadata...
> NULL);
However, I thought that libvirt would prefer not adding yet
another dependency, especially when the extensions for
virRaiseErrorFull require a per-field data structure in any
case.[3]
Mostly I'd want to avoid external libraries here due to the async signal
safety issues.
Regards,
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
5:53 a.m.
----- Original Message -----
Given systemd's fast adoption across a wide range of Linux
distros,
in particular the enterprise distros from Red Hat & SUSE, we're
going to have journald support in places where structured logging
really matters, likely expanding to all Linux distros in a reasonably
short period. As such I don't really have a desire to also support
Lumberjack format in libvirt natively. IMHO, system services should
just log to journald and either journald can forward plain messages
to syslog, or a tool can be created which pulls structured log data
out of the journal and formats it in Lumberjack format.
I can live with that; however the libvirt use case I am looking at does require adding
more metadata fields, and I can't see how doing that without memory allocation or
imposing arbitrary limits is possible. Imposing arbitrary limits it is, I guess.
> Re: async-signal-safe use: Yes, using a JSON library is more
convenien
> and generally preferred to writing a yet another JSON encoder, and yes,
> a typical JSON library will not be async-signal-safe. However,
> applications are not required to use all JSON facilities. An application
> that wants to log a static string between fork() and execve() can just as
> easily log a static JSON string.
I don't really see logging preformatted static JSON strings as a
satisfactory approach, especially when compared to the way you can
use journald.
That is either write 150 lines of code, or rely on libsystemd-journal code that was not
promised to be async-signal-safe?
> Regarding libvirt specifically, virLogVMessage is rather far
from
> async-signal-safe (e.g. virVasprintf(), virLogLock()), so this
> doesn't
> seem to be a concern for libvirt.
It actually *is* very much a concern for libvirt.
OK.
Mirek
5:58 a.m.
On Tue, Oct 09, 2012 at 06:53:36AM -0400, Miloslav Trmac wrote:
----- Original Message -----
> Given systemd's fast adoption across a wide range of Linux distros,
> in particular the enterprise distros from Red Hat & SUSE, we're
> going to have journald support in places where structured logging
> really matters, likely expanding to all Linux distros in a reasonably
> short period. As such I don't really have a desire to also support
> Lumberjack format in libvirt natively. IMHO, system services should
> just log to journald and either journald can forward plain messages
> to syslog, or a tool can be created which pulls structured log data
> out of the journal and formats it in Lumberjack format.
I can live with that; however the libvirt use case I am looking at does
require adding more metadata fields, and I can't see how doing that
without memory allocation or imposing arbitrary limits is possible.
Imposing arbitrary limits it is, I guess.
I do have some ideas of adding more metadata too. What sort of pieces
of info are you looking for ? Based on your previous patches, I am
assuming the various virError struct fields at the very least ? Any
others ?
I think arbitrary limits will be ok, since while the number of metadata
fields is theoretically unlimited, in practice I don't see us needing
more than say 15 fields.
Regards,
Daniel
--
|: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org -o- http://virt-manager.org :|
|: http://autobuild.org -o- http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
4461
days inactive
4480
days old
24 comments
4 participants
participants (4)
-
Daniel P. Berrange -
Eric Blake -
Miloslav Trmac -
Miloslav Trmač