basic/log: make sure header is printed correctly, add test

If log_do_header() was called with overly long parameters, it'd generate
improper output. Essentially, it'd be truncated at random point, in particular
missing a newline at the end, so it'd run with the next field, usually MESSAGE=.

log_do_header is called with parameters from compiled code (file name, lien
nubmer, etc), so in practice this was unlikely to ever be a problem, but it is
possible. In particular, if systemd was compiled from sources in some deeply
nested directory (which happens for example in mock and other build roots), the
filename could be very long.

As a safety measure, let's truncate all parameters to 256 bytes. So we have
5 fields which are 256 bytes (plus the field name prefix), and a few other
fields with fixed width. This must always fit in the 2048 byte buffer.
I don't think there's much gain in calculating the required length precisely,
since it's a lot of fields and a few bytes allocated on the stack don't matter.

diff --git a/src/basic/log.c b/src/basic/log.c
index 85f8eeaa9bb4d93e4dbcef9996a34afa916b4ea2..19c4ec76492970a263a60e999edf3cbc15a5623f 100644 (file)
--- a/src/basic/log.c
+++ b/src/basic/log.c
@@ -498,38 +498,40 @@ static int log_do_header(
                 const char *file, int line, const char *func,
                 const char *object_field, const char *object,
                 const char *extra_field, const char *extra) {
+        int r;
 
-        snprintf(header, size,
-                 "PRIORITY=%i\n"
-                 "SYSLOG_FACILITY=%i\n"
-                 "%s%s%s"
-                 "%s%.*i%s"
-                 "%s%s%s"
-                 "%s%.*i%s"
-                 "%s%s%s"
-                 "%s%s%s"
-                 "SYSLOG_IDENTIFIER=%s\n",
-                 LOG_PRI(level),
-                 LOG_FAC(level),
-                 isempty(file) ? "" : "CODE_FILE=",
-                 isempty(file) ? "" : file,
-                 isempty(file) ? "" : "\n",
-                 line ? "CODE_LINE=" : "",
-                 line ? 1 : 0, line, /* %.0d means no output too, special case for 0 */
-                 line ? "\n" : "",
-                 isempty(func) ? "" : "CODE_FUNC=",
-                 isempty(func) ? "" : func,
-                 isempty(func) ? "" : "\n",
-                 error ? "ERRNO=" : "",
-                 error ? 1 : 0, error,
-                 error ? "\n" : "",
-                 isempty(object) ? "" : object_field,
-                 isempty(object) ? "" : object,
-                 isempty(object) ? "" : "\n",
-                 isempty(extra) ? "" : extra_field,
-                 isempty(extra) ? "" : extra,
-                 isempty(extra) ? "" : "\n",
-                 program_invocation_short_name);
+        r = snprintf(header, size,
+                     "PRIORITY=%i\n"
+                     "SYSLOG_FACILITY=%i\n"
+                     "%s%.256s%s"        /* CODE_FILE */
+                     "%s%.*i%s"          /* CODE_LINE */
+                     "%s%.256s%s"        /* CODE_FUNC */
+                     "%s%.*i%s"          /* ERRNO */
+                     "%s%.256s%s"        /* object */
+                     "%s%.256s%s"        /* extra */
+                     "SYSLOG_IDENTIFIER=%.256s\n",
+                     LOG_PRI(level),
+                     LOG_FAC(level),
+                     isempty(file) ? "" : "CODE_FILE=",
+                     isempty(file) ? "" : file,
+                     isempty(file) ? "" : "\n",
+                     line ? "CODE_LINE=" : "",
+                     line ? 1 : 0, line, /* %.0d means no output too, special case for 0 */
+                     line ? "\n" : "",
+                     isempty(func) ? "" : "CODE_FUNC=",
+                     isempty(func) ? "" : func,
+                     isempty(func) ? "" : "\n",
+                     error ? "ERRNO=" : "",
+                     error ? 1 : 0, error,
+                     error ? "\n" : "",
+                     isempty(object) ? "" : object_field,
+                     isempty(object) ? "" : object,
+                     isempty(object) ? "" : "\n",
+                     isempty(extra) ? "" : extra_field,
+                     isempty(extra) ? "" : extra,
+                     isempty(extra) ? "" : "\n",
+                     program_invocation_short_name);
+        assert((size_t) r < size);
 
         return 0;
 }

diff --git a/src/test/test-log.c b/src/test/test-log.c
index fd19899480791c3ea5a1f8d10c7caf67bb854504..4a3c8955e3c05a72a4dbc0c07437220c81dbaf71 100644 (file)
--- a/src/test/test-log.c
+++ b/src/test/test-log.c
@@ -35,19 +35,18 @@ assert_cc((LOG_REALM_PLUS_LEVEL(LOG_REALM_SYSTEMD, LOG_LOCAL3 | LOG_DEBUG) & LOG
 assert_cc((LOG_REALM_PLUS_LEVEL(LOG_REALM_UDEV, LOG_USER | LOG_INFO) & LOG_PRIMASK)
           == LOG_INFO);
 
-int main(int argc, char* argv[]) {
-
-        log_set_target(LOG_TARGET_CONSOLE);
-        log_open();
+#define X10(x) x x x x x x x x x x
+#define X100(x) X10(X10(x))
+#define X1000(x) X100(X10(x))
 
+static void test_log_console(void) {
         log_struct(LOG_INFO,
                    "MESSAGE=Waldo PID="PID_FMT, getpid_cached(),
                    "SERVICE=piepapo",
                    NULL);
+}
 
-        log_set_target(LOG_TARGET_JOURNAL);
-        log_open();
-
+static void test_log_journal(void) {
         log_struct(LOG_INFO,
                    "MESSAGE=Foobar PID="PID_FMT, getpid_cached(),
                    "SERVICE=foobar",
@@ -59,6 +58,32 @@ int main(int argc, char* argv[]) {
                    (int) 1, 'A', (short) 2, (long int) 3, (long long int) 4, (void*) 1, "foo", (float) 2.5f, (double) 3.5, (long double) 4.5,
                    "SUFFIX=GOT IT",
                    NULL);
+}
+
+static void test_long_lines(void) {
+        log_object_internal(LOG_NOTICE,
+                            EUCLEAN,
+                            X1000("abcd_") ".txt",
+                            1000000,
+                            X1000("fff") "unc",
+                            "OBJECT=",
+                            X1000("obj_") "ect",
+                            "EXTRA=",
+                            X1000("ext_") "tra",
+                            "asdfasdf %s asdfasdfa", "foobar");
+}
+
+int main(int argc, char* argv[]) {
+        int target;
+
+        for (target = 0; target <  _LOG_TARGET_MAX; target++) {
+                log_set_target(target);
+                log_open();
+
+                test_log_console();
+                test_log_journal();
+                test_long_lines();
+        }
 
         return 0;
 }