liblog: add IF_ALOG_RATELIMIT

IF_ALOG_RATELIMIT()
    ALOGE("Only one message globally using IF_ALOG_RATELIMIT()"
          " in the process may appear ever ten seconds,"
          " (%s)", strerror(errno));

static time_t last; /* initial state zero */
IF_ALOG_RATELIMIT_LOCAL(60, &last)
    ALOGE("Only one message locally may appear every minute,"
          " (%s)", strerror(errno));

These new calls are guaranteed not to affect the value of a
non-zero errno to simplify logging of errors.  However, the
ALOGE calls in the above examples may update the errno value
upon their return.

Test: gTest liblog-unit-tests --gtest_filter=liblog.__android_log_ratelimit
Bug: 33535908
Change-Id: Id8cc192fc7d14504ffd418933cf88ae945c089f2

3 files changed, 119 insertions, 0 deletions

diff --git a/liblog/Android.bp b/liblog/Android.bp
index 2424dba75..be47fc333 100644
--- a/liblog/Android.bp
+++ b/liblog/Android.bp
@@ -21,6 +21,7 @@ liblog_sources = [
     "config_write.c",
     "logger_name.c",
     "logger_lock.c",
+    "log_ratelimit.cpp",
 ]
 liblog_host_sources = [
     "fake_log_device.c",
diff --git a/liblog/log_ratelimit.cpp b/liblog/log_ratelimit.cpp
new file mode 100644
index 000000000..dfd4b8fcc
--- /dev/null
+++ b/liblog/log_ratelimit.cpp
@@ -0,0 +1,86 @@
+/*
+** Copyright 2016, The Android Open Source Project
+**
+** Licensed under the Apache License, Version 2.0 (the "License");
+** you may not use this file except in compliance with the License.
+** You may obtain a copy of the License at
+**
+**     http://www.apache.org/licenses/LICENSE-2.0
+**
+** Unless required by applicable law or agreed to in writing, software
+** distributed under the License is distributed on an "AS IS" BASIS,
+** WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+** See the License for the specific language governing permissions and
+** limitations under the License.
+*/
+
+#include <errno.h>
+#include <pthread.h>
+#include <time.h>
+
+#include <log/log.h>
+
+#include "log_portability.h"
+
+// Global default if 'last' argument in __android_log_ratelimit is NULL
+static time_t g_last_clock;
+// Global above can not deal well with callers playing games with the
+// seconds argument, so we will also hold on to the maximum value
+// ever provided and use that to gain consistency.  If the caller
+// provides their own 'last' argument, then they can play such games
+// of varying the 'seconds' argument to their pleasure.
+static time_t g_last_seconds;
+static const time_t last_seconds_default = 10;
+static const time_t last_seconds_max = 24 * 60 * 60; // maximum of a day
+static const time_t last_seconds_min = 2; // granularity
+// Lock to protect last_clock and last_seconds, but also 'last'
+// argument (not NULL) as supplied to __android_log_ratelimit.
+static pthread_mutex_t lock_ratelimit = PTHREAD_MUTEX_INITIALIZER;
+
+// if last is NULL, caller _must_ provide a consistent value for
+// seconds, otherwise we will take the maximum ever issued and hold
+// on to that.  Preserves value of non-zero errno.  Return -1 if we
+// can not acquire a lock, 0 if we are not to log a message, and 1
+// if we are ok to log a message.  Caller should check > 0 for true.
+LIBLOG_ABI_PUBLIC int __android_log_ratelimit(time_t seconds, time_t* last) {
+    int save_errno = errno;
+
+    // Two reasons for trylock failure:
+    //   1. In a signal handler. Must prevent deadlock
+    //   2. Too many threads calling __android_log_ratelimit.
+    //      Bonus to not print if they race here because that
+    //      dovetails the goal of ratelimiting. One may print
+    //      and the others will wait their turn ...
+    if (pthread_mutex_trylock(&lock_ratelimit)) {
+        if (save_errno) errno = save_errno;
+        return -1;
+    }
+
+    if (seconds == 0) {
+        seconds = last_seconds_default;
+    } else if (seconds < last_seconds_min) {
+        seconds = last_seconds_min;
+    } else if (seconds > last_seconds_max) {
+        seconds = last_seconds_max;
+    }
+
+    if (!last) {
+        if (g_last_seconds > seconds) {
+            seconds = g_last_seconds;
+        } else if (g_last_seconds < seconds) {
+            g_last_seconds = seconds;
+        }
+        last = &g_last_clock;
+    }
+
+    time_t now = time(NULL);
+    if ((now == (time_t)-1) || ((*last + seconds) > now)) {
+        pthread_mutex_unlock(&lock_ratelimit);
+        if (save_errno) errno = save_errno;
+        return 0;
+    }
+    *last = now;
+    pthread_mutex_unlock(&lock_ratelimit);
+    if (save_errno) errno = save_errno;
+    return 1;
+}
diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp
index d07d77430..01a562c9f 100644
--- a/liblog/tests/liblog_test.cpp
+++ b/liblog/tests/liblog_test.cpp
@@ -2870,3 +2870,35 @@ TEST(liblog, event_log_tags) {
     GTEST_LOG_(INFO) << "This test does nothing.\n";
 #endif
 }
+
+TEST(liblog, __android_log_ratelimit) {
+    time_t state = 0;
+
+    errno = 42;
+    // Prime
+    __android_log_ratelimit(3, &state);
+    EXPECT_EQ(errno, 42);
+    // Check
+    EXPECT_FALSE(__android_log_ratelimit(3, &state));
+    sleep(1);
+    EXPECT_FALSE(__android_log_ratelimit(3, &state));
+    sleep(4);
+    EXPECT_TRUE(__android_log_ratelimit(3, &state));
+    sleep(5);
+    EXPECT_TRUE(__android_log_ratelimit(3, &state));
+
+    // API checks
+    IF_ALOG_RATELIMIT_LOCAL(3, &state) {
+        EXPECT_FALSE(0 != "IF_ALOG_RATELIMIT_LOCAL(3, &state)");
+    }
+
+    IF_ALOG_RATELIMIT() {
+        ;
+    } else {
+        EXPECT_TRUE(0 == "IF_ALOG_RATELIMIT()");
+    }
+    IF_ALOG_RATELIMIT() {
+        EXPECT_FALSE(0 != "IF_ALOG_RATELIMIT()");
+    }
+    // Do not test default seconds, to allow liblog to tune freely
+}