Merge branch 'acl-log' into unstable

src/acl.c

@@ -49,6 +49,8 @@ list *UsersToLoad;  /* This is a list of users found in the configuration file
                        array of SDS pointers: the first is the user name,
                        all the remaining pointers are ACL rules in the same
                        format as ACLSetUser(). */
+list *ACLLog;       /* Our security log, the user is able to inspect that
+                       using the ACL LOG command .*/
 
 struct ACLCategoryItem {
     const char *name;
@@ -93,6 +95,7 @@ struct ACLUserFlag {
 void ACLResetSubcommandsForCommand(user *u, unsigned long id);
 void ACLResetSubcommands(user *u);
 void ACLAddAllowedSubcommand(user *u, unsigned long id, const char *sub);
+void ACLFreeLogEntry(void *le);
 
 /* The length of the string representation of a hashed password. */
 #define HASH_PASSWORD_LEN SHA256_BLOCK_SIZE*2
@@ -920,6 +923,7 @@ void ACLInitDefaultUser(void) {
 void ACLInit(void) {
     Users = raxNew();
     UsersToLoad = listCreate();
+    ACLLog = listCreate();
     ACLInitDefaultUser();
 }
 
@@ -978,6 +982,7 @@ int ACLAuthenticateUser(client *c, robj *username, robj *password) {
         moduleNotifyUserChanged(c);
         return C_OK;
     } else {
+        addACLLogEntry(c,ACL_DENIED_AUTH,0,username->ptr);
         return C_ERR;
     }
 }
@@ -1034,7 +1039,7 @@ user *ACLGetUserByName(const char *name, size_t namelen) {
  * command cannot be executed because the user is not allowed to run such
  * command, the second if the command is denied because the user is trying
  * to access keys that are not among the specified patterns. */
-int ACLCheckCommandPerm(client *c) {
+int ACLCheckCommandPerm(client *c, int *keyidxptr) {
     user *u = c->user;
     uint64_t id = c->cmd->id;
 
@@ -1094,6 +1099,7 @@ int ACLCheckCommandPerm(client *c) {
                 }
             }
             if (!match) {
+                if (keyidxptr) *keyidxptr = keyidx[j];
                 getKeysFreeResult(keyidx);
                 return ACL_DENIED_KEY;
             }
@@ -1454,6 +1460,131 @@ void ACLLoadUsersAtStartup(void) {
     }
 }
 
+/* =============================================================================
+ * ACL log
+ * ==========================================================================*/
+
+#define ACL_LOG_CTX_TOPLEVEL 0
+#define ACL_LOG_CTX_LUA 1
+#define ACL_LOG_CTX_MULTI 2
+#define ACL_LOG_GROUPING_MAX_TIME_DELTA 60000
+
+/* This structure defines an entry inside the ACL log. */
+typedef struct ACLLogEntry {
+    uint64_t count;     /* Number of times this happened recently. */
+    int reason;         /* Reason for denying the command. ACL_DENIED_*. */
+    int context;        /* Toplevel, Lua or MULTI/EXEC? ACL_LOG_CTX_*. */
+    sds object;         /* The key name or command name. */
+    sds username;       /* User the client is authenticated with. */
+    mstime_t ctime;     /* Milliseconds time of last update to this entry. */
+    sds cinfo;          /* Client info (last client if updated). */
+} ACLLogEntry;
+
+/* This function will check if ACL entries 'a' and 'b' are similar enough
+ * that we should actually update the existing entry in our ACL log instead
+ * of creating a new one. */
+int ACLLogMatchEntry(ACLLogEntry *a, ACLLogEntry *b) {
+    if (a->reason != b->reason) return 0;
+    if (a->context != b->context) return 0;
+    mstime_t delta = a->ctime - b->ctime;
+    if (delta < 0) delta = -delta;
+    if (delta > ACL_LOG_GROUPING_MAX_TIME_DELTA) return 0;
+    if (sdscmp(a->object,b->object) != 0) return 0;
+    if (sdscmp(a->username,b->username) != 0) return 0;
+    return 1;
+}
+
+/* Release an ACL log entry. */
+void ACLFreeLogEntry(void *leptr) {
+    ACLLogEntry *le = leptr;
+    sdsfree(le->object);
+    sdsfree(le->username);
+    sdsfree(le->cinfo);
+    zfree(le);
+}
+
+/* Adds a new entry in the ACL log, making sure to delete the old entry
+ * if we reach the maximum length allowed for the log. This function attempts
+ * to find similar entries in the current log in order to bump the counter of
+ * the log entry instead of creating many entries for very similar ACL
+ * rules issues.
+ *
+ * The keypos argument is only used when the reason is ACL_DENIED_KEY, since
+ * it allows the function to log the key name that caused the problem.
+ * Similarly the username is only passed when we failed to authenticate the
+ * user with AUTH or HELLO, for the ACL_DENIED_AUTH reason. Otherwise
+ * it will just be NULL.
+ */
+void addACLLogEntry(client *c, int reason, int keypos, sds username) {
+    /* Create a new entry. */
+    struct ACLLogEntry *le = zmalloc(sizeof(*le));
+    le->count = 1;
+    le->reason = reason;
+    le->username = sdsdup(reason == ACL_DENIED_AUTH ? username : c->user->name);
+    le->ctime = mstime();
+
+    switch(reason) {
+    case ACL_DENIED_CMD: le->object = sdsnew(c->cmd->name); break;
+    case ACL_DENIED_KEY: le->object = sdsnew(c->argv[keypos]->ptr); break;
+    case ACL_DENIED_AUTH: le->object = sdsnew(c->argv[0]->ptr); break;
+    default: le->object = sdsempty();
+    }
+
+    client *realclient = c;
+    if (realclient->flags & CLIENT_LUA) realclient = server.lua_caller;
+
+    le->cinfo = catClientInfoString(sdsempty(),realclient);
+    if (c->flags & CLIENT_MULTI) {
+        le->context = ACL_LOG_CTX_MULTI;
+    } else if (c->flags & CLIENT_LUA) {
+        le->context = ACL_LOG_CTX_LUA;
+    } else {
+        le->context = ACL_LOG_CTX_TOPLEVEL;
+    }
+
+    /* Try to match this entry with past ones, to see if we can just
+     * update an existing entry instead of creating a new one. */
+    long toscan = 10; /* Do a limited work trying to find duplicated. */
+    listIter li;
+    listNode *ln;
+    listRewind(ACLLog,&li);
+    ACLLogEntry *match = NULL;
+    while (toscan-- && (ln = listNext(&li)) != NULL) {
+        ACLLogEntry *current = listNodeValue(ln);
+        if (ACLLogMatchEntry(current,le)) {
+            match = current;
+            listDelNode(ACLLog,ln);
+            listAddNodeHead(ACLLog,current);
+            break;
+        }
+    }
+
+    /* If there is a match update the entry, otherwise add it as a
+     * new one. */
+    if (match) {
+        /* We update a few fields of the existing entry and bump the
+         * counter of events for this entry. */
+        sdsfree(match->cinfo);
+        match->cinfo = le->cinfo;
+        match->ctime = le->ctime;
+        match->count++;
+
+        /* Release the old entry. */
+        le->cinfo = NULL;
+        ACLFreeLogEntry(le);
+    } else {
+        /* Add it to our list of entires. We'll have to trim the list
+         * to its maximum size. */
+        listAddNodeHead(ACLLog, le);
+        while(listLength(ACLLog) > server.acllog_max_len) {
+            listNode *ln = listLast(ACLLog);
+            ACLLogEntry *le = listNodeValue(ln);
+            ACLFreeLogEntry(le);
+            listDelNode(ACLLog,ln);
+        }
+    }
+}
+
 /* =============================================================================
  * ACL related commands
  * ==========================================================================*/
@@ -1469,6 +1600,7 @@ void ACLLoadUsersAtStartup(void) {
  * ACL GETUSER <username>
  * ACL GENPASS
  * ACL WHOAMI
+ * ACL LOG [<count> | RESET]
  */
 void aclCommand(client *c) {
     char *sub = c->argv[1]->ptr;
@@ -1655,6 +1787,71 @@ void aclCommand(client *c) {
         char pass[32]; /* 128 bits of actual pseudo random data. */
         getRandomHexChars(pass,sizeof(pass));
         addReplyBulkCBuffer(c,pass,sizeof(pass));
+    } else if (!strcasecmp(sub,"log") && (c->argc == 2 || c->argc ==3)) {
+        long count = 10; /* Number of entries to emit by default. */
+
+        /* Parse the only argument that LOG may have: it could be either
+         * the number of entires the user wants to display, or alternatively
+         * the "RESET" command in order to flush the old entires. */
+        if (c->argc == 3) {
+            if (!strcasecmp(c->argv[2]->ptr,"reset")) {
+                listSetFreeMethod(ACLLog,ACLFreeLogEntry);
+                listEmpty(ACLLog);
+                listSetFreeMethod(ACLLog,NULL);
+                addReply(c,shared.ok);
+                return;
+            } else if (getLongFromObjectOrReply(c,c->argv[2],&count,NULL)
+                       != C_OK)
+            {
+                return;
+            }
+            if (count < 0) count = 0;
+        }
+
+        /* Fix the count according to the number of entries we got. */
+        if ((size_t)count > listLength(ACLLog))
+            count = listLength(ACLLog);
+
+        addReplyArrayLen(c,count);
+        listIter li;
+        listNode *ln;
+        listRewind(ACLLog,&li);
+        mstime_t now = mstime();
+        while (count-- && (ln = listNext(&li)) != NULL) {
+            ACLLogEntry *le = listNodeValue(ln);
+            addReplyMapLen(c,7);
+            addReplyBulkCString(c,"count");
+            addReplyLongLong(c,le->count);
+
+            addReplyBulkCString(c,"reason");
+            char *reasonstr;
+            switch(le->reason) {
+            case ACL_DENIED_CMD: reasonstr="command"; break;
+            case ACL_DENIED_KEY: reasonstr="key"; break;
+            case ACL_DENIED_AUTH: reasonstr="auth"; break;
+            }
+            addReplyBulkCString(c,reasonstr);
+
+            addReplyBulkCString(c,"context");
+            char *ctxstr;
+            switch(le->context) {
+            case ACL_LOG_CTX_TOPLEVEL: ctxstr="toplevel"; break;
+            case ACL_LOG_CTX_MULTI: ctxstr="multi"; break;
+            case ACL_LOG_CTX_LUA: ctxstr="lua"; break;
+            default: ctxstr="unknown";
+            }
+            addReplyBulkCString(c,ctxstr);
+
+            addReplyBulkCString(c,"object");
+            addReplyBulkCBuffer(c,le->object,sdslen(le->object));
+            addReplyBulkCString(c,"username");
+            addReplyBulkCBuffer(c,le->username,sdslen(le->username));
+            addReplyBulkCString(c,"age-seconds");
+            double age = (double)(now - le->ctime)/1000;
+            addReplyDouble(c,age);
+            addReplyBulkCString(c,"client-info");
+            addReplyBulkCBuffer(c,le->cinfo,sdslen(le->cinfo));
+        }
     } else if (!strcasecmp(sub,"help")) {
         const char *help[] = {
 "LOAD                              -- Reload users from the ACL file.",
@@ -1667,6 +1864,7 @@ void aclCommand(client *c) {
 "CAT <category>                    -- List commands inside category.",
 "GENPASS                           -- Generate a secure user password.",
 "WHOAMI                            -- Return the current connection username.",
+"LOG [<count> | RESET]             -- Show the ACL log entries.",
 NULL
         };
         addReplyHelp(c,help);

src/config.c

@@ -2233,6 +2233,7 @@ standardConfig configs[] = {
     /* Unsigned Long configs */
     createULongConfig("active-defrag-max-scan-fields", NULL, MODIFIABLE_CONFIG, 1, LONG_MAX, server.active_defrag_max_scan_fields, 1000, INTEGER_CONFIG, NULL, NULL), /* Default: keys with more than 1000 fields will be processed separately */
     createULongConfig("slowlog-max-len", NULL, MODIFIABLE_CONFIG, 0, LONG_MAX, server.slowlog_max_len, 128, INTEGER_CONFIG, NULL, NULL),
+    createULongConfig("acllog-max-len", NULL, MODIFIABLE_CONFIG, 0, LONG_MAX, server.acllog_max_len, 128, INTEGER_CONFIG, NULL, NULL),
 
     /* Long Long configs */
     createLongLongConfig("lua-time-limit", NULL, MODIFIABLE_CONFIG, 0, LONG_MAX, server.lua_time_limit, 5000, INTEGER_CONFIG, NULL, NULL),/* milliseconds */

src/multi.c

@@ -177,8 +177,10 @@ void execCommand(client *c) {
             must_propagate = 1;
         }
 
-        int acl_retval = ACLCheckCommandPerm(c);
+        int acl_keypos;
+        int acl_retval = ACLCheckCommandPerm(c,&acl_keypos);
         if (acl_retval != ACL_OK) {
+            addACLLogEntry(c,acl_retval,acl_keypos,NULL);
             addReplyErrorFormat(c,
                 "-NOPERM ACLs rules changed between the moment the "
                 "transaction was accumulated and the EXEC call. "

src/scripting.c

@@ -606,8 +606,10 @@ int luaRedisGenericCommand(lua_State *lua, int raise_error) {
     }
 
     /* Check the ACLs. */
-    int acl_retval = ACLCheckCommandPerm(c);
+    int acl_keypos;
+    int acl_retval = ACLCheckCommandPerm(c,&acl_keypos);
     if (acl_retval != ACL_OK) {
+        addACLLogEntry(c,acl_retval,acl_keypos,NULL);
         if (acl_retval == ACL_DENIED_CMD)
             luaPushError(lua, "The user executing the script can't run this "
                               "command or subcommand");

src/server.c

@@ -3377,8 +3377,10 @@ int processCommand(client *c) {
 
     /* Check if the user can run this command according to the current
      * ACLs. */
-    int acl_retval = ACLCheckCommandPerm(c);
+    int acl_keypos;
+    int acl_retval = ACLCheckCommandPerm(c,&acl_keypos);
     if (acl_retval != ACL_OK) {
+        addACLLogEntry(c,acl_retval,acl_keypos,NULL);
         flagTransaction(c);
         if (acl_retval == ACL_DENIED_CMD)
             addReplyErrorFormat(c,

src/server.h

@@ -1385,6 +1385,7 @@ struct redisServer {
     dict *latency_events;
     /* ACLs */
     char *acl_filename;     /* ACL Users file. NULL if not configured. */
+    unsigned long acllog_max_len; /* Maximum length of the ACL LOG list. */
     /* Assert & bug reporting */
     const char *assert_failed;
     const char *assert_file;
@@ -1820,11 +1821,12 @@ void ACLInit(void);
 #define ACL_OK 0
 #define ACL_DENIED_CMD 1
 #define ACL_DENIED_KEY 2
+#define ACL_DENIED_AUTH 3 /* Only used for ACL LOG entries. */
 int ACLCheckUserCredentials(robj *username, robj *password);
 int ACLAuthenticateUser(client *c, robj *username, robj *password);
 unsigned long ACLGetCommandID(const char *cmdname);
 user *ACLGetUserByName(const char *name, size_t namelen);
-int ACLCheckCommandPerm(client *c);
+int ACLCheckCommandPerm(client *c, int *keyidxptr);
 int ACLSetUser(user *u, const char *op, ssize_t oplen);
 sds ACLDefaultUserFirstPassword(void);
 uint64_t ACLGetCommandCategoryFlagByName(const char *name);
@@ -1836,6 +1838,7 @@ void ACLLoadUsersAtStartup(void);
 void addReplyCommandCategories(client *c, struct redisCommand *cmd);
 user *ACLCreateUnlinkedUser();
 void ACLFreeUserAndKillClients(user *u);
+void addACLLogEntry(client *c, int reason, int keypos, sds username);
 
 /* Sorted sets data type */
 

tests/unit/acl.tcl

@@ -141,4 +141,111 @@ start_server {tags {"acl"}} {
         r ACL setuser newuser -debug
         # The test framework will detect a leak if any.
     }
+
+    test {ACL LOG shows failed command executions at toplevel} {
+        r ACL LOG RESET
+        r ACL setuser antirez >foo on +set ~object:1234
+        r ACL setuser antirez +eval +multi +exec
+        r AUTH antirez foo
+        catch {r GET foo}
+        r AUTH default ""
+        set entry [lindex [r ACL LOG] 0]
+        assert {[dict get $entry username] eq {antirez}}
+        assert {[dict get $entry context] eq {toplevel}}
+        assert {[dict get $entry reason] eq {command}}
+        assert {[dict get $entry object] eq {get}}
+    }
+
+    test {ACL LOG is able to test similar events} {
+        r AUTH antirez foo
+        catch {r GET foo}
+        catch {r GET foo}
+        catch {r GET foo}
+        r AUTH default ""
+        set entry [lindex [r ACL LOG] 0]
+        assert {[dict get $entry count] == 4}
+    }
+
+    test {ACL LOG is able to log keys access violations and key name} {
+        r AUTH antirez foo
+        catch {r SET somekeynotallowed 1234}
+        r AUTH default ""
+        set entry [lindex [r ACL LOG] 0]
+        assert {[dict get $entry reason] eq {key}}
+        assert {[dict get $entry object] eq {somekeynotallowed}}
+    }
+
+    test {ACL LOG RESET is able to flush the entries in the log} {
+        r ACL LOG RESET
+        assert {[llength [r ACL LOG]] == 0}
+    }
+
+    test {ACL LOG can distinguish the transaction context (1)} {
+        r AUTH antirez foo
+        r MULTI
+        catch {r INCR foo}
+        catch {r EXEC}
+        r AUTH default ""
+        set entry [lindex [r ACL LOG] 0]
+        assert {[dict get $entry context] eq {multi}}
+        assert {[dict get $entry object] eq {incr}}
+    }
+
+    test {ACL LOG can distinguish the transaction context (2)} {
+        set rd1 [redis_deferring_client]
+        r ACL SETUSER antirez +incr
+
+        r AUTH antirez foo
+        r MULTI
+        r INCR object:1234
+        $rd1 ACL SETUSER antirez -incr
+        $rd1 read
+        catch {r EXEC}
+        $rd1 close
+        r AUTH default ""
+        set entry [lindex [r ACL LOG] 0]
+        assert {[dict get $entry context] eq {multi}}
+        assert {[dict get $entry object] eq {incr}}
+        r ACL SETUSER antirez -incr
+    }
+
+    test {ACL can log errors in the context of Lua scripting} {
+        r AUTH antirez foo
+        catch {r EVAL {redis.call('incr','foo')} 0}
+        r AUTH default ""
+        set entry [lindex [r ACL LOG] 0]
+        assert {[dict get $entry context] eq {lua}}
+        assert {[dict get $entry object] eq {incr}}
+    }
+
+    test {ACL LOG can accept a numerical argument to show less entries} {
+        r AUTH antirez foo
+        catch {r INCR foo}
+        catch {r INCR foo}
+        catch {r INCR foo}
+        catch {r INCR foo}
+        r AUTH default ""
+        assert {[llength [r ACL LOG]] > 1}
+        assert {[llength [r ACL LOG 2]] == 2}
+    }
+
+    test {ACL LOG can log failed auth attempts} {
+        catch {r AUTH antirez wrong-password}
+        set entry [lindex [r ACL LOG] 0]
+        assert {[dict get $entry context] eq {toplevel}}
+        assert {[dict get $entry reason] eq {auth}}
+        assert {[dict get $entry object] eq {AUTH}}
+        assert {[dict get $entry username] eq {antirez}}
+    }
+
+    test {ACL LOG entries are limited to a maximum amount} {
+        r ACL LOG RESET
+        r CONFIG SET acllog-max-len 5
+        r AUTH antirez foo
+        for {set j 0} {$j < 10} {incr j} {
+            catch {r SET obj:$j 123}
+        }
+        r AUTH default ""
+        assert {[llength [r ACL LOG]] == 5}
+    }
 }