projects / platform / core / system / dlog.git / commitdiff
? search:
summary | shortlog | log | commit | commitdiff | tree
raw | patch | inline | side by side (parent: e9b6f1f)
Add PID-limit exceeded message 37/241337/2
authorMateusz Majewski <m.majewski2@samsung.com>
Wed, 19 Aug 2020 08:48:52 +0000 (10:48 +0200)
committerMichal Bloch <m.bloch@partner.samsung.com>
Wed, 19 Aug 2020 15:54:48 +0000 (15:54 +0000)
Change-Id: I06ece67a40a38a2128eb7e3ddd3f4f536c48fac2

include/loglimiter.h patch | blob | history
src/libdlog/log.c patch | blob | history
src/shared/loglimiter.c patch | blob | history
src/tests/pid_limiter.c patch | blob | history
tests/dlog_test.in patch | blob | history

diff --git a/include/loglimiter.h b/include/loglimiter.h
index c3ae5c0..a6cec33 100644 (file)
--- a/include/loglimiter.h
+++ b/include/loglimiter.h
@@ -57,6 +57,7 @@ struct pass_log_result {
                DECISION_ALLOWED,
                DECISION_DENIED,
                DECISION_TAG_LIMIT_EXCEEDED_MESSAGE,
+               DECISION_PID_LIMIT_EXCEEDED_MESSAGE,
        } decision;
 
        int logs_per_period;
diff --git a/src/libdlog/log.c b/src/libdlog/log.c
index a989744..bbf9480 100644 (file)
--- a/src/libdlog/log.c
+++ b/src/libdlog/log.c
@@ -312,14 +312,16 @@ static int dlog_check_limiter(log_id_t log_id, int prio, const char *tag)
                        case DECISION_DENIED:
                                return DLOG_ERROR_NOT_PERMITTED;
 
-                       case DECISION_TAG_LIMIT_EXCEEDED_MESSAGE: {
+                       case DECISION_TAG_LIMIT_EXCEEDED_MESSAGE:
+                       case DECISION_PID_LIMIT_EXCEEDED_MESSAGE: {
                                struct timespec tp;
                                int result = clock_gettime(CLOCK_MONOTONIC, &tp);
                                if (result < 0)
                                        return DLOG_ERROR_NOT_PERMITTED;
                                char buf[100] = {};
                                snprintf(buf, sizeof(buf),
-                                               "Your log has been blocked due to per-tag limit of %d logs per %d seconds.",
+                                               "Your log has been blocked due to per-%s limit of %d logs per %d seconds.",
+                                               should_log.decision == DECISION_TAG_LIMIT_EXCEEDED_MESSAGE ? "tag" : "PID",
                                                should_log.logs_per_period, should_log.period_s);
                                write_to_log(log_id, prio, tag, buf, &tp);
                                return DLOG_ERROR_NOT_PERMITTED;
diff --git a/src/shared/loglimiter.c b/src/shared/loglimiter.c
index c573ffa..8324174 100644 (file)
--- a/src/shared/loglimiter.c
+++ b/src/shared/loglimiter.c
@@ -71,7 +71,7 @@ static size_t sent_by_me = 0;
 static time_t last_pid_time = -1;
 static time_t refresh_rate_s = -1;
 static pid_t prev_pid = -1;
-static bool block_by_pid()
+static struct pass_log_result block_by_pid()
 {
        const pid_t my_pid = getpid();
 
@@ -99,20 +99,28 @@ static bool block_by_pid()
        }
 
        if (cached_pid_rule->limit > __LOG_LIMITER_LIMIT_MAX)
-               return false;
+               return (struct pass_log_result) { .decision = DECISION_ALLOWED, };
 
        prev_pid = my_pid;
        if (++sent_by_me <= cached_pid_rule->limit)
-               return false;
+               return (struct pass_log_result) { .decision = DECISION_ALLOWED, };
 
        const time_t now = time(NULL);
-       if (now < last_pid_time + refresh_rate_s)
-               return true;
-
-       last_pid_time = now;
-       sent_by_me = 0;
+       if (now >= last_pid_time + refresh_rate_s) {
+               last_pid_time = now;
+               sent_by_me = 1;
+       }
 
-       return ++sent_by_me > cached_pid_rule->limit;
+       if (sent_by_me <= cached_pid_rule->limit)
+               return (struct pass_log_result) { .decision = DECISION_ALLOWED, };
+       else if (sent_by_me == cached_pid_rule->limit + 1)
+               return (struct pass_log_result) {
+                       .decision = DECISION_PID_LIMIT_EXCEEDED_MESSAGE,
+                       .logs_per_period = cached_pid_rule->limit,
+                       .period_s = refresh_rate_s,
+               };
+       else
+               return (struct pass_log_result) { .decision = DECISION_DENIED, };
 }
 
 static void rules_destroy(struct rule **rlist)
@@ -412,8 +420,9 @@ struct limiter_limits __log_limiter_get_limits(const char *tag, int prio)
  */
 struct pass_log_result __log_limiter_pass_log(const char* tag, int prio)
 {
-       if (block_by_pid())
-               return (struct pass_log_result) { .decision = DECISION_DENIED, };
+       struct pass_log_result pid_result = block_by_pid();
+       if (pid_result.decision != DECISION_ALLOWED)
+               return pid_result;
 
        if (!rules_hashmap)
                return (struct pass_log_result) { .decision = DECISION_ALLOWED, };
diff --git a/src/tests/pid_limiter.c b/src/tests/pid_limiter.c
index 8d5a52f..6c28cce 100644 (file)
--- a/src/tests/pid_limiter.c
+++ b/src/tests/pid_limiter.c
@@ -36,26 +36,31 @@ int main()
        __log_limiter_update(&conf);
 
 #define PASS  assert(__log_limiter_pass_log("FOO", 'W').decision == DECISION_ALLOWED)
+#define MSG   assert(__log_limiter_pass_log("FOO", 'W').decision == DECISION_PID_LIMIT_EXCEEDED_MESSAGE)
 #define BLOCK assert(__log_limiter_pass_log("FOO", 'W').decision == DECISION_DENIED)
 
        pid_ret = 77;
        for (int i =   0; i <   7; ++i) PASS;
-       for (int i =   7; i < 100; ++i) BLOCK;
+       for (int i =   7; i <   8; ++i) MSG;
+       for (int i =   8; i < 100; ++i) BLOCK;
        __log_limiter_update(&conf); // shouldn't have any effect
        for (int i = 100; i < 200; ++i) BLOCK;
 
        advance_clock();
 
        for (int i =   0; i <   7; ++i) PASS;
-       for (int i =   7; i < 100; ++i) BLOCK;
+       for (int i =   7; i <   8; ++i) MSG;
+       for (int i =   8; i < 100; ++i) BLOCK;
        pid_ret = 55; // pid change emulates a fork
        for (int i =   0; i < 125; ++i) PASS;
-       for (int i = 125; i < 333; ++i) BLOCK;
+       for (int i = 125; i < 126; ++i) MSG;
+       for (int i = 126; i < 333; ++i) BLOCK;
 
        advance_clock();
 
        for (int i =   0; i < 125; ++i) PASS;
-       for (int i = 125; i < 666; ++i) BLOCK;
+       for (int i = 125; i < 126; ++i) MSG;
+       for (int i = 126; i < 333; ++i) BLOCK;
 
        log_config_remove(&conf, "pidlimit|55");
        __log_limiter_update(&conf);
@@ -63,7 +68,8 @@ int main()
 
        for (int i = 0; i < 1936; ++i) PASS;
        pid_ret = 88;
-       for (int i = 0; i < 1939; ++i) BLOCK; // ¡No pasarán!
+       for (int i = 0; i <    1; ++i) MSG;
+       for (int i = 1; i < 1939; ++i) BLOCK; // ¡No pasarán!
        pid_ret = 99;
        for (int i = 0; i < 1975; ++i) PASS; // Hemos pasado
 
diff --git a/tests/dlog_test.in b/tests/dlog_test.in
index 82f206a..abd84be 100644 (file)
--- a/tests/dlog_test.in
+++ b/tests/dlog_test.in
@@ -715,11 +715,13 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
                dlogctl --pid $DLOGSEND_PID -s deny
                kill -s CONT $DLOGSEND_PID
                wait $DLOGSEND_PID
-               LOG_DETAILS="testing if PID limiting works (1/10)"
-               [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 0 ]] && ok || fail
-               LOG_DETAILS="testing if PID limiting works (2/10)"
+               LOG_DETAILS="testing if PID limiting works (1/14)"
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep -v blocked | wc -l) -eq 0 ]] && ok || fail
+               LOG_DETAILS="testing if PID limiting works (2/14)"
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep blocked | wc -l) -eq 1 ]] && ok || fail
+               LOG_DETAILS="testing if PID limiting works (3/14)"
                [[ $(dlogctl --pid $DLOGSEND_PID -g) == "Denied" ]] && ok || fail
-               LOG_DETAILS="testing if PID limiting works (3/10)"
+               LOG_DETAILS="testing if PID limiting works (4/14)"
                dlogctl -g | grep -q "Denied for $DLOGSEND_PID" && ok || fail
 
                sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' &
@@ -728,11 +730,13 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
                dlogctl --pid $DLOGSEND_PID -s 25
                kill -s CONT $DLOGSEND_PID
                wait $DLOGSEND_PID
-               LOG_DETAILS="testing if PID limiting works (4/10)"
-               [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 25 ]] && ok || fail
-               LOG_DETAILS="testing if PID limiting works (5/10)"
+               LOG_DETAILS="testing if PID limiting works (5/14)"
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep -v blocked | wc -l) -eq 25 ]] && ok || fail
+               LOG_DETAILS="testing if PID limiting works (6/14)"
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep blocked | wc -l) -eq 1 ]] && ok || fail
+               LOG_DETAILS="testing if PID limiting works (7/14)"
                [[ $(dlogctl --pid $DLOGSEND_PID -g) == '25 logs/min' ]] && ok || fail
-               LOG_DETAILS="testing if PID limiting works (6/10)"
+               LOG_DETAILS="testing if PID limiting works (8/14)"
                dlogctl -g | grep -q "25 logs/min for $DLOGSEND_PID" && ok || fail
 
                sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' &
@@ -741,11 +745,13 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
                dlogctl --pid $DLOGSEND_PID -s allow
                kill -s CONT $DLOGSEND_PID
                wait $DLOGSEND_PID
-               LOG_DETAILS="testing if PID limiting works (7/10)"
-               [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 100 ]] && ok || fail
-               LOG_DETAILS="testing if PID limiting works (8/10)"
+               LOG_DETAILS="testing if PID limiting works (9/14)"
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep -v blocked | wc -l) -eq 100 ]] && ok || fail
+               LOG_DETAILS="testing if PID limiting works (10/14)"
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep blocked | wc -l) -eq 0 ]] && ok || fail
+               LOG_DETAILS="testing if PID limiting works (11/14)"
                [[ $(dlogctl --pid $DLOGSEND_PID -g) == 'Unlimited' ]] && ok || fail
-               LOG_DETAILS="testing if PID limiting works (9/10)"
+               LOG_DETAILS="testing if PID limiting works (12/14)"
                dlogctl -g | grep -q "Unlimited for $DLOGSEND_PID" && ok || fail
 
                echo "qos_refresh_rate_s=5" > "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf"
@@ -756,10 +762,12 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
                kill -s CONT $DLOGSEND_PID
                wait $DLOGSEND_PID
                rm "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf"
-               LOG_DETAILS="testing if PID limiting works (10/10)"
+               LOG_DETAILS="testing if PID limiting works (13/14)"
                # In each 5 second period, 5 logs are sent, so there are 3 periods.
                # 2 logs from each period are allowed.
-               [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 6 ]] && ok || fail
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep -v blocked | wc -l) -eq 6 ]] && ok || fail
+               LOG_DETAILS="testing if PID limiting works (14/14)"
+               [[ $(dlogutil --pid $DLOGSEND_PID -d | grep blocked | wc -l) -eq 3 ]] && ok || fail
 
                # TODO: HACK ALERT!
                # The following QoS tests make perfect sense for the pipe backend, since we kill the already
@@ -780,7 +788,7 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
 
                dlogsend -b main -t DLOG_QOS_TEST0 -c 30 -d 1 -f 2 "A normal app that just wants to log"
                LOG_DETAILS="testing if QoS works (1/4)"
-               [[ $(dlogutil -d DLOG_QOS_TEST0 | wc -l) -eq 30 ]] && ok || fail
+               [[ $(dlogutil -d DLOG_QOS_TEST0 | grep -v blocked | wc -l) -eq 30 ]] && ok || fail
                kill $LOGGER > /dev/null
                sleep 1
                if [ $type == "logger" ]; then
@@ -792,7 +800,7 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
 
                dlogsend -b main -t DLOG_QOS_TEST1 -c 300 -d 1 -f 20 "Some log spam"
                LOG_DETAILS="testing if QoS works (2/4)"
-               [[ $(dlogutil -d DLOG_QOS_TEST1 | wc -l) -le 180 ]] && ok || fail
+               [[ $(dlogutil -d DLOG_QOS_TEST1 | grep -v blocked | wc -l) -le 180 ]] && ok || fail
                kill $LOGGER > /dev/null
                sleep 1
                if [ $type == "logger" ]; then
@@ -807,9 +815,9 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
                dlogsend -b main -t DLOG_QOS_TEST3 -c 270 -d 1 -f 18 "Some log spam"
                wait $DLOGSEND_PID
                LOG_DETAILS="testing if QoS works (3/4)"
-               [[ $(dlogutil -d DLOG_QOS_TEST2 DLOG_QOS_TEST3 | wc -l) -le 180 ]] && ok || fail
+               [[ $(dlogutil -d DLOG_QOS_TEST2 DLOG_QOS_TEST3 | grep -v blocked | wc -l) -le 180 ]] && ok || fail
                LOG_DETAILS="testing if QoS works (4/4)"
-               [[ $(dlogutil -d DLOG_QOS_TEST2 | wc -l) -gt 24 ]] && ok || fail
+               [[ $(dlogutil -d DLOG_QOS_TEST2 | grep -v blocked | wc -l) -gt 24 ]] && ok || fail
 
                DLOG_CONFIG_PATH=$PREQOS_CONFIG_PATH
                kill $LOGGER > /dev/null
Domain: System / System Framework;