chiark / gitweb /
journal: generate structured journal messages for a number of events
authorLennart Poettering <lennart@poettering.net>
Fri, 24 Aug 2012 20:21:20 +0000 (22:21 +0200)
committerLennart Poettering <lennart@poettering.net>
Tue, 4 Sep 2012 01:59:04 +0000 (18:59 -0700)
16 files changed:
.gitignore
Makefile.am
TODO
src/core/job.c
src/core/manager.c
src/core/unit.c
src/login/logind-dbus.c
src/login/logind-seat.c
src/login/logind-session.c
src/shared/log.c
src/shared/log.h
src/sleep/sleep.c
src/systemd/sd-id128.h
src/systemd/sd-messages.h
src/test/test-log.c [new file with mode: 0644]
src/timedate/timedated.c

index 4c8bba8871937a63e6e460ffedb45cd774e36e01..ca95d7afba597f679d94bb40102f6fd556bafa3f 100644 (file)
@@ -1,3 +1,4 @@
+/test-log
 /test-journal-verify
 /test-journal-match
 /test-journal-stream
index e5ace9b97177da565f9f94b5212d22af086111c9..927d25f0856b45ca715e392d2f55388154930bec 100644 (file)
@@ -1117,7 +1117,8 @@ noinst_PROGRAMS += \
        test-strv \
        test-install \
        test-watchdog \
-       test-unit-name
+       test-unit-name \
+       test-log
 
 TESTS += \
        test-job-type \
@@ -1173,6 +1174,12 @@ test_unit_name_SOURCES = \
 test_unit_name_LDADD = \
        libsystemd-core.la
 
+test_log_SOURCES = \
+       src/test/test-log.c
+
+test_log_LDADD = \
+       libsystemd-core.la
+
 test_daemon_SOURCES = \
        src/test/test-daemon.c
 
diff --git a/TODO b/TODO
index a4643d7b831e42b408b8ef5dd609512810f65501..b1d92dafad8f3244d0ae508777d698cbe92c72c3 100644 (file)
--- a/TODO
+++ b/TODO
@@ -49,6 +49,10 @@ Bugfixes:
 
 Features:
 
+* wall messages for shutdown should move to logind
+
+* remove wants from journald.service
+
 * allow writing multiple conditions in unit files on one line
 
 * journal: json output needs to be able to deal with multiple assignments of the same field
index 8d51aa3fdd7036be8286f3acb2cd3b45663bf84a..9614642f562e94ef41ef01046502200523c1f941 100644 (file)
@@ -24,6 +24,8 @@
 #include <sys/timerfd.h>
 #include <sys/epoll.h>
 
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 #include "set.h"
 #include "unit.h"
 #include "macro.h"
@@ -549,17 +551,74 @@ int job_run_and_invalidate(Job *j) {
         return r;
 }
 
-static void job_print_status_message(Unit *u, JobType t, JobResult result) {
+static const char *job_get_status_message_format(Unit *u, JobType t, JobResult result) {
         const UnitStatusMessageFormats *format_table;
-        const char *format;
+
+        assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
 
         format_table = &UNIT_VTABLE(u)->status_message_formats;
         if (!format_table)
-                return;
+                return NULL;
+
+        if (t == JOB_START)
+                return format_table->finished_start_job[result];
+        else if (t == JOB_STOP || t == JOB_RESTART)
+                return format_table->finished_stop_job[result];
+
+        return NULL;
+}
 
+static const char *job_get_status_message_format_try_harder(Unit *u, JobType t, JobResult result) {
+        const char *format;
+
+        assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
+
+        format = job_get_status_message_format(u, t, result);
+        if (format)
+                return format;
+
+        /* Return generic strings */
         if (t == JOB_START) {
+                if (result == JOB_DONE)
+                        return "Started %s.";
+                else if (result == JOB_FAILED)
+                        return "Failed to start %s.";
+                else if (result == JOB_DEPENDENCY)
+                        return "Dependency failed for %s.";
+                else if (result == JOB_TIMEOUT)
+                        return "Timed out starting %s.";
+        } else if (t == JOB_STOP || t == JOB_RESTART) {
+                if (result == JOB_DONE)
+                        return "Stopped %s.";
+                else if (result == JOB_FAILED)
+                        return "Stopped (with error) %s.";
+                else if (result == JOB_TIMEOUT)
+                        return "Timed out stoppping %s.";
+        } else if (t == JOB_RELOAD) {
+                if (result == JOB_DONE)
+                        return "Reloaded %s.";
+                else if (result == JOB_FAILED)
+                        return "Reload failed for %s.";
+                else if (result == JOB_TIMEOUT)
+                        return "Timed out reloading %s.";
+        }
+
+        return NULL;
+}
+
+static void job_print_status_message(Unit *u, JobType t, JobResult result) {
+        const char *format;
 
-                format = format_table->finished_start_job[result];
+        assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
+
+        if (t == JOB_START) {
+                format = job_get_status_message_format(u, t, result);
                 if (!format)
                         return;
 
@@ -572,7 +631,7 @@ static void job_print_status_message(Unit *u, JobType t, JobResult result) {
 
                 case JOB_FAILED:
                         unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON "FAILED" ANSI_HIGHLIGHT_OFF, format, unit_description(u));
-                        unit_status_printf(u, "", "See 'systemctl status %s' for details.", u->id);
+                        unit_status_printf(u, NULL, "See 'systemctl status %s' for details.", u->id);
                         break;
 
                 case JOB_DEPENDENCY:
@@ -589,7 +648,7 @@ static void job_print_status_message(Unit *u, JobType t, JobResult result) {
 
         } else if (t == JOB_STOP || t == JOB_RESTART) {
 
-                format = format_table->finished_stop_job[result];
+                format = job_get_status_message_format(u, t, result);
                 if (!format)
                         return;
 
@@ -618,6 +677,52 @@ static void job_print_status_message(Unit *u, JobType t, JobResult result) {
         }
 }
 
+#pragma GCC diagnostic push
+#pragma GCC diagnostic ignored "-Wformat-nonliteral"
+static void job_log_status_message(Unit *u, JobType t, JobResult result) {
+        const char *format;
+        char buf[LINE_MAX];
+
+        assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
+
+        format = job_get_status_message_format_try_harder(u, t, result);
+        if (!format)
+                return;
+
+        snprintf(buf, sizeof(buf), format, unit_description(u));
+        char_array_0(buf);
+
+        if (t == JOB_START) {
+                sd_id128_t mid;
+
+                mid = result == JOB_DONE ? SD_MESSAGE_UNIT_STARTED : SD_MESSAGE_UNIT_FAILED;
+                log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR,
+                           "MESSSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(mid),
+                           "UNIT=%s", u->id,
+                           "RESULT=%s", job_result_to_string(result),
+                           "MESSAGE=%s", buf,
+                           NULL);
+
+        } else if (t == JOB_STOP)
+                log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR,
+                           "MESSSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_UNIT_STOPPED),
+                           "UNIT=%s", u->id,
+                           "RESULT=%s", job_result_to_string(result),
+                           "MESSAGE=%s", buf,
+                           NULL);
+
+        else if (t == JOB_RELOAD)
+                log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR,
+                           "MESSSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_UNIT_RELOADED),
+                           "UNIT=%s", u->id,
+                           "RESULT=%s", job_result_to_string(result),
+                           "MESSAGE=%s", buf,
+                           NULL);
+}
+#pragma GCC diagnostic pop
+
 int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) {
         Unit *u;
         Unit *other;
@@ -636,6 +741,7 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) {
         log_debug("Job %s/%s finished, result=%s", u->id, job_type_to_string(t), job_result_to_string(result));
 
         job_print_status_message(u, t, result);
+        job_log_status_message(u, t, result);
 
         job_add_to_dbus_queue(j);
 
index bcaf913b5a8865c32785705af7dcf3351827fb60..da766e6d58e0e1de72030a23c14af20ef451f893 100644 (file)
@@ -41,7 +41,9 @@
 #include <libaudit.h>
 #endif
 
-#include <systemd/sd-daemon.h>
+#include "systemd/sd-daemon.h"
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 
 #include "manager.h"
 #include "transaction.h"
@@ -2030,26 +2032,41 @@ void manager_check_finished(Manager *m) {
                         kernel_usec = m->initrd_timestamp.monotonic;
                         initrd_usec = m->startup_timestamp.monotonic - m->initrd_timestamp.monotonic;
 
-                        log_info("Startup finished in %s (kernel) + %s (initrd) + %s (userspace) = %s.",
-                                 format_timespan(kernel, sizeof(kernel), kernel_usec),
-                                 format_timespan(initrd, sizeof(initrd), initrd_usec),
-                                 format_timespan(userspace, sizeof(userspace), userspace_usec),
-                                 format_timespan(sum, sizeof(sum), total_usec));
+                        log_struct(LOG_INFO,
+                                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_STARTUP_FINISHED),
+                                   "KERNEL_USEC=%llu", (unsigned long long) kernel_usec,
+                                   "INITRD_USEC=%llu", (unsigned long long) initrd_usec,
+                                   "USERSPACE_USEC=%llu", (unsigned long long) userspace_usec,
+                                   "MESSAGE=Startup finished in %s (kernel) + %s (initrd) + %s (userspace) = %s.",
+                                   format_timespan(kernel, sizeof(kernel), kernel_usec),
+                                   format_timespan(initrd, sizeof(initrd), initrd_usec),
+                                   format_timespan(userspace, sizeof(userspace), userspace_usec),
+                                   format_timespan(sum, sizeof(sum), total_usec),
+                                   NULL);
                 } else {
                         kernel_usec = m->startup_timestamp.monotonic;
                         initrd_usec = 0;
 
-                        log_info("Startup finished in %s (kernel) + %s (userspace) = %s.",
-                                 format_timespan(kernel, sizeof(kernel), kernel_usec),
-                                 format_timespan(userspace, sizeof(userspace), userspace_usec),
-                                 format_timespan(sum, sizeof(sum), total_usec));
+                        log_struct(LOG_INFO,
+                                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_STARTUP_FINISHED),
+                                   "KERNEL_USEC=%llu", (unsigned long long) kernel_usec,
+                                   "USERSPACE_USEC=%llu", (unsigned long long) userspace_usec,
+                                   "MESSAGE=Startup finished in %s (kernel) + %s (userspace) = %s.",
+                                   format_timespan(kernel, sizeof(kernel), kernel_usec),
+                                   format_timespan(userspace, sizeof(userspace), userspace_usec),
+                                   format_timespan(sum, sizeof(sum), total_usec),
+                                   NULL);
                 }
         } else {
-                userspace_usec = initrd_usec = kernel_usec = 0;
-                total_usec = m->finish_timestamp.monotonic - m->startup_timestamp.monotonic;
-
-                log_debug("Startup finished in %s.",
-                          format_timespan(sum, sizeof(sum), total_usec));
+                initrd_usec = kernel_usec = 0;
+                total_usec = userspace_usec = m->finish_timestamp.monotonic - m->startup_timestamp.monotonic;
+
+                log_struct(LOG_INFO,
+                           "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_STARTUP_FINISHED),
+                           "USERSPACE_USEC=%llu", (unsigned long long) userspace_usec,
+                           "MESSAGE=Startup finished in %s.",
+                           format_timespan(sum, sizeof(sum), total_usec),
+                           NULL);
         }
 
         bus_broadcast_finished(m, kernel_usec, initrd_usec, userspace_usec, total_usec);
index 0d5d15ef906d06ce1d47f93487c73d873a29fbc4..8246837658251a100215d28bb322e6032b6dca6f 100644 (file)
@@ -29,6 +29,8 @@
 #include <unistd.h>
 #include <sys/stat.h>
 
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 #include "set.h"
 #include "unit.h"
 #include "macro.h"
@@ -936,21 +938,93 @@ bool unit_condition_test(Unit *u) {
         return u->condition_result;
 }
 
-static void unit_status_print_starting_stopping(Unit *u, bool stopping) {
+static const char* unit_get_status_message_format(Unit *u, JobType t) {
         const UnitStatusMessageFormats *format_table;
-        const char *format;
+
+        assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
+
+        if (t != JOB_START && t != JOB_STOP)
+                return NULL;
 
         format_table = &UNIT_VTABLE(u)->status_message_formats;
         if (!format_table)
-                return;
+                return NULL;
+
+        return format_table->starting_stopping[t == JOB_STOP];
+}
+
+static const char *unit_get_status_message_format_try_harder(Unit *u, JobType t) {
+        const char *format;
+
+        assert(u);
+        assert(t >= 0);
+        assert(t < _JOB_TYPE_MAX);
+
+        format = unit_get_status_message_format(u, t);
+        if (format)
+                return format;
+
+        /* Return generic strings */
+        if (t == JOB_START)
+                return "Starting %s.";
+        else if (t == JOB_STOP)
+                return "Stopping %s.";
+        else if (t == JOB_RELOAD)
+                return "Reloading %s.";
+
+        return NULL;
+}
+
+static void unit_status_print_starting_stopping(Unit *u, JobType t) {
+        const char *format;
+
+        assert(u);
 
-        format = format_table->starting_stopping[stopping];
+        /* We only print status messages for selected units on
+         * selected operations. */
+
+        format = unit_get_status_message_format(u, t);
         if (!format)
                 return;
 
         unit_status_printf(u, "", format, unit_description(u));
 }
 
+#pragma GCC diagnostic push
+#pragma GCC diagnostic ignored "-Wformat-nonliteral"
+static void unit_status_log_starting_stopping_reloading(Unit *u, JobType t) {
+        const char *format;
+        char buf[LINE_MAX];
+        sd_id128_t mid;
+
+        assert(u);
+
+        if (t != JOB_START && t != JOB_STOP && t != JOB_RELOAD)
+                return;
+
+        /* We log status messages for all units and all operations. */
+
+        format = unit_get_status_message_format_try_harder(u, t);
+        if (!format)
+                return;
+
+        snprintf(buf, sizeof(buf), format, unit_description(u));
+        char_array_0(buf);
+
+        mid = t == JOB_START ? SD_MESSAGE_UNIT_STARTING :
+              t == JOB_STOP  ? SD_MESSAGE_UNIT_STOPPING :
+                               SD_MESSAGE_UNIT_RELOADING;
+
+        log_struct(LOG_INFO,
+                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(mid),
+                   "UNIT=%s", u->id,
+                   "MESSAGE=%s", buf,
+                   NULL);
+}
+#pragma GCC diagnostic pop
+
 /* Errors:
  *         -EBADR:     This unit type does not support starting.
  *         -EALREADY:  Unit is already started.
@@ -990,7 +1064,8 @@ int unit_start(Unit *u) {
                 return unit_start(following);
         }
 
-        unit_status_print_starting_stopping(u, false);
+        unit_status_log_starting_stopping_reloading(u, JOB_START);
+        unit_status_print_starting_stopping(u, JOB_START);
 
         /* If it is stopped, but we cannot start it, then fail */
         if (!UNIT_VTABLE(u)->start)
@@ -1040,7 +1115,8 @@ int unit_stop(Unit *u) {
                 return unit_stop(following);
         }
 
-        unit_status_print_starting_stopping(u, true);
+        unit_status_log_starting_stopping_reloading(u, JOB_STOP);
+        unit_status_print_starting_stopping(u, JOB_STOP);
 
         if (!UNIT_VTABLE(u)->stop)
                 return -EBADR;
@@ -1079,6 +1155,8 @@ int unit_reload(Unit *u) {
                 return unit_reload(following);
         }
 
+        unit_status_log_starting_stopping_reloading(u, JOB_RELOAD);
+
         unit_add_to_dbus_queue(u);
         return UNIT_VTABLE(u)->reload(u);
 }
index ae9671bb1ef3d9b7a19c041290560b5cabb67cde..af62d8782117796423eca411fefd54ec0e9b18c6 100644 (file)
@@ -31,6 +31,8 @@
 #include "path-util.h"
 #include "polkit.h"
 #include "special.h"
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 
 #define BUS_MANAGER_INTERFACE                                           \
         " <interface name=\"org.freedesktop.login1.Manager\">\n"        \
@@ -1138,6 +1140,42 @@ finish:
         return 0;
 }
 
+static int bus_manager_log_shutdown(
+                Manager *m,
+                InhibitWhat w,
+                const char *unit_name) {
+
+        const char *p, *q;
+
+        assert(m);
+        assert(unit_name);
+
+        if (w != INHIBIT_SHUTDOWN)
+                return 0;
+
+        if (streq(unit_name, SPECIAL_POWEROFF_TARGET)) {
+                p = "MESSAGE=System is powering down.";
+                q = "SHUTDOWN=power-off";
+        } else if (streq(unit_name, SPECIAL_HALT_TARGET)) {
+                p = "MESSAGE=System is halting.";
+                q = "SHUTDOWN=halt";
+        } else if (streq(unit_name, SPECIAL_REBOOT_TARGET)) {
+                p = "MESSAGE=System is rebooting.";
+                q = "SHUTDOWN=reboot";
+        } else if (streq(unit_name, SPECIAL_KEXEC_TARGET)) {
+                p = "MESSAGE=System is rebooting with kexec.";
+                q = "SHUTDOWN=kexec";
+        } else {
+                p = "MESSAGE=System is shutting down.";
+                q = NULL;
+        }
+
+        return log_struct(LOG_NOTICE,
+                          "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SHUTDOWN),
+                          p,
+                          q, NULL);
+}
+
 int bus_manager_shutdown_or_sleep_now_or_later(
                 Manager *m,
                 const char *unit_name,
@@ -1160,10 +1198,13 @@ int bus_manager_shutdown_or_sleep_now_or_later(
                 /* Shutdown is delayed, keep in mind what we
                  * want to do, and start a timeout */
                 r = delay_shutdown_or_sleep(m, w, unit_name);
-        else
+        else {
+                bus_manager_log_shutdown(m, w, unit_name);
+
                 /* Shutdown is not delayed, execute it
                  * immediately */
                 r = send_start_unit(m->bus, unit_name, error);
+        }
 
         return r;
 }
@@ -2256,6 +2297,8 @@ int manager_dispatch_delayed(Manager *manager) {
         if (delayed)
                 return 0;
 
+        bus_manager_log_shutdown(manager, manager->delayed_what, manager->delayed_unit);
+
         /* Reset delay data */
         unit_name = manager->delayed_unit;
         manager->delayed_unit = NULL;
index 045712192a35e0feecb9ff5044de1759aae2480a..937315ebf1ab17c4fa8a9b0ab61003c784451ed4 100644 (file)
@@ -27,6 +27,8 @@
 #include <linux/vt.h>
 #include <string.h>
 
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 #include "logind-seat.h"
 #include "logind-acl.h"
 #include "util.h"
@@ -337,7 +339,11 @@ int seat_start(Seat *s) {
         if (s->started)
                 return 0;
 
-        log_info("New seat %s.", s->id);
+        log_struct(LOG_INFO,
+                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SEAT_START),
+                   "SEAT_ID=%s", s->id,
+                   "MESSAGE=New seat %s.", s->id,
+                   NULL);
 
         /* Initialize VT magic stuff */
         seat_preallocate_vts(s);
@@ -361,7 +367,11 @@ int seat_stop(Seat *s) {
         assert(s);
 
         if (s->started)
-                log_info("Removed seat %s.", s->id);
+                log_struct(LOG_INFO,
+                           "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SEAT_STOP),
+                           "SEAT_ID=%s", s->id,
+                           "MESSAGE=Removed seat %s.", s->id,
+                           NULL);
 
         seat_stop_sessions(s);
 
index 16d4955d5d94bc1f69151140ad689026149ec12b..77462a8d152bb64f10a7606edfae03380f10f859 100644 (file)
@@ -25,6 +25,8 @@
 #include <sys/epoll.h>
 #include <fcntl.h>
 
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 #include "strv.h"
 #include "util.h"
 #include "mkdir.h"
@@ -542,8 +544,13 @@ int session_start(Session *s) {
         if (r < 0)
                 return r;
 
-        log_full(s->type == SESSION_TTY || s->type == SESSION_X11 ? LOG_INFO : LOG_DEBUG,
-                 "New session %s of user %s.", s->id, s->user->name);
+        log_struct(s->type == SESSION_TTY || s->type == SESSION_X11 ? LOG_INFO : LOG_DEBUG,
+                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SESSION_START),
+                   "SESSION_ID=%s", s->id,
+                   "USER_ID=%s", s->user->name,
+                   "LEADER=%lu", (unsigned long) s->leader,
+                   "MESSAGE=New session %s of user %s.", s->id, s->user->name,
+                   NULL);
 
         /* Create cgroup */
         r = session_create_cgroup(s);
@@ -679,8 +686,13 @@ int session_stop(Session *s) {
         assert(s);
 
         if (s->started)
-                log_full(s->type == SESSION_TTY || s->type == SESSION_X11 ? LOG_INFO : LOG_DEBUG,
-                         "Removed session %s.", s->id);
+                log_struct(s->type == SESSION_TTY || s->type == SESSION_X11 ? LOG_INFO : LOG_DEBUG,
+                           "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SESSION_STOP),
+                           "SESSION_ID=%s", s->id,
+                           "USER_ID=%s", s->user->name,
+                           "LEADER=%lu", (unsigned long) s->leader,
+                           "MESSAGE=Removed session %s.", s->id,
+                           NULL);
 
         /* Kill cgroup */
         k = session_terminate_cgroup(s);
index 4fc430eed11a1f783e9defeb89cf7317483def06..67a3e1b843bc41272f1420530557c1ce6ea786ee 100644 (file)
@@ -658,11 +658,127 @@ _noreturn_ void log_assert_failed_unreachable(const char *text, const char *file
         log_assert(text, file, line, func, "Code should not be reached '%s' at %s:%u, function %s(). Aborting.");
 }
 
-int __log_oom(const char *file, int line, const char *func) {
+int log_oom_internal(const char *file, int line, const char *func) {
         log_meta(LOG_ERR, file, line, func, "Out of memory.");
         return -ENOMEM;
 }
 
+int log_struct_internal(
+                int level,
+                const char *file,
+                int line,
+                const char *func,
+                const char *format, ...) {
+
+        int saved_errno;
+        va_list ap;
+        int r;
+
+        if (_likely_(LOG_PRI(level) > log_max_level))
+                return 0;
+
+        if (log_target == LOG_TARGET_NULL)
+                return 0;
+
+        if ((level & LOG_FACMASK) == 0)
+                level = log_facility | LOG_PRI(level);
+
+        saved_errno = errno;
+
+        if ((log_target == LOG_TARGET_AUTO ||
+             log_target == LOG_TARGET_JOURNAL_OR_KMSG ||
+             log_target == LOG_TARGET_JOURNAL) &&
+            journal_fd >= 0) {
+
+                char header[LINE_MAX];
+                struct iovec iovec[17];
+                unsigned n = 0, i;
+                struct msghdr mh;
+                const char nl = '\n';
+
+                /* If the journal is available do structured logging */
+
+                snprintf(header, sizeof(header),
+                        "PRIORITY=%i\n"
+                        "SYSLOG_FACILITY=%i\n"
+                        "CODE_FILE=%s\n"
+                        "CODE_LINE=%i\n"
+                        "CODE_FUNCTION=%s\n"
+                        "SYSLOG_IDENTIFIER=%s\n",
+                        LOG_PRI(level),
+                        LOG_FAC(level),
+                        file,
+                        line,
+                        func,
+                        program_invocation_short_name);
+                char_array_0(header);
+
+                zero(iovec);
+                IOVEC_SET_STRING(iovec[n++], header);
+
+                va_start(ap, format);
+                while (format && n + 1 < ELEMENTSOF(iovec)) {
+                        char *buf;
+
+                        if (vasprintf(&buf, format, ap) < 0) {
+                                r = -ENOMEM;
+                                goto finish;
+                        }
+
+                        IOVEC_SET_STRING(iovec[n++], buf);
+
+                        iovec[n].iov_base = (char*) &nl;
+                        iovec[n].iov_len = 1;
+                        n++;
+
+                        format = va_arg(ap, char *);
+                }
+                va_end(ap);
+
+                zero(mh);
+                mh.msg_iov = iovec;
+                mh.msg_iovlen = n;
+
+                if (sendmsg(journal_fd, &mh, MSG_NOSIGNAL) < 0)
+                        r = -errno;
+                else
+                        r = 1;
+
+        finish:
+                for (i = 1; i < n; i += 2)
+                        free(iovec[i].iov_base);
+
+        } else {
+                char buf[LINE_MAX];
+                bool found = false;
+
+                /* Fallback if journal logging is not available */
+
+                va_start(ap, format);
+                while (format) {
+
+                        vsnprintf(buf, sizeof(buf), format, ap);
+                        char_array_0(buf);
+
+                        if (startswith(buf, "MESSAGE=")) {
+                                found = true;
+                                break;
+                        }
+
+                        format = va_arg(ap, char *);
+                }
+                va_end(ap);
+
+                if (found)
+                        r = log_dispatch(level, file, line, func, buf + 8);
+                else
+                        r = -EINVAL;
+        }
+
+        errno = saved_errno;
+        return r;
+}
+
 int log_set_target_from_string(const char *e) {
         LogTarget t;
 
index ab894df172ef724776cce154847684e681336fbb..0c60b7671bea0107254b0f8325141517c6342600 100644 (file)
@@ -70,30 +70,51 @@ void log_close_console(void);
 void log_parse_environment(void);
 
 int log_meta(
-        int level,
-        const char*file,
-        int line,
-        const char *func,
-        const char *format, ...) _printf_attr_(5,6);
+                int level,
+                const char*file,
+                int line,
+                const char *func,
+                const char *format, ...) _printf_attr_(5,6);
 
 int log_metav(
-        int level,
-        const char*file,
-        int line,
-        const char *func,
-        const char *format,
-        va_list ap);
-
-_noreturn_ void log_assert_failed(const char *text, const char *file, int line, const char *func);
-_noreturn_ void log_assert_failed_unreachable(const char *text, const char *file, int line, const char *func);
+                int level,
+                const char*file,
+                int line,
+                const char *func,
+                const char *format,
+                va_list ap);
+
+int log_struct_internal(
+                int level,
+                const char *file,
+                int line,
+                const char *func,
+                const char *format, ...) _sentinel_;
+
+int log_oom_internal(
+                const char *file,
+                int line,
+                const char *func);
 
 /* This modifies the buffer passed! */
 int log_dump_internal(
-        int level,
-        const char*file,
-        int line,
-        const char *func,
-        char *buffer);
+                int level,
+                const char*file,
+                int line,
+                const char *func,
+                char *buffer);
+
+_noreturn_ void log_assert_failed(
+                const char *text,
+                const char *file,
+                int line,
+                const char *func);
+
+_noreturn_ void log_assert_failed_unreachable(
+                const char *text,
+                const char *file,
+                int line,
+                const char *func);
 
 #define log_full(level, ...) log_meta(level,   __FILE__, __LINE__, __func__, __VA_ARGS__)
 
@@ -103,8 +124,9 @@ int log_dump_internal(
 #define log_warning(...) log_meta(LOG_WARNING, __FILE__, __LINE__, __func__, __VA_ARGS__)
 #define log_error(...)   log_meta(LOG_ERR,     __FILE__, __LINE__, __func__, __VA_ARGS__)
 
-int __log_oom(const char *file, int line, const char *func);
-#define log_oom() __log_oom(__FILE__, __LINE__, __func__)
+#define log_struct(level, ...) log_struct_internal(level, __FILE__, __LINE__, __func__, __VA_ARGS__)
+
+#define log_oom() log_oom_internal(__FILE__, __LINE__, __func__)
 
 /* This modifies the buffer passed! */
 #define log_dump(level, buffer) log_dump_internal(level, __FILE__, __LINE__, __func__, buffer)
index c86f69c4aa379761923f45959466f0681afcbe00..71c7518a3b4efaea819edb9e8b5c67bc811a5aa5 100644 (file)
@@ -25,6 +25,8 @@
 
 #include "log.h"
 #include "util.h"
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 
 int main(int argc, char *argv[]) {
         const char *verb;
@@ -66,9 +68,17 @@ int main(int argc, char *argv[]) {
         execute_directory(SYSTEM_SLEEP_PATH, NULL, arguments);
 
         if (streq(argv[1], "suspend"))
-                log_info("Suspending system...");
+                log_struct(LOG_INFO,
+                           "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SLEEP_START),
+                           "MESSAGE=Suspending system...",
+                           "SLEEP=suspend",
+                           NULL);
         else
-                log_info("Hibernating system...");
+                log_struct(LOG_INFO,
+                           "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SLEEP_START),
+                           "MESSAGE=Hibernating system...",
+                           "SLEEP=hibernate",
+                           NULL);
 
         fputs(verb, f);
         fputc('\n', f);
@@ -77,9 +87,17 @@ int main(int argc, char *argv[]) {
         r = ferror(f) ? -errno : 0;
 
         if (streq(argv[1], "suspend"))
-                log_info("System resumed.");
+                log_struct(LOG_INFO,
+                           "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SLEEP_STOP),
+                           "MESSAGE=System resumed.",
+                           "SLEEP=suspend",
+                           NULL);
         else
-                log_info("System thawed.");
+                log_struct(LOG_INFO,
+                           "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_SLEEP_STOP),
+                           "MESSAGE=System thawed.",
+                           "SLEEP=hibernate",
+                           NULL);
 
         arguments[1] = (char*) "post";
         execute_directory(SYSTEM_SLEEP_PATH, NULL, arguments);
index 27fa479427be610f10c95df50832d56a7541c6ed..126d83ce8a87409d57ee93ae1a29a2fdf1ccb061 100644 (file)
@@ -56,6 +56,7 @@ int sd_id128_get_boot(sd_id128_t *ret);
  * times. It is hence not a good idea to call this macro with an
  * expensive function as paramater or an expression with side
  * effects */
+
 #define SD_ID128_FORMAT_STR "%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x"
 #define SD_ID128_FORMAT_VAL(x) (x).bytes[0], (x).bytes[1], (x).bytes[2], (x).bytes[3], (x).bytes[4], (x).bytes[5], (x).bytes[6], (x).bytes[7], (x).bytes[8], (x).bytes[9], (x).bytes[10], (x).bytes[11], (x).bytes[12], (x).bytes[13], (x).bytes[14], (x).bytes[15]
 
index 9b485b9a8bc505d66bee950e00bf2aa8452cade1..01616c8f019fbf594dcd165f66f049e655806526 100644 (file)
 extern "C" {
 #endif
 
-#define SD_MESSAGE_JOURNAL_START   SD_ID128_MAKE(f7,73,79,a8,49,0b,40,8b,be,5f,69,40,50,5a,77,7b)
-#define SD_MESSAGE_JOURNAL_STOP    SD_ID128_MAKE(d9,3f,b3,c9,c2,4d,45,1a,97,ce,a6,15,ce,59,c0,0b)
-#define SD_MESSAGE_JOURNAL_DROPPED SD_ID128_MAKE(a5,96,d6,fe,7b,fa,49,94,82,8e,72,30,9e,95,d6,1e)
-#define SD_MESSAGE_JOURNAL_MISSED  SD_ID128_MAKE(e9,bf,28,e6,e8,34,48,1b,b6,f4,8f,54,8a,d1,36,06)
+#define SD_MESSAGE_JOURNAL_START    SD_ID128_MAKE(f7,73,79,a8,49,0b,40,8b,be,5f,69,40,50,5a,77,7b)
+#define SD_MESSAGE_JOURNAL_STOP     SD_ID128_MAKE(d9,3f,b3,c9,c2,4d,45,1a,97,ce,a6,15,ce,59,c0,0b)
+#define SD_MESSAGE_JOURNAL_DROPPED  SD_ID128_MAKE(a5,96,d6,fe,7b,fa,49,94,82,8e,72,30,9e,95,d6,1e)
+#define SD_MESSAGE_JOURNAL_MISSED   SD_ID128_MAKE(e9,bf,28,e6,e8,34,48,1b,b6,f4,8f,54,8a,d1,36,06)
 
-#define SD_MESSAGE_COREDUMP        SD_ID128_MAKE(fc,2e,22,bc,6e,e6,47,b6,b9,07,29,ab,34,a2,50,b1)
+#define SD_MESSAGE_COREDUMP         SD_ID128_MAKE(fc,2e,22,bc,6e,e6,47,b6,b9,07,29,ab,34,a2,50,b1)
+
+#define SD_MESSAGE_SESSION_START    SD_ID128_MAKE(8d,45,62,0c,1a,43,48,db,b1,74,10,da,57,c6,0c,66)
+#define SD_MESSAGE_SESSION_STOP     SD_ID128_MAKE(33,54,93,94,24,b4,45,6d,98,02,ca,83,33,ed,42,4a)
+#define SD_MESSAGE_SEAT_START       SD_ID128_MAKE(fc,be,fc,5d,a2,3d,42,80,93,f9,7c,82,a9,29,0f,7b)
+#define SD_MESSAGE_SEAT_STOP        SD_ID128_MAKE(e7,85,2b,fe,46,78,4e,d0,ac,cd,e0,4b,c8,64,c2,d5)
+
+#define SD_MESSAGE_TIME_CHANGE      SD_ID128_MAKE(c7,a7,87,07,9b,35,4e,aa,a9,e7,7b,37,18,93,cd,27)
+#define SD_MESSAGE_TIMEZONE_CHANGE  SD_ID128_MAKE(45,f8,2f,4a,ef,7a,4b,bf,94,2c,e8,61,d1,f2,09,90)
+
+#define SD_MESSAGE_STARTUP_FINISHED SD_ID128_MAKE(b0,7a,24,9c,d0,24,41,4a,82,dd,00,cd,18,13,78,ff)
+
+#define SD_MESSAGE_SLEEP_START      SD_ID128_MAKE(6b,bd,95,ee,97,79,41,e4,97,c4,8b,e2,7c,25,41,28)
+#define SD_MESSAGE_SLEEP_STOP       SD_ID128_MAKE(88,11,e6,df,2a,8e,40,f5,8a,94,ce,a2,6f,8e,bf,14)
+
+#define SD_MESSAGE_SHUTDOWN         SD_ID128_MAKE(98,26,88,66,d1,d5,4a,49,9c,4e,98,92,1d,93,bc,40)
+
+#define SD_MESSAGE_UNIT_STARTING    SD_ID128_MAKE(7d,49,58,e8,42,da,4a,75,8f,6c,1c,dc,7b,36,dc,c5)
+#define SD_MESSAGE_UNIT_STARTED     SD_ID128_MAKE(39,f5,34,79,d3,a0,45,ac,8e,11,78,62,48,23,1f,bf)
+#define SD_MESSAGE_UNIT_STOPPING    SD_ID128_MAKE(de,5b,42,6a,63,be,47,a7,b6,ac,3e,aa,c8,2e,2f,6f)
+#define SD_MESSAGE_UNIT_STOPPED     SD_ID128_MAKE(9d,1a,aa,27,d6,01,40,bd,96,36,54,38,aa,d2,02,86)
+#define SD_MESSAGE_UNIT_FAILED      SD_ID128_MAKE(be,02,cf,68,55,d2,42,8b,a4,0d,f7,e9,d0,22,f0,3d)
+#define SD_MESSAGE_UNIT_RELOADING   SD_ID128_MAKE(be,02,cf,68,55,d2,42,8b,a4,0d,f7,e9,d0,22,f0,3d)
+#define SD_MESSAGE_UNIT_RELOADED    SD_ID128_MAKE(be,02,cf,68,55,d2,42,8b,a4,0d,f7,e9,d0,22,f0,3d)
 
 #ifdef __cplusplus
 }
diff --git a/src/test/test-log.c b/src/test/test-log.c
new file mode 100644 (file)
index 0000000..cc924fa
--- /dev/null
@@ -0,0 +1,46 @@
+/*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/
+
+/***
+  This file is part of systemd.
+
+  Copyright 2012 Lennart Poettering
+
+  systemd is free software; you can redistribute it and/or modify it
+  under the terms of the GNU Lesser General Public License as published by
+  the Free Software Foundation; either version 2.1 of the License, or
+  (at your option) any later version.
+
+  systemd is distributed in the hope that it will be useful, but
+  WITHOUT ANY WARRANTY; without even the implied warranty of
+  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+  Lesser General Public License for more details.
+
+  You should have received a copy of the GNU Lesser General Public License
+  along with systemd; If not, see <http://www.gnu.org/licenses/>.
+***/
+
+#include <stddef.h>
+#include <unistd.h>
+
+#include "log.h"
+
+int main(int argc, char* argv[]) {
+
+        log_set_target(LOG_TARGET_CONSOLE);
+        log_open();
+
+        log_struct(LOG_INFO,
+                   "MESSAGE=Waldo PID=%lu", (unsigned long) getpid(),
+                   "SERVICE=piepapo",
+                   NULL);
+
+        log_set_target(LOG_TARGET_JOURNAL);
+        log_open();
+
+        log_struct(LOG_INFO,
+                   "MESSAGE=Foobar PID=%lu", (unsigned long) getpid(),
+                   "SERVICE=foobar",
+                   NULL);
+
+        return 0;
+}
index 09fd8083324d7ff2079e651443f0f5427da35607..34d287b2a14c6f85328db0f805e4315fdf7bd009 100644 (file)
@@ -25,6 +25,8 @@
 #include <string.h>
 #include <unistd.h>
 
+#include "systemd/sd-id128.h"
+#include "systemd/sd-messages.h"
 #include "util.h"
 #include "strv.h"
 #include "dbus-common.h"
@@ -701,7 +703,11 @@ static DBusHandlerResult timedate_message_handler(
                                 hwclock_set_time(tm);
                         }
 
-                        log_info("Changed timezone to '%s'.", tz.zone);
+                        log_struct(LOG_INFO,
+                                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_TIMEZONE_CHANGE),
+                                   "TIMEZONE=%s", tz.zone,
+                                   "MESSAGE=Changed timezone to '%s'.", tz.zone,
+                                   NULL);
 
                         changed = bus_properties_changed_new(
                                         "/org/freedesktop/timedate1",
@@ -842,7 +848,11 @@ static DBusHandlerResult timedate_message_handler(
 
                         hwclock_set_time(tm);
 
-                        log_info("Changed local time to %s", ctime(&ts.tv_sec));
+                        log_struct(LOG_INFO,
+                                   "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(SD_MESSAGE_TIME_CHANGE),
+                                   "REALTIME=%llu", (unsigned long long) timespec_load(&ts),
+                                   "MESSAGE=Changed local time to %s", ctime(&ts.tv_sec),
+                                   NULL);
                 }
         } else if (dbus_message_is_method_call(message, "org.freedesktop.timedate1", "SetNTP")) {
                 dbus_bool_t ntp;