dlogutil: add pid and tid based filtering 52/170252/15
authorMaciej Slodczyk <m.slodczyk2@partner.samsung.com>
Thu, 15 Feb 2018 12:29:46 +0000 (13:29 +0100)
committerMichal Bloch <m.bloch@samsung.com>
Wed, 7 Mar 2018 13:35:40 +0000 (14:35 +0100)
Add dlogutil command line options to specify pid and tid
list to be passed to daemon and filter log output by.

Change-Id: Icf233d8e01fec32a25ca2ec28791bf4e7642222f
Signed-off-by: Maciej Slodczyk <m.slodczyk2@partner.samsung.com>
include/logprint.h
src/logger/logger.c
src/logutil/logutil.c
src/logutil/logutil_doc.h
src/logutil/sort_vector.c
src/shared/log_file.c
src/shared/logprint.c
src/tests/filters.c

index 31c4155..b5bc882 100644 (file)
@@ -100,12 +100,42 @@ int log_add_filter_rule(log_format *p_format, const char *filterExpression);
 
 int log_add_filter_string(log_format *p_format, const char *filterString);
 
+
+/**
+ * pid: an int with a pid of a log source process,
+ * can be added multiple times with different values
+ * (in that case log_should_print_line() will logically
+ * OR all filter pid values to make a decision)
+ *
+ * returns 0 on success and -1 on invalid expression
+ *
+ * Assumes single threaded execution
+ *
+ */
+
+int log_add_filter_pid(log_format *p_format, pid_t pid);
+
+
+/**
+ * tid: an int with a tid of a log source thread,
+ * can be added multiple times with different values
+ * (in that case log_should_print_line() will logically
+ * OR all filter tid values to make a decision)
+ *
+ * returns 0 on success and -1 on invalid expression
+ *
+ * Assumes single threaded execution
+ *
+ */
+
+int log_add_filter_tid(log_format *p_format, pthread_t tid);
+
 /**
- * returns true if this log line should be printed based on its priority
- * and tag, and false if it should not
+ * returns true if this log line should be printed based on its entry
+ * data (priority, tag, pid and tid), and false if it should not
  */
 bool log_should_print_line(
-               log_format *p_format, const char *tag, log_priority pri);
+               log_format *p_format, log_entry *entry);
 
 /**
  * Splits a wire-format buffer into an log_entry
index fc9003f..d140e16 100755 (executable)
@@ -872,6 +872,7 @@ static int print_out_logs(struct logger *server, struct reader *reader)
        char tmp[LOG_MAX_SIZE];
        char * tag;
        unsigned from = reader->current;
+       log_entry entry;
 
        int plaintext = reader->file.path && buf_writes_to_plaintext(reader->buf_ptr->id);
 
@@ -911,13 +912,11 @@ static int print_out_logs(struct logger *server, struct reader *reader)
                        continue;
                }
 
-               log_priority priority = log_priority_from_char(ple->msg[0]);
-
                tag = ple->msg + 1;
                if (!strlen(tag))
                        continue;
 
-               if (!log_should_print_line(reader->file.format, tag, priority))
+               if (log_process_log_buffer(ple, &entry) || !log_should_print_line(reader->file.format, &entry))
                        continue;
 
                r = write(reader->file.path ? reader->file.fd : reader->fd_entity.fd, ple, ple->len);
index 3e05c02..bc83a4a 100755 (executable)
@@ -199,6 +199,8 @@ int parse_options(int argc, char **argv, struct log_file *l_file, struct sort_ve
        while (1) {
                static const struct option long_options[] = {
                        {"dumpfile", required_argument, 0, 0},
+                       {"tid", required_argument, 0, 1},
+                       {"pid", required_argument, 0, 2},
                        {"help", no_argument, 0, 'h'},
                        {0, 0, 0, 0}
                };
@@ -212,6 +214,22 @@ int parse_options(int argc, char **argv, struct log_file *l_file, struct sort_ve
                case 0:
                        list_add(file_input_names, optarg);
                        break;
+               case 1: { /* tid filter */
+                       int tid;
+                       if (sscanf(optarg, "%d", &tid) == 1)
+                               log_add_filter_tid(l_file->format, tid);
+                       else
+                               err_arg_nondigit = 1;
+                       break;
+               }
+               case 2: { /* pid filter */
+                       int pid;
+                       if (sscanf(optarg, "%d", &pid) == 1)
+                               log_add_filter_pid(l_file->format, pid);
+                       else
+                               err_arg_nondigit = 1;
+                       break;
+               }
                case 'd':
                        *dump = -1;
                        break;
index 99da685..1065f78 100644 (file)
@@ -56,6 +56,8 @@ static void show_help(const char *cmd)
                "                    the default set is main + system + apps\n"
                "  -u <size>         Sets the initial size of sort buffer (0 to disable sorting)\n"
                "                    Smaller is faster but lowers sorting quality\n"
+               "  --pid <pid>       Filter messages by process id\n"
+               "  --tid <tid>       Filter messages by thread id\n"
                "  -h or --help      show this help\n"
                "  --dumpfile <file> only for pipe backend. Parses a dlog_logger daemon generated file\n"
                "filterspecs are a series of\n<tag>[*][:priority]\n and \n<prefix>*[:=priority]\n"
index 53e298a..42b3dec 100644 (file)
@@ -129,7 +129,7 @@ int sort_vector_push(struct sort_vector *logs, struct logger_entry *p, struct lo
        log_entry entry;
 
        if (log_process_log_buffer(p, &entry) ||
-               !log_should_print_line(l_file->format, entry.tag, entry.priority)) {
+               !log_should_print_line(l_file->format, &entry)) {
                free(p);
                return -EPERM;
        }
index 17f6761..be89979 100644 (file)
@@ -219,7 +219,7 @@ void logfile_do_rotate(struct log_file *file)
 int logfile_write_with_rotation(struct logger_entry *e, struct log_file *file)
 {
        log_entry entry;
-       if (log_process_log_buffer(e, &entry) || !log_should_print_line(file->format, entry.tag, entry.priority))
+       if (log_process_log_buffer(e, &entry) || !log_should_print_line(file->format, &entry))
                return 1;
        int written_bytes = log_print_log_line(file->format, file->fd, &entry);
        if (written_bytes <= 0)
index dbfdf59..72e6a79 100644 (file)
@@ -16,6 +16,7 @@
  * limitations under the License.
  */
 
+#include <assert.h>
 #include <stdbool.h>
 #include <stdio.h>
 #include <stdlib.h>
  * @{
  */
 
+#define FILTERINFO_PID_NONE -1
+#define FILTERINFO_TID_NONE -1
+
+struct tag_and_prio {
+       char *tag;
+       int tagLength;
+       log_priority pri;
+       bool exactPri;
+       bool prefix;
+};
+
 typedef struct FilterInfo_t {
-       char *mTag;
-       int mTagLength;
+       enum {
+               FILTER_TAG_AND_PRIO,
+               FILTER_PID,
+               FILTER_TID,
+       } type;
+       union {
+               struct tag_and_prio tnp;
+               pid_t pid;
+               pthread_t tid;
+       };
        struct FilterInfo_t *p_next;
-       log_priority mPri;
-       bool mExactPri;
-       bool mPrefix;
 } FilterInfo;
 
 struct log_format_t {
@@ -42,7 +59,6 @@ struct log_format_t {
        log_print_format format;
        log_priority global_pri;
        bool exact_global_pri;
-
 };
 
 /**
@@ -55,27 +71,53 @@ struct log_format_t {
  * @return The new structure (or NULL if allocation failed).
  * @see filterinfo_free
  */
-static FilterInfo * filterinfo_new(const char *tag, log_priority pri, bool prefix,  bool exactPri)
+static FilterInfo *filterinfo_new(const char *tag, log_priority pri, bool prefix, bool exactPri, pid_t pid, pthread_t tid)
 {
        FilterInfo *p_ret = (FilterInfo *)calloc(1, sizeof(FilterInfo));
        if (!p_ret)
                return NULL;
 
-       p_ret->mTag = strdup(tag);
-
-       if (!p_ret->mTag) {
-               free(p_ret);
-               return NULL;
+       if (tag) {
+               p_ret->type = FILTER_TAG_AND_PRIO;
+               p_ret->tnp.tag = strdup(tag);
+               if (!p_ret->tnp.tag) {
+                       free(p_ret);
+                       return NULL;
+               }
+               p_ret->tnp.tagLength = strlen(p_ret->tnp.tag);
+               p_ret->tnp.pri = pri;
+               p_ret->tnp.exactPri = exactPri;
+               p_ret->tnp.prefix = prefix;
+       } else if (pid != FILTERINFO_PID_NONE) {
+               p_ret->type = FILTER_PID;
+               p_ret->pid = pid;
+       } else if (tid != FILTERINFO_TID_NONE) {
+               p_ret->type = FILTER_TID;
+               p_ret->tid = tid;
+       } else {
+               assert(false);
        }
 
-       p_ret->mTagLength = strlen(p_ret->mTag);
-       p_ret->mPri = pri;
-       p_ret->mExactPri = exactPri;
-       p_ret->mPrefix = prefix;
-
        return p_ret;
 }
 
+static FilterInfo *filterinfo_clone(FilterInfo *p_info)
+{
+       assert(p_info);
+
+       switch (p_info->type) {
+       case FILTER_TAG_AND_PRIO:
+               return filterinfo_new(p_info->tnp.tag, p_info->tnp.pri, p_info->tnp.exactPri, p_info->tnp.prefix, FILTERINFO_PID_NONE, FILTERINFO_TID_NONE);
+       case FILTER_PID:
+               return filterinfo_new(NULL, 0, false, false, p_info->pid, FILTERINFO_TID_NONE);
+       case FILTER_TID:
+               return filterinfo_new(NULL, 0, false, false, FILTERINFO_PID_NONE, p_info->tid);
+       default:
+               assert(false);
+               return NULL;
+       }
+}
+
 /**
  * @brief Deallocate filter info
  * @details Deallocates the entire filter info structure
@@ -87,8 +129,11 @@ static void filterinfo_free(FilterInfo *p_info)
        if (p_info == NULL)
                return;
 
-       free(p_info->mTag);
-       p_info->mTag = NULL;
+       if (p_info->type == FILTER_TAG_AND_PRIO) {
+               free(p_info->tnp.tag);
+               p_info->tnp.tag = NULL;
+       }
+
        free(p_info);
 }
 
@@ -168,37 +213,55 @@ char filter_pri_to_char(log_priority pri)
  * @brief Filter a line
  * @details Passes a line through filters to discover whether it should be logged or not
  * @param[in] p_format The format to work with
- * @param[in] tag The line's tag
- * @param[in] pri The line's priority
- * @return true if the line should be printed, else false
+ * @param[in] entry The log entry to filter
+ * @return True if the line should be printed, else false
  */
-bool log_should_print_line(log_format *p_format, const char *tag, log_priority pri)
+bool log_should_print_line(log_format *p_format, log_entry *entry)
 {
+       assert(p_format);
+       assert(entry);
+
        FilterInfo *p_curFilter;
        bool prefix;
        bool matched = false;
-
        for (p_curFilter = p_format->filters; p_curFilter != NULL; p_curFilter = p_curFilter->p_next) {
-               prefix = p_curFilter->mPrefix;
-               if ((prefix && (0 == strncmp(tag, p_curFilter->mTag, p_curFilter->mTagLength))) ||
-                   (!prefix && (0 == strcmp(tag, p_curFilter->mTag)))) {
-                       matched = true;
-                       if (p_curFilter->mExactPri) {
-                               if (pri == p_curFilter->mPri)
-                                       return true;
-                       } else {
-                               if (pri >= p_curFilter->mPri)
-                                       return true;
+               switch (p_curFilter->type) {
+               case FILTER_TAG_AND_PRIO:
+                       prefix = p_curFilter->tnp.prefix;
+                       if ((prefix && (0 == strncmp(entry->tag, p_curFilter->tnp.tag, p_curFilter->tnp.tagLength))) ||
+                           (!prefix && (0 == strcmp(entry->tag, p_curFilter->tnp.tag)))) {
+                               matched = true;
+                               if (p_curFilter->tnp.exactPri) {
+                                       if (entry->priority == p_curFilter->tnp.pri)
+                                               return true;
+                               } else {
+                                       if (entry->priority >= p_curFilter->tnp.pri)
+                                               return true;
+                               }
                        }
+                       break;
+               case FILTER_PID:
+                       matched = true;
+                       if (entry->pid == p_curFilter->pid)
+                               return true;
+                       break;
+               case FILTER_TID:
+                       matched = true;
+                       if (entry->tid == p_curFilter->tid)
+                               return true;
+                       break;
+               default:
+                       assert(false);
                }
+
        }
        if (matched)
                return false;
 
        if (p_format->exact_global_pri)
-               return (pri == p_format->global_pri);
+               return (entry->priority == p_format->global_pri);
        else
-               return (pri >= p_format->global_pri);
+               return (entry->priority >= p_format->global_pri);
 }
 
 /**
@@ -242,8 +305,8 @@ log_format *log_format_from_format(log_format *p_format)
        p_info = p_format->filters;
 
        while (p_info != NULL) {
-               FilterInfo *p_tmp;
-               p_tmp = filterinfo_new(p_info->mTag, p_info->mPri, p_info->mExactPri, p_info->mPrefix);
+               FilterInfo *p_tmp = filterinfo_clone(p_info);
+
                if (!p_tmp) {
                        log_format_free(p_ret);
                        return NULL;
@@ -391,7 +454,7 @@ int log_add_filter_rule(log_format *p_format,
                if (!tagName)
                        goto error;
 
-               FilterInfo *p_fi = filterinfo_new(tagName, pri, pattern, exact);
+               FilterInfo *p_fi = filterinfo_new(tagName, pri, pattern, exact, FILTERINFO_PID_NONE, FILTERINFO_TID_NONE);
                free(tagName);
                if (!p_fi)
                        goto error;
@@ -442,6 +505,50 @@ error:
 }
 
 /**
+ * @brief Add pid to filter by
+ * @details Adds a single pid filtering rule
+ * @param[in] p_format The log format to add the filter rules to
+ * @param[in] pid A pid to filter by
+ * @return 0 on success, else -ENOMEM
+ * @remarks Assumes single threaded execution
+ */
+int log_add_filter_pid(log_format *p_format, pid_t pid)
+{
+       assert(p_format);
+
+       FilterInfo *p_fi = filterinfo_new(NULL, 0, false, false, pid, FILTERINFO_TID_NONE);
+       if (!p_fi)
+               return -ENOMEM;
+
+       p_fi->p_next = p_format->filters;
+       p_format->filters = p_fi;
+
+       return 0;
+}
+
+/**
+ * @brief Add tid to filter by
+ * @details Adds a single tid filtering rule
+ * @param[in] p_format The log format to add the filter rules to
+ * @param[in] pid A tid to filter by
+ * @return 0 on success, else -ENOMEM
+ * @remarks Assumes single threaded execution
+ */
+int log_add_filter_tid(log_format *p_format, pthread_t tid)
+{
+       assert(p_format);
+
+       FilterInfo *p_fi = filterinfo_new(NULL, 0, false, false, FILTERINFO_PID_NONE, tid);
+       if (!p_fi)
+               return -ENOMEM;
+
+       p_fi->p_next = p_format->filters;
+       p_format->filters = p_fi;
+
+       return 0;
+}
+
+/**
  * @brief Preprocess a log buffer for printing
  * @details Converts a log entry into a printable format
  * @param[in] entry_raw The raw entry to convert
index 768a847..b6d182f 100644 (file)
@@ -12,6 +12,98 @@ enum {
        fatal   = (1 << 5),
 };
 
+int pid_tid_filter_list[] = {
+       1234,
+       2345,
+       34567,
+       98273545,
+       1,
+};
+
+/**
+ * @brief Checks if a log message with a tid is printed as expected
+ * @details Verify the log_should_print_line function returns the expected value
+ * @param[in] line The number of source code line in this file, printed in debug messages
+ * @param[in] p_format The format to work with
+ * @param[in] tid The tid to filter with
+ * @param[in] expected The expected result returned by log_should_print_line function
+ * @return 0 if the log_should_print_line returns the expected result, 1 otherwise
+ */
+int check_print_line_tid_single(int line, log_format *p_format, pthread_t tid, bool expected)
+{
+       log_entry entry;
+
+       entry.tag = NULL;
+       entry.pid = 0;
+       entry.tid = tid;
+       entry.priority = DLOG_DEBUG; // for unmatched entries that have to face the global filter
+       if (expected != log_should_print_line(p_format, &entry)) {
+               printf("Check in line %d for tid %lu failed to return %d \n", line, tid,
+                       expected);
+               return 1;
+       }
+       return 0;
+}
+
+/**
+ * @brief Checks if a log message if filtered properly for a group of tids
+ * @details Verify the log_should_print_line function returns the expected values
+ * @param[in] line The number of line in test, printed in debug messages
+ * @param[in] p_format The format to work with
+ * @param[in] tid The tid to filter with
+ * @return Number of tids for which log_should_print_line returns wrong answer
+ */
+
+int check_print_line_tid(int line, log_format *p_format, pthread_t tid)
+{
+       int result = 0;
+       for (int tid_no = 0; tid_no < NELEMS(pid_tid_filter_list); tid_no++)
+               result += check_print_line_tid_single(line, p_format, pid_tid_filter_list[tid_no], (pid_tid_filter_list[tid_no] == tid));
+       return result;
+}
+
+/**
+ * @brief Checks if a log message with a pid is printed as expected
+ * @details Verify the log_should_print_line function returns the expected value
+ * @param[in] line The number of source code line in this file, printed in debug messages
+ * @param[in] p_format The format to work with
+ * @param[in] pid The pid to filter with
+ * @param[in] expected The expected result returned by log_should_print_line function
+ * @return 0 if the log_should_print_line returns the expected result, 1 otherwise
+ */
+int check_print_line_pid_single(int line, log_format *p_format, pid_t pid, bool expected)
+{
+       log_entry entry;
+
+       entry.tag = NULL;
+       entry.tid = 0;
+       entry.pid = pid;
+       entry.priority = DLOG_DEBUG; // for unmatched entries that have to face the global filter
+       if (expected != log_should_print_line(p_format, &entry)) {
+               printf("Check in line %d for pid %d failed to return %d \n", line, pid,
+                       expected);
+               return 1;
+       }
+       return 0;
+}
+
+/**
+ * @brief Checks if a log message if filtered properly for a group of pids
+ * @details Verify the log_should_print_line function returns the expected values
+ * @param[in] line The number of line in test, printed in debug messages
+ * @param[in] p_format The format to work with
+ * @param[in] pid The pid to filter with
+ * @return Number of pids for which log_should_print_line returns wrong answer
+ */
+
+int check_print_line_pid(int line, log_format *p_format, pid_t pid)
+{
+       int result = 0;
+       for (int pid_no = 0; pid_no < NELEMS(pid_tid_filter_list); pid_no++)
+               result += check_print_line_pid_single(line, p_format, pid_tid_filter_list[pid_no], (pid_tid_filter_list[pid_no] == pid));
+       return result;
+}
+
 /**
  * @brief Checks if a log message with a tag and priority is printed as expected
  * @details Verify the log_should_print_line function returns the expected value
@@ -22,9 +114,15 @@ enum {
  * @param[in] expected The expected result returned by log_should_print_line function
  * @return 0 if the log_should_print_line returns the expected result, 1 otherwise
  */
-int check_print_line_tag_prior(int line, log_format *p_format, const char *tag, int priority, bool expected)
+int check_print_line_tag_prior(int line, log_format *p_format, char *tag, int priority, bool expected)
 {
-       if (expected != log_should_print_line(p_format, tag, priority)) {
+       log_entry entry;
+
+       entry.tid = 0;
+       entry.pid = 0;
+       entry.tag = tag;
+       entry.priority = priority;
+       if (expected != log_should_print_line(p_format, &entry)) {
                printf("Check in line %d for tag %s and priority %c failed to return %d \n", line, tag,
                        filter_pri_to_char(priority), expected);
                return 1;
@@ -42,7 +140,7 @@ int check_print_line_tag_prior(int line, log_format *p_format, const char *tag,
  * @return Number of priorities for which log_should_print_line returns wrong answer
  */
 
-int check_print_line_tag(int line, log_format *p_format, const char *tag, int priors)
+int check_print_line_tag(int line, log_format *p_format, char *tag, int priors)
 {
        int result = 0;
        result += check_print_line_tag_prior(line, p_format, tag, DLOG_VERBOSE, (priors & verbose) > 0);
@@ -58,8 +156,9 @@ int main()
 {
        int err;
        int result = 0;
-       const char *tag, *tag_short, *tag_middle, *tag_long;
+       char *tag, *tag_short, *tag_middle, *tag_long;
        log_format *p_format;
+       log_entry entry;
 
        p_format = log_format_new();
 
@@ -112,7 +211,9 @@ int main()
 
 
        log_add_filter_rule(p_format, "crap:*");
-       assert(log_should_print_line(p_format, "crap", DLOG_VERBOSE));
+       entry.priority = DLOG_VERBOSE;
+       entry.tag = "crap";
+       assert(log_should_print_line(p_format, &entry));
        result += check_print_line_tag(__LINE__, p_format, "crap", verbose | debug | info | warn | error | fatal);
        result += check_print_line_tag(__LINE__, p_format, tag, verbose | debug | info | warn | error | fatal);
        result += check_print_line_tag(__LINE__, p_format, tag_short, info | warn | error | fatal);
@@ -234,6 +335,28 @@ int main()
        result += check_print_line_tag(__LINE__, p_format, tag, 0);
        log_format_free(p_format);
 
+       //pid filtering rules
+       p_format = log_format_new();
+       result += check_print_line_pid(__LINE__, p_format, 0);
+       err = log_add_filter_pid(p_format, 9876);
+       assert(err == 0);
+       result += check_print_line_pid(__LINE__, p_format, 9876);
+       err = log_add_filter_pid(p_format, pid_tid_filter_list[0]);
+       assert(err == 0);
+       result += check_print_line_pid(__LINE__, p_format, pid_tid_filter_list[0]);
+       log_format_free(p_format);
+
+       //tid filtering rules
+       p_format = log_format_new();
+       result += check_print_line_tid(__LINE__, p_format, 0);
+       err = log_add_filter_tid(p_format, 9876);
+       assert(err == 0);
+       result += check_print_line_tid(__LINE__, p_format, 9876);
+       err = log_add_filter_tid(p_format, pid_tid_filter_list[0]);
+       assert(err == 0);
+       result += check_print_line_tid(__LINE__, p_format, pid_tid_filter_list[0]);
+       log_format_free(p_format);
+
        if (result > 0)
                exit(-1);
        return 0;