nettika/geary
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Switch to using GLib structured logging

Browse source 
This converts the logging infrastructure to using structured logging
calls, adds and sets a structured logging writer.
This commit is contained in:
Michael Gratton 2018-12-29 12:57:01 +11:00 • committed by Michael James Gratton
parent de8c3858e9
commit b0ca8c9e0a
6 changed files with 232 additions and 22 deletions
Download patch file Download diff file Expand all files Collapse all files

2
src/client/application/geary-application.vala
View file

@ -412,7 +412,7 @@ public class GearyApplication : Gtk.Application {
Configuration.init(this.is_installed, GSETTINGS_DIR);
Geary.Logging.init();
Geary.Logging.log_to(stderr);
GLib.Log.set_default_handler(Geary.Logging.default_handler);
GLib.Log.set_writer_func(Geary.Logging.default_log_writer);
Util.Date.init();

151
src/engine/api/geary-logging.vala
View file

@ -47,6 +47,51 @@ public enum Flag {
public inline bool is_any_set(Flag flags) {
return (flags & this) != 0;
}
public string to_string() {
GLib.StringBuilder buf = new GLib.StringBuilder();
if (this == ALL) {
buf.append("ALL");
} else if (this == NONE) {
buf.append("NONE");
} else {
if (this.is_any_set(NETWORK)) {
buf.append("NET");
}
if (this.is_any_set(SERIALIZER)) {
if (buf.len > 0) {
buf.append_c('|');
}
buf.append("SER");
}
if (this.is_any_set(REPLAY)) {
if (buf.len > 0) {
buf.append_c('|');
}
buf.append("REPLAY");
}
if (this.is_any_set(SQL)) {
if (buf.len > 0) {
buf.append_c('|');
}
buf.append("SQL");
}
if (this.is_any_set(FOLDER_NORMALIZATION)) {
if (buf.len > 0) {
buf.append_c('|');
}
buf.append("NORM");
}
if (this.is_any_set(DESERIALIZER)) {
if (buf.len > 0) {
buf.append_c('|');
}
buf.append("DESER");
}
}
return buf.str;
}
}
/**
@ -173,33 +218,27 @@ public inline bool are_all_flags_set(Flag flags) {
[PrintfFormat]
public inline void error(Flag flags, string fmt, ...) {
if (flags == ALL || logging_flags.is_any_set(flags))
GLib.logv(DOMAIN, LogLevelFlags.LEVEL_ERROR, fmt, va_list());
logv(flags, GLib.LogLevelFlags.LEVEL_ERROR, fmt, va_list());
}
[PrintfFormat]
public inline void critical(Flag flags, string fmt, ...) {
if (flags == ALL || logging_flags.is_any_set(flags))
GLib.logv(DOMAIN, LogLevelFlags.LEVEL_CRITICAL, fmt, va_list());
logv(flags, GLib.LogLevelFlags.LEVEL_CRITICAL, fmt, va_list());
}
[PrintfFormat]
public inline void warning(Flag flags, string fmt, ...) {
if (flags == ALL || logging_flags.is_any_set(flags))
GLib.logv(DOMAIN, LogLevelFlags.LEVEL_WARNING, fmt, va_list());
logv(flags, GLib.LogLevelFlags.LEVEL_WARNING, fmt, va_list());
}
[PrintfFormat]
public inline void message(Flag flags, string fmt, ...) {
if (flags == ALL || logging_flags.is_any_set(flags))
GLib.logv(DOMAIN, LogLevelFlags.LEVEL_MESSAGE, fmt, va_list());
logv(flags, GLib.LogLevelFlags.LEVEL_MESSAGE, fmt, va_list());
}
[PrintfFormat]
public inline void debug(Flag flags, string fmt, ...) {
if (flags == ALL || logging_flags.is_any_set(flags)) {
GLib.logv(DOMAIN, LogLevelFlags.LEVEL_DEBUG, fmt, va_list());
}
logv(flags, GLib.LogLevelFlags.LEVEL_DEBUG, fmt, va_list());
}
public inline void logv(Flag flags,
@ -207,7 +246,13 @@ public inline void logv(Flag flags,
string fmt,
va_list args) {
if (flags == ALL || logging_flags.is_any_set(flags)) {
GLib.logv(DOMAIN, level, fmt, args);
string formatted = fmt.vprintf(args);
GLib.LogField<string> message = GLib.LogField<string>();
message.key = "MESSAGE";
message.length = -1;
message.value = formatted;
GLib.log_structured_array(level, { message });
}
}
@ -277,6 +322,88 @@ public void default_handler(string? domain,
}
}
public GLib.LogWriterOutput default_log_writer(GLib.LogLevelFlags log_levels,
GLib.LogField[] fields) {
unowned FileStream? out = stream;
if (out != null ||
((LogLevelFlags.LEVEL_WARNING & log_levels) > 0) ||
((LogLevelFlags.LEVEL_CRITICAL & log_levels) > 0) ||
((LogLevelFlags.LEVEL_ERROR & log_levels) > 0)) {
if (out == null) {
out = GLib.stderr;
}
string domain = "default";
Flag flag = Flag.NONE;
string message = "[no message]";
string[] strings = new string[fields.length];
uint string_count = 0;
foreach (GLib.LogField field in fields) {
switch (field.key.ascii_up()) {
case "GLIB_DOMAIN":
if (field.length < 0) {
domain = (string) field.value;
}
break;
case "MESSAGE":
if (field.length < 0) {
message = (string) field.value;
}
break;
case "PRIORITY":
// noop, we get it from the args
break;
case "GEARY_FLAGS":
flag = (Flag) field.value;
break;
default:
string? string_value = null;
if (field.length < 0) {
string_value = (string) field.value;
} else {
Loggable? loggable = field.value as Loggable;
if (loggable != null) {
string_value = loggable.to_string();
}
}
if (string_value != null) {
strings[string_count++] = string_value;
}
break;
}
}
GLib.Time tm = GLib.Time.local(time_t());
out.printf(
"%s %02d:%02d:%02d %lf %s",
to_prefix(log_levels),
tm.hour, tm.minute, tm.second,
entry_timer.elapsed(),
domain
);
if (flag != ALL && flag != NONE) {
out.printf("[%s]: ", flag.to_string());
} else {
out.puts(": ");
}
for (int i = 0; i < string_count; i++) {
out.puts(strings[i]);
out.putc(' ');
}
out.puts(message);
out.putc('\n');
entry_timer.start();
}
return GLib.LogWriterOutput.HANDLED;
}
private inline string to_prefix(LogLevelFlags level) {
switch (level) {
case LogLevelFlags.LEVEL_ERROR:

95
src/engine/util/util-loggable.vala
View file

@ -18,6 +18,88 @@
public interface Geary.Loggable : GLib.Object {
// Based on function from with the same name from GLib's
// gmessages.c. Return value must be 1 byte long (plus nul byte).
// Reference:
// http://man7.org/linux/man-pages/man3/syslog.3.html#DESCRIPTION
private static string log_level_to_priority(GLib.LogLevelFlags level) {
if (GLib.LogLevelFlags.LEVEL_ERROR in level) {
return "3";
}
if (GLib.LogLevelFlags.LEVEL_CRITICAL in level) {
return "4";
}
if (GLib.LogLevelFlags.LEVEL_WARNING in level) {
return "4";
}
if (GLib.LogLevelFlags.LEVEL_MESSAGE in level) {
return "5";
}
if (GLib.LogLevelFlags.LEVEL_INFO in level) {
return "6";
}
if (GLib.LogLevelFlags.LEVEL_DEBUG in level) {
return "7";
}
/* Default to LOG_NOTICE for custom log levels. */
return "5";
}
protected struct Context {
// 8 fields ought to be enough for anybody...
private const uint8 FIELD_COUNT = 8;
public GLib.LogField[] fields;
public uint8 len;
public uint8 count;
public string message;
Context(string domain,
Logging.Flag flags,
GLib.LogLevelFlags level,
string message,
va_list args) {
this.fields = new GLib.LogField[FIELD_COUNT];
this.len = FIELD_COUNT;
this.count = 0;
append("PRIORITY", log_level_to_priority(level));
append("GLIB_DOMAIN", domain);
append("GEARY_FLAGS", flags);
this.message = message.vprintf(va_list.copy(args));
}
public void append<T>(string key, T value) {
uint8 count = this.count;
if (count + 1 >= this.len) {
this.fields.resize(this.len + FIELD_COUNT);
}
this.fields[count].key = key;
this.fields[count].value = value;
this.fields[count].length = (typeof(T) == typeof(string)) ? -1 : 0;
this.count++;
}
public inline void append_instance<T>(T value) {
this.append(typeof(T).name(), value);
}
public GLib.LogField[] to_array() {
// MESSAGE must always be last, so append it here
append("MESSAGE", this.message);
return this.fields[0:this.count];
}
}
/**
* Default flags to use for this loggable when logging messages.
*/
@ -92,15 +174,14 @@ public interface Geary.Loggable : GLib.Object {
GLib.LogLevelFlags levels,
string fmt,
va_list args) {
GLib.StringBuilder message = new GLib.StringBuilder(fmt);
Loggable? decorator = this;
while (decorator != null) {
message.prepend_c(' ');
message.prepend(decorator.to_string());
decorator = decorator.loggable_parent;
Context context = Context(Logging.DOMAIN, flags, levels, fmt, args);
Loggable? decorated = this;
while (decorated != null) {
context.append_instance(decorated);
decorated = decorated.loggable_parent;
}
Logging.logv(flags, levels, message.str, args);
GLib.log_structured_array(levels, context.to_array());
}
}

2
src/mailer/main.vala
View file

@ -161,7 +161,7 @@ int main(string[] args) {
Geary.Logging.init();
Geary.Logging.log_to(stdout);
Geary.Logging.enable_flags(Geary.Logging.Flag.NETWORK);
GLib.Log.set_default_handler(Geary.Logging.default_handler);
GLib.Log.set_writer_func(Geary.Logging.default_log_writer);
}
Geary.RFC822.init();

2
src/meson.build
View file

@ -31,6 +31,8 @@ endif
geary_c_options = [
'-include', 'config.h',
# Enable GLib structured logging
'-DG_LOG_USE_STRUCTURED',
# Select libunwind's optimised, local-only backtrace unwiding. See
# libunwind(3).
'-DUNW_LOCAL_ONLY',

2
test/test-integration.vala
View file

@ -36,7 +36,7 @@ int main(string[] args) {
Geary.HTML.init();
Geary.Logging.init();
Geary.Logging.log_to(stderr);
GLib.Log.set_default_handler(Geary.Logging.default_handler);
GLib.Log.set_writer_func(Geary.Logging.default_log_writer);
Integration.Configuration config = load_config(args);