luc14n0/glib
1
0
Fork 0
mirror of https://gitlab.gnome.org/GNOME/glib.git synced 2025-10-31 00:12:19 +01:00
Code Issues Packages Projects Releases Wiki Activity

gmessages: Add a structured logging API

Browse Source 
In parallel with g_log(), add a new structured logging API, based around
g_log_structured() and various helper functions which are exposed
publicly to allow programs to build their own logging policies easily,
without having to rewrite a lot of gmessages.c because it’s all
internal.

See the expanded documentation at the top of gmessages.c for some
rationale. See the g_log_structured() documentation for some example
code.

https://bugzilla.gnome.org/show_bug.cgi?id=744456
This commit is contained in:
Philip Withnall
2016-02-20 12:34:29 +00:00
committed by Matthias Clasen
parent 8345a42cd0
commit 052eaf24f7
5 changed files with 1118 additions and 4 deletions
Download Patch File Download Diff File Expand all files Collapse all files

15
configure.ac
View File

@@ -1730,6 +1730,21 @@ if test x$have_libelf = xyes; then
AC_DEFINE(HAVE_LIBELF, 1, [Define if libelf is available])
fi
dnl *************************
dnl *** check for systemd ***
dnl *************************
AC_ARG_ENABLE([libsystemd],
[AS_HELP_STRING([--disable-libsystemd],
[build without libsystemd support])])
AS_IF([test "$enable_libsystemd" != "no"],[
PKG_CHECK_MODULES([LIBSYSTEMD], [libsystemd],
[have_libsystemd=yes], [have_libsystemd=no])
])
AS_IF([test "$have_libsystemd" = "yes"],[
AC_DEFINE([HAVE_LIBSYSTEMD],[1],[Define if libsystemd is available])
])
dnl ****************************************
dnl *** platform dependent source checks ***
dnl ****************************************

4
glib/Makefile.am
View File

@@ -350,8 +350,8 @@ pcre_lib = pcre/libpcre.la
pcre_inc =
endif
libglib_2_0_la_CFLAGS = $(AM_CFLAGS) $(GLIB_HIDDEN_VISIBILITY_CFLAGS)
libglib_2_0_la_LIBADD = libcharset/libcharset.la $(printf_la) @GIO@ @GSPAWN@ @PLATFORMDEP@ @ICONV_LIBS@ @G_LIBS_EXTRA@ $(pcre_lib) $(G_THREAD_LIBS_EXTRA) $(G_THREAD_LIBS_FOR_GTHREAD)
libglib_2_0_la_CFLAGS = $(AM_CFLAGS) $(GLIB_HIDDEN_VISIBILITY_CFLAGS) $(LIBSYSTEMD_CFLAGS)
libglib_2_0_la_LIBADD = libcharset/libcharset.la $(printf_la) @GIO@ @GSPAWN@ @PLATFORMDEP@ @ICONV_LIBS@ @G_LIBS_EXTRA@ $(pcre_lib) $(G_THREAD_LIBS_EXTRA) $(G_THREAD_LIBS_FOR_GTHREAD) $(LIBSYSTEMD_LIBS)
libglib_2_0_la_DEPENDENCIES = libcharset/libcharset.la $(printf_la) @GIO@ @GSPAWN@ @PLATFORMDEP@ $(glib_win32_res) $(glib_def)
libglib_2_0_la_LDFLAGS = $(GLIB_LINK_FLAGS) \

812
glib/gmessages.c
View File

@@ -43,6 +43,47 @@
* generally considered undefined after one of these checks fails.
* They are not intended for normal control flow, only to give a
* perhaps-helpful warning before giving up.
*
* Structured logging output is supported using g_log_structured(). This differs
* from the traditional g_log() API in that log messages are handled as a
* collection of key–value pairs representing individual pieces of information,
* rather than as a single string containing all the information in an arbitrary
* format.
*
* The support for structured logging was motivated by the following needs (some
* of which were supported previously; others weren’t):
* * Support for multiple logging levels.
* * Structured log support with the ability to add `MESSAGE_ID`s (see
* g_log_structured()).
* * Moving the responsibility for filtering log messages from the program to
* the log viewer — instead of libraries and programs installing log handlers
* (with g_log_set_handler()) which filter messages before output, all log
* messages are outputted, and the log viewer program (such as `journalctl`)
* must filter them. This is based on the idea that bugs are sometimes hard
* to reproduce, so it is better to log everything possible and then use
* tools to analyse the logs than it is to not be able to reproduce a bug to
* get additional log data. Code which uses logging in performance-critical
* sections should compile out the g_log_structured() calls in
* release builds, and compile them in in debugging builds.
* * A single writer function which handles all log messages in a process, from
* all libraries and program code; rather than multiple log handlers with
* poorly defined interactions between them. This allows a program to easily
* change its logging policy by changing the writer function, for example to
* log to an additional location or to change what logging output fallbacks
* are used. The log writer functions provided by GLib are exposed publicly
* so they can be used from programs’ log writers. This allows log writer
* policy and implementation to be kept separate.
* * If a library wants to add standard information to all of its log messages
* (such as library state) or to redact private data (such as passwords or
* network credentials), it should use a wrapper function around its
* g_log_structured() calls or implement that in the single log writer
* function.
* * If a program wants to pass context data from a g_log_structured() call to
* its log writer function so that, for example, it can use the correct
* server connection to submit logs to, that user data can be passed as a
* zero-length #GLogField to g_log_structured_array().
* * Colour output needed to be supported on the terminal, to make reading
* through logs easier.
*/
#include "config.h"
@@ -56,6 +97,7 @@
#include <errno.h>
#include "glib-init.h"
#include "galloca.h"
#include "gbacktrace.h"
#include "gcharset.h"
#include "gconvert.h"
@@ -79,6 +121,11 @@
# include <windows.h>
#endif
#ifdef HAVE_LIBSYSTEMD
#include <sys/uio.h>
#include <systemd/sd-journal.h>
#endif
/**
* SECTION:messages
@@ -299,10 +346,14 @@ static GLogDomain *g_log_domains = NULL;
static GPrintFunc glib_print_func = NULL;
static GPrintFunc glib_printerr_func = NULL;
static GPrivate g_log_depth;
static GPrivate g_log_structured_depth;
static GLogFunc default_log_func = g_log_default_handler;
static gpointer default_log_data = NULL;
static GTestLogFatalFunc fatal_log_func = NULL;
static gpointer fatal_log_data;
static GLogWriterFunc log_writer_func = g_log_writer_default;
static gpointer log_writer_user_data = NULL;
static GDestroyNotify log_writer_user_data_free = NULL;
/* --- functions --- */
@@ -376,6 +427,18 @@ write_string (FILE *stream,
fputs (string, stream);
}
static void
write_string_sized (FILE *stream,
const gchar *string,
gssize length)
{
/* Is it nul-terminated? */
if (length < 0)
write_string (stream, string);
else
fwrite (string, 1, length, stream);
}
static GLogDomain*
g_log_find_domain_L (const gchar *log_domain)
{
@@ -475,6 +538,14 @@ g_log_domain_get_handler_L (GLogDomain *domain,
* the `G_DEBUG` environment variable (see
* [Running GLib Applications](glib-running.html)).
*
* Libraries should not call this function, as it affects all messages logged
* by a process, including those from other libraries.
*
* Structured log messages (using g_log_structured() and
* g_log_structured_array()) are fatal only if the default log writer is used;
* otherwise it is up to the writer function to determine which log messages
* are fatal.
*
* Returns: the old fatal mask
*/
GLogLevelFlags
@@ -507,6 +578,11 @@ g_log_set_always_fatal (GLogLevelFlags fatal_mask)
* Sets the log levels which are fatal in the given domain.
* %G_LOG_LEVEL_ERROR is always fatal.
*
* This has no effect on structured log messages (using g_log_structured() or
* g_log_structured_array()). To change the fatal behaviour for specific log
* messages, programs must install a custom log writer function using
* g_log_set_writer_func().
*
* Returns: the old fatal mask for the log domain
*/
GLogLevelFlags
@@ -518,7 +594,7 @@ g_log_set_fatal_mask (const gchar *log_domain,
if (!log_domain)
log_domain = "";
/* force errors to be fatal */
fatal_mask |= G_LOG_LEVEL_ERROR;
/* remove bogus flag */
@@ -695,6 +771,11 @@ g_log_set_default_handler (GLogFunc log_func,
*
* This handler has no effect on g_error messages.
*
* This handler also has no effect on structured log messages (using
* g_log_structured() or g_log_structured_array()). To change the fatal
* behaviour for specific log messages, programs must install a custom log
* writer function using g_log_set_writer_func().
*
* Since: 2.22
**/
void
@@ -1128,6 +1209,733 @@ g_log (const gchar *log_domain,
va_end (args);
}
/* Return value must be 1 byte long (plus nul byte).
* Reference: http://man7.org/linux/man-pages/man3/syslog.3.html#DESCRIPTION
*/
static const gchar *
log_level_to_priority (GLogLevelFlags log_level)
{
if (log_level & G_LOG_LEVEL_ERROR)
return "3";
else if (log_level & G_LOG_LEVEL_CRITICAL)
return "4";
else if (log_level & G_LOG_LEVEL_WARNING)
return "4";
else if (log_level & G_LOG_LEVEL_MESSAGE)
return "5";
else if (log_level & G_LOG_LEVEL_INFO)
return "6";
else if (log_level & G_LOG_LEVEL_DEBUG)
return "7";
/* Default to LOG_NOTICE for custom log levels. */
return "5";
}
static FILE *
log_level_to_file (GLogLevelFlags log_level)
{
if (log_level & (G_LOG_LEVEL_ERROR | G_LOG_LEVEL_CRITICAL |
G_LOG_LEVEL_WARNING | G_LOG_LEVEL_MESSAGE))
return stderr;
else
return stdout;
}
/**
* g_log_structured:
* @log_domain: log domain, usually %G_LOG_DOMAIN
* @log_level: log level, either from #GLogLevelFlags, or a user-defined
* level
* @format: message format, in printf() style
* @...: parameters to insert into the format string, followed by key–value
* pairs of structured data to add to the log message, terminated with a
* %NULL
*
* Log a message with structured data. The message will be passed through to the
* log writer set by the application using g_log_set_writer_func(). If the
* message is fatal (i.e. its log level is %G_LOG_LEVEL_ERROR), the program will
* be aborted at the end of this function.
*
* The structured data is provided as key–value pairs, where keys are UTF-8
* strings, and values are arbitrary pointers — typically pointing to UTF-8
* strings, but that is not a requirement. To pass binary (non-nul-terminated)
* structured data, use g_log_structured_array(). The keys for structured data
* should follow the [systemd journal
* fields](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html)
* specification.
*
* The @log_domain will be converted into a `GLIB_DOMAIN` field. @log_level will
* be converted into a `PRIORITY` field. @format will have its placeholders
* substituted for the provided values and be converted into a `MESSAGE` field.
*
* Other fields you may commonly want to pass into this function:
*
* * [`MESSAGE_ID`](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html#MESSAGE_ID=)
* * [`CODE_FILE`](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html#CODE_FILE=)
* * [`CODE_LINE`](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html#CODE_LINE=)
* * [`CODE_FUNC`](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html#CODE_FUNC=)
* * [`ERRNO`](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html#ERRNO=)
*
* Note that `CODE_FILE`, `CODE_LINE` and `CODE_FUNC` are automatically set by
* the logging macros, g_debug_structured(), G_DEBUG_HERE(),
* g_message_structured(), g_warning_structured(), g_critical_structured() and
* g_error_structured().
*
* For example:
* ```
* g_log_structured (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG,
* "This is a debug message about pointer %p and integer %u.",
* some_pointer, some_integer,
* "MESSAGE_ID", "06d4df59e6c24647bfe69d2c27ef0b4e",
* "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
* NULL);
* ```
*
* Note that each `MESSAGE_ID` **must** be [uniquely and randomly
* generated](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html#MESSAGE_ID=).
* If adding a `MESSAGE_ID`, consider shipping a [message
* catalog](https://www.freedesktop.org/wiki/Software/systemd/catalog/) with
* your software.
*
* To pass a user data pointer to the log writer function which is specific to
* this logging call, you must use g_log_structured_array() and pass the pointer
* as a field with #GLogField.length set to zero, otherwise it will be
* interpreted as a string.
*
* For example:
* ```
* const GLogField fields[] = {
* { "MESSAGE", "This is a debug message.", -1 },
* { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
* { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 },
* { "MY_APPLICATION_STATE", state_object, 0 },
* };
* g_log_structured_array (G_LOG_LEVEL_DEBUG, fields, G_N_ELEMENTS (fields));
* ```
*
* Note also that, even if no structured fields are specified, the argument list
* **must** be %NULL-terminated.
*
* The default writer function for `stdout` and `stderr` will automatically
* append a new-line character to the @format, so you should not add one
* manually.
*
* Since: 2.50
*/
void
g_log_structured (const gchar *log_domain,
GLogLevelFlags log_level,
const gchar *format,
...)
{
va_list args, field_args;
gchar buffer[1025], *message_allocated = NULL;
const gchar *message, *priority;
gpointer p;
gsize n_fields, i;
GLogField *fields = NULL;
/* Format the message. */
va_start (args, format);
if (log_level & G_LOG_FLAG_RECURSION)
{
/* we use a stack buffer of fixed size, since we're likely
* in an out-of-memory situation
*/
gsize size G_GNUC_UNUSED;
size = _g_vsnprintf (buffer, sizeof (buffer), format, args);
message = buffer;
}
else
{
message = message_allocated = g_strdup_vprintf (format, args);
}
/* Format the priority. */
priority = log_level_to_priority (log_level);
/* Work out how many fields we have. */
va_copy (field_args, args);
for (p = va_arg (args, gchar *), n_fields = 0;
p != NULL;
p = va_arg (args, gchar *), n_fields++)
va_arg (args, gpointer);
/* Add MESSAGE, PRIORITY and GLIB_DOMAIN. */
n_fields += 3;
/* Build the fields array. */
fields = g_alloca (sizeof (GLogField) * n_fields);
fields[0].key = "MESSAGE";
fields[0].value = message;
fields[0].length = -1;
fields[1].key = "PRIORITY";
fields[1].value = priority;
fields[1].length = 1; /* byte */
fields[2].key = "GLIB_DOMAIN";
fields[2].value = log_domain;
fields[2].length = -1;
for (p = va_arg (field_args, gchar *), i = 3;
p != NULL;
p = va_arg (field_args, gchar *), i++)
{
GLogField *field = &fields[i];
const gchar *key = p;
gconstpointer value = va_arg (field_args, gpointer);
/* These are already provided as @format, @log_level and @log_domain. */
g_warn_if_fail (g_strcmp0 (key, "MESSAGE") != 0);
g_warn_if_fail (g_strcmp0 (key, "PRIORITY") != 0);
g_warn_if_fail (g_strcmp0 (key, "GLIB_DOMAIN") != 0);
field->key = key;
field->value = value;
field->length = -1;
}
/* Log it. */
g_log_structured_array (log_level, fields, n_fields);
g_free (message_allocated);
va_end (field_args);
va_end (args);
}
static GLogWriterOutput _g_log_writer_fallback (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data);
/**
* g_log_structured_array:
* @log_level: log level, either from #GLogLevelFlags, or a user-defined
* level
* @fields: (array length=n_fields): key–value pairs of structured data to add
* to the log message
* @n_fields: number of elements in the @fields array
*
* Log a message with structured data. The message will be passed through to the
* log writer set by the application using g_log_set_writer_func(). If the
* message is fatal (i.e. its log level is %G_LOG_LEVEL_ERROR), the program will
* be aborted at the end of this function.
*
* See g_log_structured() for more documentation.
*
* This assumes that @log_level is already present in @fields (typically as the
* `PRIORITY` field).
*
* Since: 2.50
*/
void
g_log_structured_array (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields)
{
GLogWriterFunc writer_func;
gpointer writer_user_data;
gboolean recursion;
guint depth;
if (n_fields == 0)
return;
/* Check for recursion and look up the writer function. */
depth = GPOINTER_TO_UINT (g_private_get (&g_log_structured_depth));
recursion = (depth > 0);
g_mutex_lock (&g_messages_lock);
writer_func = recursion ? _g_log_writer_fallback : log_writer_func;
writer_user_data = log_writer_user_data;
g_mutex_unlock (&g_messages_lock);
/* Write the log entry. */
g_private_set (&g_log_structured_depth, GUINT_TO_POINTER (++depth));
g_assert (writer_func != NULL);
writer_func (log_level, fields, n_fields, writer_user_data);
g_private_set (&g_log_structured_depth, GUINT_TO_POINTER (--depth));
/* Abort if the message was fatal. */
if (log_level & G_LOG_FATAL_MASK)
_g_log_abort (!(log_level & G_LOG_FLAG_RECURSION));
}
/**
* g_log_set_writer_func:
* @func: log writer function, which must not be %NULL
* @user_data: (closure func): user data to pass to @func
* @user_data_free: (destroy func): function to free @user_data once it’s
* finished with, if non-%NULL
*
* Set a writer function which will be called to format and write out each log
* message. Each program should set a writer function, or the default writer
* (g_log_writer_default()) will be used.
*
* Libraries **must not** call this function — only programs are allowed to
* install a writer function, as there must be a single, central point where
* log messages are formatted and outputted.
*
* There can only be one writer function. It is an error to set more than one.
*
* Since: 2.50
*/
void
g_log_set_writer_func (GLogWriterFunc func,
gpointer user_data,
GDestroyNotify user_data_free)
{
g_return_if_fail (func != NULL);
g_return_if_fail (log_writer_func == g_log_writer_default);
g_mutex_lock (&g_messages_lock);
log_writer_func = func;
log_writer_user_data = user_data;
log_writer_user_data_free = user_data_free;
g_mutex_unlock (&g_messages_lock);
}
/**
* g_log_writer_is_journald:
* @output_fd: output file descriptor to check
*
* Check whether the given @output_fd file descriptor is a connection to the
* systemd journal, or something else (like a log file or `stdout` or
* `stderr`).
*
* Returns: %TRUE if @output_fd points to the journal, %FALSE otherwise
* Since: 2.50
*/
gboolean
g_log_writer_is_journald (gint output_fd)
{
#ifdef HAVE_LIBSYSTEMD
/* FIXME: Use the new journal API for detecting whether we’re writing to the
* journal. See: https://github.com/systemd/systemd/issues/2473
*/
static gsize initialized;
static gboolean stdout_is_socket;
g_return_val_if_fail (output_fd >= 0, FALSE);
if (g_once_init_enter (&initialized))
{
guint64 pid = (guint64) getpid ();
char *fdpath = g_strdup_printf ("/proc/%" G_GUINT64_FORMAT "/fd/%d",
pid, output_fd);
char buf[1024];
ssize_t bytes_read;
if ((bytes_read = readlink (fdpath, buf, sizeof(buf) - 1)) != -1)
{
buf[bytes_read] = '\0';
stdout_is_socket = g_str_has_prefix (buf, "socket:");
}
else
stdout_is_socket = FALSE;
g_free (fdpath);
g_once_init_leave (&initialized, TRUE);
}
return stdout_is_socket;
#else /* if !HAVE_LIBSYSTEMD */
return FALSE;
#endif
}
static void escape_string (GString *string);
/**
* g_log_writer_format_fields:
* @log_level: log level, either from #GLogLevelFlags, or a user-defined
* level
* @fields: (array length=n_fields): key–value pairs of structured data forming
* the log message
* @n_fields: number of elements in the @fields array
*
* Format a structured log message as a string suitable for outputting to the
* terminal (or elsewhere). This will include the values of all fields it knows
* how to interpret, which includes `MESSAGE` and `GLIB_DOMAIN` (see the
* documentation for g_log_structured()). It does not include values from
* unknown fields.
*
* The returned string does **not** have a trailing new-line character. It is
* encoded in the character set of the current locale, which is not necessarily
* UTF-8.
*
* Returns: (transfer full): string containing the formatted log message, in
* the character set of the current locale
* Since: 2.50
*/
gchar *
g_log_writer_format_fields (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields)
{
gsize i;
const gchar *message = NULL;
const gchar *log_domain = NULL;
gchar level_prefix[STRING_BUFFER_SIZE];
GString *gstring;
/* Extract some common fields. */
for (i = 0; (message == NULL || log_domain == NULL) && i < n_fields; i++)
{
const GLogField *field = &fields[i];
if (g_strcmp0 (field->key, "MESSAGE") == 0)
message = field->value;
else if (g_strcmp0 (field->key, "GLIB_DOMAIN") == 0)
log_domain = field->value;
}
/* Format things. */
mklevel_prefix (level_prefix, log_level);
gstring = g_string_new (NULL);
if (log_level & ALERT_LEVELS)
g_string_append (gstring, "\n");
if (!log_domain)
g_string_append (gstring, "** ");
if ((g_log_msg_prefix & (log_level & G_LOG_LEVEL_MASK)) ==
(log_level & G_LOG_LEVEL_MASK))
{
const gchar *prg_name = g_get_prgname ();
gulong pid = getpid ();
if (prg_name == NULL)
g_string_append_printf (gstring, "(process:%lu): ", pid);
else
g_string_append_printf (gstring, "(%s:%lu): ", prg_name, pid);
}
if (log_domain != NULL)
{
g_string_append (gstring, log_domain);
g_string_append_c (gstring, '-');
}
g_string_append (gstring, level_prefix);
g_string_append (gstring, ": ");
if (message == NULL)
{
g_string_append (gstring, "(NULL) message");
}
else
{
GString *msg;
const gchar *charset;
msg = g_string_new (message);
escape_string (msg);
if (g_get_charset (&charset))
{
/* charset is UTF-8 already */
g_string_append (gstring, msg->str);
}
else
{
gchar *lstring = strdup_convert (msg->str, charset);
g_string_append (gstring, lstring);
g_free (lstring);
}
g_string_free (msg, TRUE);
}
return g_string_free (gstring, FALSE);
}
/**
* g_log_writer_journald:
* @log_level: log level, either from #GLogLevelFlags, or a user-defined
* level
* @fields: (array length=n_fields): key–value pairs of structured data forming
* the log message
* @n_fields: number of elements in the @fields array
* @user_data: user data passed to g_log_set_writer_func()
*
* Format a structured log message and send it to the systemd journal as a set
* of key–value pairs. All fields are sent to the journal, but if a field has
* length zero (indicating program-specific data) then only its key will be
* sent.
*
* This is suitable for use as a #GLogWriterFunc.
*
* If GLib has been compiled without systemd support, this function is still
* defined, but will always return %G_LOG_WRITER_UNHANDLED.
*
* Returns: %G_LOG_WRITER_HANDLED on success, %G_LOG_WRITER_UNHANDLED otherwise
* Since: 2.50
*/
GLogWriterOutput
g_log_writer_journald (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data)
{
#ifdef HAVE_LIBSYSTEMD
gsize i;
struct iovec *pairs;
gint retval;
g_return_val_if_fail (fields != NULL, G_LOG_WRITER_UNHANDLED);
g_return_val_if_fail (n_fields > 0, G_LOG_WRITER_UNHANDLED);
/* According to systemd.journal-fields(7), the journal allows fields in any
* format (including arbitrary binary), but expects text fields to be UTF-8.
* This is great, because we require input strings to be in UTF-8, so no
* conversion is necessary and we don’t need to care about the current
* locale’s character set.
*/
pairs = g_alloca (sizeof (struct iovec) * n_fields);
for (i = 0; i < n_fields; i++)
{
guint8 *buf = NULL;
gsize key_length;
gsize value_length;
/* Build the iovec for this field. */
key_length = strlen (fields[i].key);
value_length =
(fields[i].length < 0) ? strlen (fields[i].value) : fields[i].length;
buf = g_malloc (key_length + 1 + value_length + 1);
pairs[i].iov_base = buf;
pairs[i].iov_len = key_length + 1 + value_length;
strncpy ((char *) buf, fields[i].key, key_length);
buf[key_length] = '=';
memcpy ((char *) buf + key_length + 1, fields[i].value, value_length);
buf[key_length + 1 + value_length] = '\0';
}
retval = sd_journal_sendv (pairs, n_fields);
for (i = 0; i < n_fields; i++)
g_free (pairs[i].iov_base);
return (retval == 0) ? G_LOG_WRITER_HANDLED : G_LOG_WRITER_UNHANDLED;
#else /* if !HAVE_LIBSYSTEMD */
return G_LOG_WRITER_UNHANDLED;
#endif
}
/**
* g_log_writer_standard_streams:
* @log_level: log level, either from #GLogLevelFlags, or a user-defined
* level
* @fields: (array length=n_fields): key–value pairs of structured data forming
* the log message
* @n_fields: number of elements in the @fields array
* @user_data: user data passed to g_log_set_writer_func()
*
* Format a structured log message and print it to either `stdout` or `stderr`,
* depending on its log level. %G_LOG_LEVEL_INFO and %G_LOG_LEVEL_DEBUG messages
* are sent to `stdout`; all other log levels are sent to `stderr`. Only fields
* which are understood by this function are included in the formatted string
* which is printed.
*
* A trailing new-line character is added to the log message when it is printed.
*
* This is suitable for use as a #GLogWriterFunc.
*
* Returns: %G_LOG_WRITER_HANDLED on success, %G_LOG_WRITER_UNHANDLED otherwise
* Since: 2.50
*/
GLogWriterOutput
g_log_writer_standard_streams (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data)
{
FILE *stream;
gchar *out = NULL; /* in the current locale’s character set */
g_return_val_if_fail (fields != NULL, G_LOG_WRITER_UNHANDLED);
g_return_val_if_fail (n_fields > 0, G_LOG_WRITER_UNHANDLED);
stream = log_level_to_file (log_level);
out = g_log_writer_format_fields (log_level, fields, n_fields);
_g_fprintf (stream, "%s\n", out);
g_free (out);
return G_LOG_WRITER_HANDLED;
}
/**
* g_log_writer_default:
* @log_level: log level, either from #GLogLevelFlags, or a user-defined
* level
* @fields: (array length=n_fields): key–value pairs of structured data forming
* the log message
* @n_fields: number of elements in the @fields array
* @user_data: user data passed to g_log_set_writer_func()
*
* Format a structured log message and output it to the default log destination
* for the platform. On Linux, this is typically the systemd journal, falling
* back to `stdout` or `stderr` if running from the terminal or if output is
* being redirected to a file.
*
* Support for other platform-specific logging mechanisms may be added in
* future. Distributors of GLib may modify this function to impose their own
* (documented) platform-specific log writing policies.
*
* This is suitable for use as a #GLogWriterFunc, and is the default writer used
* if no other is set using g_log_set_writer_func().
*
* Returns: %G_LOG_WRITER_HANDLED on success, %G_LOG_WRITER_UNHANDLED otherwise
* Since: 2.50
*/
GLogWriterOutput
g_log_writer_default (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data)
{
g_return_val_if_fail (fields != NULL, G_LOG_WRITER_UNHANDLED);
g_return_val_if_fail (n_fields > 0, G_LOG_WRITER_UNHANDLED);
/* Disable debug message output unless specified in G_MESSAGES_DEBUG. */
if (!(log_level & DEFAULT_LEVELS) && !(log_level >> G_LOG_LEVEL_USER_SHIFT))
{
const gchar *domains, *log_domain = NULL;
gsize i;
domains = g_getenv ("G_MESSAGES_DEBUG");
if ((log_level & INFO_LEVELS) == 0 ||
domains == NULL)
return G_LOG_WRITER_HANDLED;
for (i = 0; i < n_fields; i++)
{
if (g_strcmp0 (fields[i].key, "GLIB_DOMAIN") == 0)
{
log_domain = fields[i].value;
break;
}
}
if (strcmp (domains, "all") != 0 &&
(log_domain == NULL || !strstr (domains, log_domain)))
return G_LOG_WRITER_HANDLED;
}
/* Mark messages as fatal if they have a level set in
* g_log_set_always_fatal().
*/
if (log_level & g_log_always_fatal)
log_level |= G_LOG_FLAG_FATAL;
/* Try logging to the systemd journal as first choice. */
if (g_log_writer_is_journald (fileno (stderr)) &&
g_log_writer_journald (log_level, fields, n_fields, user_data) ==
G_LOG_WRITER_HANDLED)
goto handled;
/* FIXME: Add support for the Windows log. */
if (g_log_writer_standard_streams (log_level, fields, n_fields, user_data) ==
G_LOG_WRITER_HANDLED)
goto handled;
return G_LOG_WRITER_UNHANDLED;
handled:
/* Abort if the message was fatal. */
if (log_level & G_LOG_FLAG_FATAL)
{
#ifdef G_OS_WIN32
if (!g_test_initialized ())
{
gchar *locale_msg = NULL;
locale_msg = g_locale_from_utf8 (fatal_msg_buf, -1, NULL, NULL, NULL);
MessageBox (NULL, locale_msg, NULL,
MB_ICONERROR | MB_SETFOREGROUND);
g_free (locale_msg);
}
#endif /* !G_OS_WIN32 */
_g_log_abort (!(log_level & G_LOG_FLAG_RECURSION));
}
return G_LOG_WRITER_HANDLED;
}
static GLogWriterOutput
_g_log_writer_fallback (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data)
{
FILE *stream;
gsize i;
/* we cannot call _any_ GLib functions in this fallback handler,
* which is why we skip UTF-8 conversion, etc.
* since we either recursed or ran out of memory, we're in a pretty
* pathologic situation anyways, what we can do is giving the
* the process ID unconditionally however.
*/
stream = log_level_to_file (log_level);
for (i = 0; i < n_fields; i++)
{
const GLogField *field = &fields[i];
/* Only print fields we definitely recognise, otherwise we could end up
* printing a random non-string pointer provided by the user to be
* interpreted by their writer function.
*/
if (strcmp (field->key, "MESSAGE") != 0 &&
strcmp (field->key, "MESSAGE_ID") != 0 &&
strcmp (field->key, "PRIORITY") != 0 &&
strcmp (field->key, "CODE_FILE") != 0 &&
strcmp (field->key, "CODE_LINE") != 0 &&
strcmp (field->key, "CODE_FUNC") != 0 &&
strcmp (field->key, "ERRNO") != 0 &&
strcmp (field->key, "SYSLOG_FACILITY") != 0 &&
strcmp (field->key, "SYSLOG_IDENTIFIER") != 0 &&
strcmp (field->key, "SYSLOG_PID") != 0 &&
strcmp (field->key, "GLIB_DOMAIN") != 0)
continue;
write_string (stream, field->key);
write_string (stream, "=");
write_string_sized (stream, field->value, field->length);
}
#ifndef G_OS_WIN32
{
gchar pid_string[FORMAT_UNSIGNED_BUFSIZE];
format_unsigned (pid_string, getpid (), 10);
write_string (stream, "_PID=");
write_string (stream, pid_string);
}
#endif
return G_LOG_WRITER_HANDLED;
}
/**
* g_return_if_fail_warning: (skip)
* @log_domain: (nullable):
@@ -1472,7 +2280,7 @@ g_log_default_handler (const gchar *log_domain,
if ((g_log_msg_prefix & (log_level & G_LOG_LEVEL_MASK)) == (log_level & G_LOG_LEVEL_MASK))
{
const gchar *prg_name = g_get_prgname ();
if (!prg_name)
g_string_append_printf (gstring, "(process:%lu): ", (gulong)getpid ());
else

261
glib/gmessages.h
View File

@@ -30,6 +30,7 @@
#endif
#include <stdarg.h>
#include <stdio.h>
#include <glib/gtypes.h>
#include <glib/gmacros.h>
@@ -113,6 +114,266 @@ GLogLevelFlags g_log_set_fatal_mask (const gchar *log_domain,
GLIB_AVAILABLE_IN_ALL
GLogLevelFlags g_log_set_always_fatal (GLogLevelFlags fatal_mask);
/* Structured logging mechanism. */
/**
* GLogWriterOutput:
* @G_LOG_WRITER_HANDLED: Log writer has handled the log entry.
* @G_LOG_WRITER_UNHANDLED: Log writer could not handle the log entry.
*
* Return values from #GLogWriterFuncs to indicate whether the given log entry
* was successfully handled by the writer, or whether there was an error in
* handling it (and hence a fallback writer should be used).
*
* If a #GLogWriterFunc ignores a log entry, it should return
* %G_LOG_WRITER_HANDLED.
*
* Since: 2.50
*/
typedef enum
{
G_LOG_WRITER_HANDLED = 1,
G_LOG_WRITER_UNHANDLED = 0,
} GLogWriterOutput;
/**
* GLogField:
* @key: field name (UTF-8 string)
* @value: field value (arbitrary bytes)
* @length: length of @value, in bytes, or -1 if it is nul-terminated
*
* Structure representing a single field in a structured log entry. See
* g_log_structured() for details.
*
* Log fields may contain arbitrary values, including binary with embedded nul
* bytes. If the field contains a string, the string must be UTF-8 encoded and
* have a trailing nul byte. Otherwise, @length must be set to a non-negative
* value.
*
* Since: 2.50
*/
typedef struct
{
const gchar *key;
gconstpointer value;
gssize length;
} GLogField;
/**
* GLogWriterFunc:
* @log_level: log level of the message
* @fields: (array length=n_fields): fields forming the message
* @n_fields: number of @fields
* @user_data: user data passed to g_log_set_writer_func()
*
* Writer function for log entries. A log entry is a collection of one or more
* #GLogFields, using the standard [field names from journal
* specification](https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html).
* See g_log_structured() for more information.
*
* Writer functions must ignore fields which they do not recognise, unless they
* can write arbitrary binary output, as field values may be arbitrary binary.
*
* @log_level is guaranteed to be included in @fields as the `PRIORITY` field,
* but is provided separately for convenience of deciding whether or where to
* output the log entry.
*
* Returns: %G_LOG_WRITER_HANDLED if the log entry was handled successfully;
* %G_LOG_WRITER_UNHANDLED otherwise
* Since: 2.50
*/
typedef GLogWriterOutput (*GLogWriterFunc) (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data);
GLIB_AVAILABLE_IN_2_50
void g_log_structured (const gchar *log_domain,
GLogLevelFlags log_level,
const gchar *format,
...)
G_GNUC_NULL_TERMINATED;
GLIB_AVAILABLE_IN_2_50
void g_log_structured_array (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields);
GLIB_AVAILABLE_IN_2_50
void g_log_set_writer_func (GLogWriterFunc func,
gpointer user_data,
GDestroyNotify user_data_free);
GLIB_AVAILABLE_IN_2_50
gboolean g_log_writer_is_journald (gint output_fd);
GLIB_AVAILABLE_IN_2_50
gchar *g_log_writer_format_fields (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields);
GLIB_AVAILABLE_IN_2_50
GLogWriterOutput g_log_writer_journald (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data);
GLIB_AVAILABLE_IN_2_50
GLogWriterOutput g_log_writer_standard_streams (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data);
GLIB_AVAILABLE_IN_2_50
GLogWriterOutput g_log_writer_default (GLogLevelFlags log_level,
const GLogField *fields,
gsize n_fields,
gpointer user_data);
/**
* G_DEBUG_HERE:
*
* A convenience form of g_debug_structured(), recommended to be added to
* functions when debugging. It prints the current monotonic time and the code
* location using %G_STRLOC.
*
* Since: 2.50
*/
#define G_DEBUG_HERE() \
g_debug_structured ("%" G_GINT64_FORMAT ": %s", g_get_monotonic_time (), \
G_STRLOC)
/**
* g_debug_structured:
* @format: message format, in printf() style
* @...: parameters to insert into the format string
*
* Convenience wrapper around g_log_structured() to output a log message at
* %G_LOG_LEVEL_DEBUG in %G_LOG_DOMAIN with the given message and the
* `CODE_FILE`, `CODE_LINE` and `CODE_FUNC` fields added automatically. As this
* macro uses `__LINE__`, it cannot be wrapped in a helper function.
*
* The provided structured fields may change in future.
*
* Since: 2.50
*/
#define g_debug_structured(format, __va_args__) \
g_log_structured (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG, \
format, ##__va_args__, \
"CODE_FILE", G_STRINGIFY (__FILE__), \
"CODE_LINE", G_STRINGIFY (__LINE__), \
"CODE_FUNC", G_STRINGIFY (__FUNC__), \
NULL)
/**
* g_info_structured:
* @format: message format, in printf() style
* @...: parameters to insert into the format string
*
* Convenience wrapper around g_log_structured() to output a log message at
* %G_LOG_LEVEL_INFO in %G_LOG_DOMAIN with the given message and the
* `CODE_FILE`, `CODE_LINE` and `CODE_FUNC` fields added automatically. As this
* macro uses `__LINE__`, it cannot be wrapped in a helper function.
*
* The provided structured fields may change in future.
*
* Since: 2.50
*/
#define g_info_structured(format, __va_args__) \
g_log_structured (G_LOG_DOMAIN, G_LOG_LEVEL_INFO, \
format, ##__va_args__, \
"CODE_FILE", G_STRINGIFY (__FILE__), \
"CODE_LINE", G_STRINGIFY (__LINE__), \
"CODE_FUNC", G_STRINGIFY (__FUNC__), \
NULL)
/**
* g_message_structured:
* @format: message format, in printf() style
* @...: parameters to insert into the format string
*
* Convenience wrapper around g_log_structured() to output a log message at
* %G_LOG_LEVEL_MESSAGE in %G_LOG_DOMAIN with the given message and the
* `CODE_FILE`, `CODE_LINE` and `CODE_FUNC` fields added automatically. As this
* macro uses `__LINE__`, it cannot be wrapped in a helper function.
*
* The provided structured fields may change in future.
*
* Since: 2.50
*/
#define g_message_structured(format, __va_args__) \
g_log_structured (G_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE, \
format, ##__va_args__, \
"CODE_FILE", G_STRINGIFY (__FILE__), \
"CODE_LINE", G_STRINGIFY (__LINE__), \
"CODE_FUNC", G_STRINGIFY (__FUNC__), \
NULL)
/**
* g_warning_structured:
* @format: message format, in printf() style
* @...: parameters to insert into the format string
*
* Convenience wrapper around g_log_structured() to output a log message at
* %G_LOG_LEVEL_WARNING in %G_LOG_DOMAIN with the given message and the
* `CODE_FILE`, `CODE_LINE` and `CODE_FUNC` fields added automatically. As this
* macro uses `__LINE__`, it cannot be wrapped in a helper function.
*
* The provided structured fields may change in future.
*
* Since: 2.50
*/
#define g_warning_structured(format, __va_args__) \
g_log_structured (G_LOG_DOMAIN, G_LOG_LEVEL_WARNING, \
format, ##__va_args__, \
"CODE_FILE", G_STRINGIFY (__FILE__), \
"CODE_LINE", G_STRINGIFY (__LINE__), \
"CODE_FUNC", G_STRINGIFY (__FUNC__), \
NULL)
/**
* g_critical_structured:
* @format: message format, in printf() style
* @...: parameters to insert into the format string
*
* Convenience wrapper around g_log_structured() to output a log message at
* %G_LOG_LEVEL_CRITICAL in %G_LOG_DOMAIN with the given message and the
* `CODE_FILE`, `CODE_LINE` and `CODE_FUNC` fields added automatically. As this
* macro uses `__LINE__`, it cannot be wrapped in a helper function.
*
* The provided structured fields may change in future.
*
* Since: 2.50
*/
#define g_critical_structured(format, __va_args__) \
g_log_structured (G_LOG_DOMAIN, G_LOG_LEVEL_CRITICAL, \
format, ##__va_args__, \
"CODE_FILE", G_STRINGIFY (__FILE__), \
"CODE_LINE", G_STRINGIFY (__LINE__), \
"CODE_FUNC", G_STRINGIFY (__FUNC__), \
NULL)
/**
* g_error_structured:
* @format: message format, in printf() style
* @...: parameters to insert into the format string
*
* Convenience wrapper around g_log_structured() to output a log message at
* %G_LOG_LEVEL_ERROR in %G_LOG_DOMAIN with the given message and the
* `CODE_FILE`, `CODE_LINE` and `CODE_FUNC` fields added automatically. As this
* macro uses `__LINE__`, it cannot be wrapped in a helper function.
*
* The provided structured fields may change in future.
*
* Since: 2.50
*/
#define g_error_structured(format, __va_args__) \
g_log_structured (G_LOG_DOMAIN, G_LOG_LEVEL_ERROR, \
format, ##__va_args__, \
"CODE_FILE", G_STRINGIFY (__FILE__), \
"CODE_LINE", G_STRINGIFY (__LINE__), \
"CODE_FUNC", G_STRINGIFY (__FUNC__), \
NULL)
/* internal */
void _g_log_fallback_handler (const gchar *log_domain,
GLogLevelFlags log_level,

30
glib/tests/logging.c
View File

@@ -294,6 +294,34 @@ test_gibberish (void)
g_test_trap_assert_stderr ("*bla bla \\x9e\\x9f\\u000190*");
}
static void
test_structured_logging_no_state (void)
{
gpointer some_pointer = GUINT_TO_POINTER (0x100);
guint some_integer = 123;
g_log_structured ("some-domain", G_LOG_LEVEL_MESSAGE,
"This is a debug message about pointer %p and integer %u.",
some_pointer, some_integer,
"MESSAGE_ID", "06d4df59e6c24647bfe69d2c27ef0b4e",
"MY_APPLICATION_CUSTOM_FIELD", "some debug string",
NULL);
}
static void
test_structured_logging_some_state (void)
{
gpointer state_object = NULL; /* this must not be dereferenced */
const GLogField fields[] = {
{ "MESSAGE", "This is a debug message.", -1 },
{ "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
{ "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 },
{ "MY_APPLICATION_STATE", state_object, 0 },
};
g_log_structured_array (G_LOG_LEVEL_DEBUG, fields, G_N_ELEMENTS (fields));
}
int
main (int argc, char *argv[])
{
@@ -319,6 +347,8 @@ main (int argc, char *argv[])
g_test_add_func ("/logging/printerr-handler", test_printerr_handler);
g_test_add_func ("/logging/653052", bug653052);
g_test_add_func ("/logging/gibberish", test_gibberish);
g_test_add_func ("/structured-logging/no-state", test_structured_logging_no_state);
g_test_add_func ("/structured-logging/some-state", test_structured_logging_some_state);
return g_test_run ();
}