Storage format keeps cached priority 93/173993/13
authorMaciej Slodczyk <m.slodczyk2@partner.samsung.com>
Tue, 27 Mar 2018 10:11:23 +0000 (12:11 +0200)
committerMichal Bloch <m.bloch@samsung.com>
Tue, 10 Apr 2018 13:23:22 +0000 (13:23 +0000)
Change-Id: I2b60fe7909b60883133fd9ff7bb39879e8548253

include/logprint.h
include/queued_entry.h
src/shared/logprint.c
src/shared/queued_entry.c
src/tests/filters.c
src/tests/pipe_message.c
src/tests/syslog_parser.c
src/tests/test_logger_log_storage.c

index 486f6cb..c0be716 100644 (file)
@@ -152,13 +152,6 @@ char* log_buffer_get_tag(const struct logger_entry *entry);
 char* log_buffer_get_message(const struct logger_entry *entry);
 
 /**
- * Returns priority of a log entry
- *
- * Finds the priority in entry's payload and returns it
- */
-log_priority log_buffer_get_priority(const struct logger_entry *entry);
-
-/**
  * Formats a log message into a buffer
  *
  * Uses defaultBuffer if it can, otherwise malloc()'s a new buffer
index 083369e..b6af931 100644 (file)
@@ -24,7 +24,8 @@
 
 struct logger_entry {
        uint16_t    len;    /* length of the payload */
-       uint16_t    padding;/* padding for alignment */
+       uint8_t     priority; /* entry's priority*/
+       uint8_t     padding;/* padding for alignment */
        int32_t     pid;    /* generating process's pid */
        int32_t     tid;    /* generating process's tid */
        int32_t     sec;    /* seconds since Epoch, time sent */
index aafd962..8f9e60b 100644 (file)
@@ -228,7 +228,7 @@ bool log_should_print_line(log_format *p_format, const struct logger_entry *entr
        log_priority prio;
 
        tag = log_buffer_get_tag(entry);
-       prio = log_buffer_get_priority(entry);
+       prio = (log_priority)entry->priority;
 
        for (p_curFilter = p_format->filters; p_curFilter != NULL; p_curFilter = p_curFilter->p_next) {
                switch (p_curFilter->type) {
@@ -562,15 +562,14 @@ int log_add_filter_tid(log_format *p_format, pthread_t tid)
  */
 char* log_buffer_get_tag(const struct logger_entry *entry)
 {
-       if (entry->len - sizeof(struct logger_entry) < 3) {
+       if (entry->len - sizeof(struct logger_entry) < 2) {
                fprintf(stderr, "Entry too small\n");
                return NULL;
        }
 
-       return (char*)entry->msg + 1; /* tag is right after priority byte */
+       return (char*)entry->msg;
 }
 
-
 /**
  * @brief Return pointer to log entry message
  * @details Finds the beginning of a log message in entry's payload and returns it
@@ -579,34 +578,12 @@ char* log_buffer_get_tag(const struct logger_entry *entry)
  */
 char* log_buffer_get_message(const struct logger_entry *entry)
 {
-       if (entry->len - sizeof(struct logger_entry) < 3) {
+       if (entry->len - sizeof(struct logger_entry) < 2) {
                fprintf(stderr, "Entry too small\n");
                return NULL;
        }
 
-       return (char*)entry->msg + 1 /* prio */ + entry->tag_len + 1 /* NULL delimiter */;
-}
-
-/**
- * @brief Return priority of a log entry
- * @details Finds the priority in entry's payload and returns it
- * @param[in] entry The log entry
- * @return Priority of a log entry
- */
-log_priority log_buffer_get_priority(const struct logger_entry *entry)
-{
-       const unsigned char pri = entry->msg[0]; // cannot cast to log_priority directly because then the compiler is allowed to optimize the below check out
-
-       if (entry->len - sizeof(struct logger_entry) < 3) {
-               fprintf(stderr, "Entry too small\n");
-               return DLOG_UNKNOWN;
-       }
-
-       if (pri > DLOG_SILENT) {
-               fprintf(stderr, "Wrong priority message, %u but should be <%u\n", pri, DLOG_SILENT);
-               return DLOG_UNKNOWN;
-       }
-       return (log_priority)pri;
+       return (char*)entry->msg + entry->tag_len + 1 /* NULL delimiter */;
 }
 
 /**
@@ -639,7 +616,7 @@ char *log_format_log_line(
        char *tag, *msg;
        char * ret = NULL;
 
-       priChar = filter_pri_to_char(log_buffer_get_priority(entry));
+       priChar = filter_pri_to_char((log_priority)entry->priority);
 
        tag = log_buffer_get_tag(entry);
        msg = log_buffer_get_message(entry);
@@ -771,7 +748,7 @@ char *log_format_log_line(
        char *p;
        size_t bufferSize;
        const char *pm;
-       int message_len = entry->len - sizeof(struct logger_entry) - entry->tag_len - 1 /* prio */ - 2 /* tag and msg delimiters */;
+       int message_len = entry->len - sizeof(struct logger_entry) - entry->tag_len - 2 /* tag and msg delimiters */;
        // odd-length messages get an extra byte of padding, get rid of that
        if (*(msg + message_len - 1)  == '\0')
                --message_len;
index b282907..44dc70a 100644 (file)
@@ -135,8 +135,9 @@ int parse_kmsg_message(char *buffer, struct logger_entry_with_msg *lem, int buff
        lem->header.pid = 0;
        lem->header.tid = 0;
 
-       lem->header.tag_len = snprintf(lem->msg, sizeof lem->msg - 1, "%c%s", 6, "DEVKMSG") - 1; // minus prio
-       lem->header.len = lem->header.tag_len + 2; // plus prio and NULL delimiter
+       lem->header.priority = 6;
+       lem->header.tag_len = snprintf(lem->msg, sizeof lem->msg - 1, "%s", "DEVKMSG");
+       lem->header.len = lem->header.tag_len + 1; // plus NULL delimiter
        lem->header.len += 1 + snprintf(lem->msg + lem->header.len, sizeof lem->msg - 1 - lem->header.len, "%s", msg_begin);
 
        lem->header.len += sizeof(struct logger_entry);
@@ -158,6 +159,7 @@ void parse_androidlogger_message(struct android_logger_entry *ale, struct logger
        assert(payload_size <= LOG_MAX_PAYLOAD_SIZE);
 
        le->tag_len = -1;
+       le->priority = ale->msg[0];
        for (int i = 1 /* 0 is prio */; i < payload_size; ++i) {
                if (ale->msg[i] != '\0')
                        continue;
@@ -174,7 +176,7 @@ void parse_androidlogger_message(struct android_logger_entry *ale, struct logger
        le->tid = ale->tid;
        le->sec = ale->sec_sent;
        le->nsec = ale->nsec_sent;
-       memmove(le->msg, ale->msg, payload_size);
+       memmove(le->msg, ale->msg + 1, payload_size - 1);
 }
 
 void parse_pipe_message(struct pipe_logger_entry *ple, struct logger_entry *le, size_t msg_size)
@@ -307,16 +309,15 @@ static void construct_logger_entry_from_syslog(struct logger_entry *le, int prio
        le->tag_len = strlen(tag);
        const int msg_len = strlen(msg) + 1;
 
-       le->len = sizeof(struct logger_entry) + le->tag_len + 1 + msg_len + 1;
+       le->len = sizeof(struct logger_entry) + le->tag_len + 1 + msg_len;
        le->pid = pid;
        le->tid = 0; // could be set to PID but this way it's explicit the TID is not known
        le->sec = mktime(timestamp);
        le->nsec = 0; // the timestamp does not have such precision
-       le->msg[0] = priority;
+       le->priority = priority;
 
-       char *const tag_begin = le->msg + 1;
-       char *const msg_begin = tag_begin + le->tag_len + 1;
-       memcpy(tag_begin, tag, le->tag_len + 1);
+       char *const msg_begin = le->msg + le->tag_len + 1;
+       memcpy(le->msg, tag, le->tag_len + 1);
        memcpy(msg_begin, msg, msg_len);
 }
 
index d453d50..7cc760e 100644 (file)
@@ -33,13 +33,14 @@ int check_print_line_tid_single(int line, log_format *p_format, pthread_t tid, b
 {
        struct logger_entry_with_msg entry;
 
-       entry.msg[1] = '\0'; /* empty tag */
-       entry.msg[2] = '\0'; /* empty msg */
+       entry.msg[0] = '\0'; /* empty tag */
+       entry.msg[1] = '\0'; /* empty msg */
+       entry.header.tag_len = 0;
        entry.header.pid = 0;
        entry.header.tid = tid;
-       entry.header.len = sizeof(struct logger_entry) + 3;
+       entry.header.priority = DLOG_DEBUG; // priority, for unmatched entries that have to face the global filter
+       entry.header.len = sizeof(struct logger_entry) + 2;
 
-       entry.msg[0] = DLOG_DEBUG; // priority, for unmatched entries that have to face the global filter
        if (expected != log_should_print_line(p_format, &entry.header)) {
                printf("Check in line %d for tid %lu failed to return %d \n", line, tid,
                        expected);
@@ -78,13 +79,14 @@ int check_print_line_pid_single(int line, log_format *p_format, pid_t pid, bool
 {
        struct logger_entry_with_msg entry;
 
-       entry.msg[1] = '\0'; /* empty tag */
-       entry.msg[2] = '\0'; /* empty msg */
+       entry.msg[0] = '\0'; /* empty tag */
+       entry.msg[1] = '\0'; /* empty msg */
+       entry.header.tag_len = 0;
        entry.header.tid = 0;
        entry.header.pid = pid;
-       entry.header.len = sizeof(struct logger_entry) + 3;
+       entry.header.priority = DLOG_DEBUG; // priority, for unmatched entries that have to face the global filter
+       entry.header.len = sizeof(struct logger_entry) + 2;
 
-       entry.msg[0] = DLOG_DEBUG; // priority, for unmatched entries that have to face the global filter
        if (expected != log_should_print_line(p_format, &entry.header)) {
                printf("Check in line %d for pid %d failed to return %d \n", line, pid,
                        expected);
@@ -126,11 +128,11 @@ int check_print_line_tag_prior(int line, log_format *p_format, char *tag, int pr
 
        entry.header.tid = 0;
        entry.header.pid = 0;
-       entry.msg[0] = priority;
-       strncpy(entry.msg + 1, tag, strlen(tag));
-       entry.msg[strlen(tag) + 1] = '\0'; /* tag delimiter */
-       entry.msg[strlen(tag) + 2] = '\0'; /* empty msg */
-       entry.header.len = sizeof(struct logger_entry) + strlen(tag) + 3;
+       entry.header.priority = priority;
+       strncpy(entry.msg, tag, strlen(tag));
+       entry.msg[strlen(tag)] = '\0'; /* tag delimiter */
+       entry.msg[strlen(tag) + 1] = '\0'; /* empty msg */
+       entry.header.len = sizeof(struct logger_entry) + strlen(tag) + 2;
 
        if (expected != log_should_print_line(p_format, &entry.header)) {
                printf("Check in line %d for tag %s and priority %c failed to return %d \n", line, tag,
@@ -227,11 +229,11 @@ int main()
 
        const size_t taglen = strlen("crap");
 
-       entry.msg[0] = DLOG_VERBOSE;
-       strncpy(entry.msg + 1, "crap", taglen);
-       entry.msg[taglen + 1] = '\0'; /* tag delimiter */
-       entry.msg[taglen + 2] = '\0'; /* empty msg */
-       entry.header.len = sizeof(struct logger_entry) + taglen + 3;
+       entry.header.priority = DLOG_VERBOSE;
+       strncpy(entry.msg, "crap", taglen);
+       entry.msg[taglen] = '\0'; /* tag delimiter */
+       entry.msg[taglen + 1] = '\0'; /* empty msg */
+       entry.header.len = sizeof(struct logger_entry) + taglen + 2;
 
        assert(log_should_print_line(p_format, &entry.header));
        result += check_print_line_tag(__LINE__, p_format, "crap", verbose | debug | info | warn | error | fatal);
index 515b1b6..d6d5cb8 100644 (file)
@@ -32,9 +32,9 @@ int main()
 
        assert(le->pid == getpid());
        assert(le->tid == gettid());
-       assert(le->msg[0] == prio);
-       assert(!strcmp(le->msg + 1, tag));
-       assert(!strcmp(le->msg + sizeof(tag) + 1, msg));
+       assert(le->priority == prio);
+       assert(!strcmp(le->msg, tag));
+       assert(!strcmp(le->msg + sizeof(tag), msg));
        assert(time_cmp(ts_pre,  le->sec, le->nsec) <= 0);
        assert(time_cmp(ts_post, le->sec, le->nsec) >= 0);
 
@@ -56,9 +56,9 @@ int main()
                create_pipe_message(ple, prio, random_tag, random_msg);
                parse_pipe_message(ple, le, ple->len);
                clock_gettime(CLOCK_MONOTONIC, &ts_post);
-               assert(le->msg[0] == prio);
-               assert(!strcmp(le->msg + 1, random_tag));
-               assert(!strcmp(le->msg + strlen(random_tag) + 2, random_msg));
+               assert(le->priority == prio);
+               assert(!strcmp(le->msg, random_tag));
+               assert(!strcmp(le->msg + strlen(random_tag) + 1, random_msg));
                assert(le->pid == getpid());
                assert(le->tid == gettid());
                assert(time_cmp(ts_pre,  le->sec, le->nsec) <= 0);
index 28869a9..7388f8b 100644 (file)
@@ -46,7 +46,7 @@ int main()
        assert(!parse_syslog_datagram(buffer, len, sle));
 
        assert(sle->pid == 678);
-       assert(log_buffer_get_priority(sle) == DLOG_FATAL);
+       assert(sle->priority == DLOG_FATAL);
        assert(!strcmp("SYSLOG_USER", log_buffer_get_tag(sle)));
        assert(!strcmp("msg", log_buffer_get_message(sle)));
 
@@ -55,7 +55,7 @@ int main()
        assert(!parse_syslog_datagram(buffer, len, sle));
 
        assert(sle->pid == 0);
-       assert(log_buffer_get_priority(sle) == DLOG_FATAL);
+       assert(sle->priority == DLOG_FATAL);
        assert(!strcmp("SYSLOG_USER", log_buffer_get_tag(sle)));
        assert(!strcmp("msg", log_buffer_get_message(sle)));
 
index cd1257a..52104d2 100644 (file)
@@ -22,7 +22,7 @@
 
 #define STR1 "a"
 
-#define LE(str, tsec, tnsec) {{sizeof(struct logger_entry)+sizeof(str)+1, 0, 1, 1, (tsec), (tnsec), 0U, 0U, 0U, 0U}, str}
+#define LE(str, tsec, tnsec) {{sizeof(struct logger_entry)+sizeof(str)+1, 0, 0, 1, 1, (tsec), (tnsec), 0U, 0U, 0U, 0U, 0U}, str}
 
 void dont_call_this_callback(const struct logger_entry *le, void *user_data)
 {