logd: sepolicy dynamic rate limiting

Processing overhead for selinux violation messages is costly. We want
to deal with bursts of violations, but we have no intent of allowing
that sustained burst to go unabated as there is a cost of processing
and battery usage.

Tunables in libaudit.h are:

AUDIT_RATE_LIMIT_DEFAULT 20        /* acceptable burst rate      */
AUDIT_RATE_LIMIT_BURST_DURATION 10 /* number of seconds of burst */
AUDIT_RATE_LIMIT_MAX     5         /* acceptable sustained rate  */

Since we can only asymptotically handle DEFAULT rate, we set an upper
threshold of half way between the MAX and DEFAULT rate.

Default kernel audit subsystem message rate is set to 20 a second.
If sepolicy exceeds 125 violation messages over up to ten seconds
(>=~12/s), tell kernel audit subsystem to drop the rate to 5 messages
a second.  If rate drops below 50 messages over the past ten seconds
(<5/s), tell kernel it is ok to increase the burst rate back to 20
messages a second.

Test: gTest logd-unit-tests --gtest_filter=logd.sepolicy_rate_limiter_*
Bug: 27878170
Change-Id: I843f8dcfbb3ecfbbe94a4865ea332c858e3be7f2

1 files changed, 47 insertions, 4 deletions

diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp
index 11ffcb785..92d957fb1 100644
--- a/logd/LogAudit.cpp
+++ b/logd/LogAudit.cpp
@@ -43,7 +43,7 @@
     '>'
 
 LogAudit::LogAudit(LogBuffer *buf, LogReader *reader, int fdDmesg) :
-        SocketListener(getLogSocket(), false),
+        SocketListener(mSock = getLogSocket(), false),
         logbuf(buf),
         reader(reader),
         fdDmesg(fdDmesg),
@@ -51,19 +51,62 @@ LogAudit::LogAudit(LogBuffer *buf, LogReader *reader, int fdDmesg) :
                                                 BOOL_DEFAULT_TRUE)),
         events(__android_logger_property_get_bool("ro.logd.auditd.events",
                                                   BOOL_DEFAULT_TRUE)),
-        initialized(false) {
+        initialized(false),
+        tooFast(false) {
     static const char auditd_message[] = { KMSG_PRIORITY(LOG_INFO),
         'l', 'o', 'g', 'd', '.', 'a', 'u', 'd', 'i', 't', 'd', ':',
         ' ', 's', 't', 'a', 'r', 't', '\n' };
     write(fdDmesg, auditd_message, sizeof(auditd_message));
 }
 
+void LogAudit::checkRateLimit() {
+
+    // trim list for AUDIT_RATE_LIMIT_BURST_DURATION of history
+    log_time oldest(AUDIT_RATE_LIMIT_BURST_DURATION, 0);
+    bucket.emplace(android_log_clockid());
+    oldest = bucket.back() - oldest;
+    while (bucket.front() < oldest) bucket.pop();
+
+    static const size_t upperThreshold =
+        ((AUDIT_RATE_LIMIT_BURST_DURATION *
+          (AUDIT_RATE_LIMIT_DEFAULT + AUDIT_RATE_LIMIT_MAX)) + 1) /
+                              2;
+    if (bucket.size() >= upperThreshold) {
+        // Hit peak, slow down source
+        if (!tooFast) {
+            tooFast = true;
+            audit_rate_limit(mSock, AUDIT_RATE_LIMIT_MAX);
+        }
+
+        // We do not need to hold on to the full set of timing data history,
+        // let's ensure it does not grow without bounds.  This also ensures
+        // that std::dequeue underneath behaves almost like a ring buffer.
+        do {
+            bucket.pop();
+        } while (bucket.size() >= upperThreshold);
+        return;
+    }
+
+    if (!tooFast) return;
+
+    static const size_t lowerThreshold = AUDIT_RATE_LIMIT_BURST_DURATION *
+                                         AUDIT_RATE_LIMIT_MAX;
+
+    if (bucket.size() >= lowerThreshold) return;
+
+    tooFast = false;
+    // Went below max sustained rate, allow source to speed up
+    audit_rate_limit(mSock, AUDIT_RATE_LIMIT_DEFAULT);
+}
+
 bool LogAudit::onDataAvailable(SocketClient *cli) {
     if (!initialized) {
         prctl(PR_SET_NAME, "logd.auditd");
         initialized = true;
     }
 
+    checkRateLimit();
+
     struct audit_message rep;
 
     rep.nlh.nlmsg_type = 0;
@@ -75,8 +118,7 @@ bool LogAudit::onDataAvailable(SocketClient *cli) {
         return false;
     }
 
-    logPrint("type=%d %.*s",
-        rep.nlh.nlmsg_type, rep.nlh.nlmsg_len, rep.data);
+    logPrint("type=%d %.*s", rep.nlh.nlmsg_type, rep.nlh.nlmsg_len, rep.data);
 
     return true;
 }
@@ -351,5 +393,6 @@ int LogAudit::getLogSocket() {
         audit_close(fd);
         fd = -1;
     }
+    (void)audit_rate_limit(fd, AUDIT_RATE_LIMIT_DEFAULT);
     return fd;
 }