AUDIT: Wait for backlog to clear when generating messages.

Add a gfp_mask to audit_log_start() and audit_log(), to reduce the
amount of GFP_ATOMIC allocation -- most of it doesn't need to be 
GFP_ATOMIC. Also if the mask includes __GFP_WAIT, then wait up to
60 seconds for the auditd backlog to clear instead of immediately 
abandoning the message. 

The timeout should probably be made configurable, but for now it'll 
suffice that it only happens if auditd is actually running.

Signed-off-by: David Woodhouse <dwmw2@infradead.org>

include/linux/audit.h

@@ -259,11 +259,11 @@ extern int audit_filter_user(int pid, int type);
 #ifdef CONFIG_AUDIT
 /* These are defined in audit.c */
 				/* Public API */
-extern void		    audit_log(struct audit_context *ctx, int type,
-				      const char *fmt, ...)
-			    __attribute__((format(printf,3,4)));
+extern void		    audit_log(struct audit_context *ctx, int gfp_mask,
+				      int type, const char *fmt, ...)
+				      __attribute__((format(printf,4,5)));
 
-extern struct audit_buffer *audit_log_start(struct audit_context *ctx,int type);
+extern struct audit_buffer *audit_log_start(struct audit_context *ctx, int gfp_mask, int type);
 extern void		    audit_log_format(struct audit_buffer *ab,
 					     const char *fmt, ...)
 			    __attribute__((format(printf,2,3)));

kernel/audit.c

@@ -106,6 +106,7 @@ static LIST_HEAD(audit_freelist);
 static struct sk_buff_head audit_skb_queue;
 static struct task_struct *kauditd_task;
 static DECLARE_WAIT_QUEUE_HEAD(kauditd_wait);
+static DECLARE_WAIT_QUEUE_HEAD(audit_backlog_wait);
 
 /* The netlink socket is only to be read by 1 CPU, which lets us assume
  * that list additions and deletions never happen simultaneously in
@@ -130,6 +131,7 @@ struct audit_buffer {
 	struct list_head     list;
 	struct sk_buff       *skb;	/* formatted skb ready to send */
 	struct audit_context *ctx;	/* NULL or associated context */
+	int		     gfp_mask;
 };
 
 static void audit_set_pid(struct audit_buffer *ab, pid_t pid)
@@ -226,7 +228,7 @@ static int audit_set_rate_limit(int limit, uid_t loginuid)
 {
 	int old		 = audit_rate_limit;
 	audit_rate_limit = limit;
-	audit_log(NULL, AUDIT_CONFIG_CHANGE, 
+	audit_log(NULL, GFP_KERNEL, AUDIT_CONFIG_CHANGE, 
 			"audit_rate_limit=%d old=%d by auid=%u",
 			audit_rate_limit, old, loginuid);
 	return old;
@@ -236,7 +238,7 @@ static int audit_set_backlog_limit(int limit, uid_t loginuid)
 {
 	int old		 = audit_backlog_limit;
 	audit_backlog_limit = limit;
-	audit_log(NULL, AUDIT_CONFIG_CHANGE,
+	audit_log(NULL, GFP_KERNEL, AUDIT_CONFIG_CHANGE,
 			"audit_backlog_limit=%d old=%d by auid=%u",
 			audit_backlog_limit, old, loginuid);
 	return old;
@@ -248,7 +250,7 @@ static int audit_set_enabled(int state, uid_t loginuid)
 	if (state != 0 && state != 1)
 		return -EINVAL;
 	audit_enabled = state;
-	audit_log(NULL, AUDIT_CONFIG_CHANGE,
+	audit_log(NULL, GFP_KERNEL, AUDIT_CONFIG_CHANGE,
 			"audit_enabled=%d old=%d by auid=%u",
 			audit_enabled, old, loginuid);
 	return old;
@@ -262,7 +264,7 @@ static int audit_set_failure(int state, uid_t loginuid)
 	    && state != AUDIT_FAIL_PANIC)
 		return -EINVAL;
 	audit_failure = state;
-	audit_log(NULL, AUDIT_CONFIG_CHANGE,
+	audit_log(NULL, GFP_KERNEL, AUDIT_CONFIG_CHANGE,
 			"audit_failure=%d old=%d by auid=%u",
 			audit_failure, old, loginuid);
 	return old;
@@ -274,6 +276,7 @@ int kauditd_thread(void *dummy)
 
 	while (1) {
 		skb = skb_dequeue(&audit_skb_queue);
+		wake_up(&audit_backlog_wait);
 		if (skb) {
 			if (audit_pid) {
 				int err = netlink_unicast(audit_sock, skb, audit_pid, 0);
@@ -417,7 +420,7 @@ static int audit_receive_msg(struct sk_buff *skb, struct nlmsghdr *nlh)
 		if (status_get->mask & AUDIT_STATUS_PID) {
 			int old   = audit_pid;
 			audit_pid = status_get->pid;
-			audit_log(NULL, AUDIT_CONFIG_CHANGE,
+			audit_log(NULL, GFP_KERNEL, AUDIT_CONFIG_CHANGE,
 				"audit_pid=%d old=%d by auid=%u",
 				  audit_pid, old, loginuid);
 		}
@@ -435,7 +438,7 @@ static int audit_receive_msg(struct sk_buff *skb, struct nlmsghdr *nlh)
 		err = audit_filter_user(pid, msg_type);
 		if (err == 1) {
 			err = 0;
-			ab = audit_log_start(NULL, msg_type);
+			ab = audit_log_start(NULL, GFP_KERNEL, msg_type);
 			if (ab) {
 				audit_log_format(ab,
 						 "user pid=%d uid=%u auid=%u msg='%.1024s'",
@@ -522,7 +525,7 @@ static int __init audit_init(void)
 	skb_queue_head_init(&audit_skb_queue);
 	audit_initialized = 1;
 	audit_enabled = audit_default;
-	audit_log(NULL, AUDIT_KERNEL, "initialized");
+	audit_log(NULL, GFP_KERNEL, AUDIT_KERNEL, "initialized");
 	return 0;
 }
 __initcall(audit_init);
@@ -586,6 +589,7 @@ static struct audit_buffer * audit_buffer_alloc(struct audit_context *ctx,
 		goto err;
 
 	ab->ctx = ctx;
+	ab->gfp_mask = gfp_mask;
 	nlh = (struct nlmsghdr *)skb_put(ab->skb, NLMSG_SPACE(0));
 	nlh->nlmsg_type = type;
 	nlh->nlmsg_flags = 0;
@@ -644,17 +648,42 @@ static inline void audit_get_stamp(struct audit_context *ctx,
  * syscall, then the syscall is marked as auditable and an audit record
  * will be written at syscall exit.  If there is no associated task, tsk
  * should be NULL. */
-struct audit_buffer *audit_log_start(struct audit_context *ctx, int type)
+
+struct audit_buffer *audit_log_start(struct audit_context *ctx, int gfp_mask,
+				     int type)
 {
 	struct audit_buffer	*ab	= NULL;
 	struct timespec		t;
 	unsigned int		serial;
+	int reserve;
 
 	if (!audit_initialized)
 		return NULL;
 
-	if (audit_backlog_limit
-	    && skb_queue_len(&audit_skb_queue) > audit_backlog_limit) {
+	if (gfp_mask & __GFP_WAIT)
+		reserve = 0;
+	else
+		reserve = 5; /* Allow atomic callers to go up to five 
+				entries over the normal backlog limit */
+
+	while (audit_backlog_limit
+	       && skb_queue_len(&audit_skb_queue) > audit_backlog_limit + reserve) {
+		if (gfp_mask & __GFP_WAIT) {
+			int ret = 1;
+			/* Wait for auditd to drain the queue a little */
+			DECLARE_WAITQUEUE(wait, current);
+			set_current_state(TASK_INTERRUPTIBLE);
+			add_wait_queue(&audit_backlog_wait, &wait);
+
+			if (audit_backlog_limit &&
+			    skb_queue_len(&audit_skb_queue) > audit_backlog_limit)
+				ret = schedule_timeout(HZ * 60);
+
+			__set_current_state(TASK_RUNNING);
+			remove_wait_queue(&audit_backlog_wait, &wait);
+			if (ret)
+				continue;
+		}
 		if (audit_rate_check())
 			printk(KERN_WARNING
 			       "audit: audit_backlog=%d > "
@@ -665,7 +694,7 @@ struct audit_buffer *audit_log_start(struct audit_context *ctx, int type)
 		return NULL;
 	}
 
-	ab = audit_buffer_alloc(ctx, GFP_ATOMIC, type);
+	ab = audit_buffer_alloc(ctx, gfp_mask, type);
 	if (!ab) {
 		audit_log_lost("out of memory in audit_log_start");
 		return NULL;
@@ -689,7 +718,7 @@ static inline int audit_expand(struct audit_buffer *ab, int extra)
 {
 	struct sk_buff *skb = ab->skb;
 	int ret = pskb_expand_head(skb, skb_headroom(skb), extra,
-				   GFP_ATOMIC);
+				   ab->gfp_mask);
 	if (ret < 0) {
 		audit_log_lost("out of memory in audit_expand");
 		return 0;
@@ -808,7 +837,7 @@ void audit_log_d_path(struct audit_buffer *ab, const char *prefix,
 		audit_log_format(ab, " %s", prefix);
 
 	/* We will allow 11 spaces for ' (deleted)' to be appended */
-	path = kmalloc(PATH_MAX+11, GFP_KERNEL);
+	path = kmalloc(PATH_MAX+11, ab->gfp_mask);
 	if (!path) {
 		audit_log_format(ab, "<no memory>");
 		return;
@@ -849,12 +878,13 @@ void audit_log_end(struct audit_buffer *ab)
 /* Log an audit record.  This is a convenience function that calls
  * audit_log_start, audit_log_vformat, and audit_log_end.  It may be
  * called in any context. */
-void audit_log(struct audit_context *ctx, int type, const char *fmt, ...)
+void audit_log(struct audit_context *ctx, int gfp_mask, int type, 
+	       const char *fmt, ...)
 {
 	struct audit_buffer *ab;
 	va_list args;
 
-	ab = audit_log_start(ctx, type);
+	ab = audit_log_start(ctx, gfp_mask, type);
 	if (ab) {
 		va_start(args, fmt);
 		audit_log_vformat(ab, fmt, args);

kernel/auditsc.c

@@ -346,7 +346,7 @@ int audit_receive_filter(int type, int pid, int uid, int seq, void *data,
 		}
 		listnr = entry->rule.flags & ~AUDIT_FILTER_PREPEND;
 		audit_add_rule(entry, &audit_filter_list[listnr]);
-		audit_log(NULL, AUDIT_CONFIG_CHANGE, 
+		audit_log(NULL, GFP_KERNEL, AUDIT_CONFIG_CHANGE, 
 				"auid=%u added an audit rule\n", loginuid);
 		break;
 	case AUDIT_DEL:
@@ -356,7 +356,7 @@ int audit_receive_filter(int type, int pid, int uid, int seq, void *data,
 
 		err = audit_del_rule(data, &audit_filter_list[listnr]);
 		if (!err)
-			audit_log(NULL, AUDIT_CONFIG_CHANGE,
+			audit_log(NULL, GFP_KERNEL, AUDIT_CONFIG_CHANGE,
 				  "auid=%u removed an audit rule\n", loginuid);
 		break;
 	default:
@@ -756,7 +756,7 @@ static void audit_log_exit(struct audit_context *context)
 	struct audit_buffer *ab;
 	struct audit_aux_data *aux;
 
-	ab = audit_log_start(context, AUDIT_SYSCALL);
+	ab = audit_log_start(context, GFP_KERNEL, AUDIT_SYSCALL);
 	if (!ab)
 		return;		/* audit_panic has been called */
 	audit_log_format(ab, "arch=%x syscall=%d",
@@ -788,7 +788,7 @@ static void audit_log_exit(struct audit_context *context)
 
 	for (aux = context->aux; aux; aux = aux->next) {
 
-		ab = audit_log_start(context, aux->type);
+		ab = audit_log_start(context, GFP_KERNEL, aux->type);
 		if (!ab)
 			continue; /* audit_panic has been called */
 
@@ -825,14 +825,14 @@ static void audit_log_exit(struct audit_context *context)
 	}
 
 	if (context->pwd && context->pwdmnt) {
-		ab = audit_log_start(context, AUDIT_CWD);
+		ab = audit_log_start(context, GFP_KERNEL, AUDIT_CWD);
 		if (ab) {
 			audit_log_d_path(ab, "cwd=", context->pwd, context->pwdmnt);
 			audit_log_end(ab);
 		}
 	}
 	for (i = 0; i < context->name_count; i++) {
-		ab = audit_log_start(context, AUDIT_PATH);
+		ab = audit_log_start(context, GFP_KERNEL, AUDIT_PATH);
 		if (!ab)
 			continue; /* audit_panic has been called */
 
@@ -1118,7 +1118,7 @@ int audit_set_loginuid(struct task_struct *task, uid_t loginuid)
 	if (task->audit_context) {
 		struct audit_buffer *ab;
 
-		ab = audit_log_start(NULL, AUDIT_LOGIN);
+		ab = audit_log_start(NULL, GFP_KERNEL, AUDIT_LOGIN);
 		if (ab) {
 			audit_log_format(ab, "login pid=%d uid=%u "
 				"old auid=%u new auid=%u",

security/selinux/avc.c

@@ -242,7 +242,7 @@ void __init avc_init(void)
 	avc_node_cachep = kmem_cache_create("avc_node", sizeof(struct avc_node),
 					     0, SLAB_PANIC, NULL, NULL);
 
-	audit_log(current->audit_context, AUDIT_KERNEL, "AVC INITIALIZED\n");
+	audit_log(current->audit_context, GFP_KERNEL, AUDIT_KERNEL, "AVC INITIALIZED\n");
 }
 
 int avc_get_hash_stats(char *page)
@@ -550,7 +550,7 @@ void avc_audit(u32 ssid, u32 tsid,
 			return;
 	}
 
-	ab = audit_log_start(current->audit_context, AUDIT_AVC);
+	ab = audit_log_start(current->audit_context, GFP_ATOMIC, AUDIT_AVC);
 	if (!ab)
 		return;		/* audit_panic has been called */
 	audit_log_format(ab, "avc:  %s ", denied ? "denied" : "granted");

security/selinux/hooks.c

@@ -3419,7 +3419,7 @@ static int selinux_nlmsg_perm(struct sock *sk, struct sk_buff *skb)
 	err = selinux_nlmsg_lookup(isec->sclass, nlh->nlmsg_type, &perm);
 	if (err) {
 		if (err == -EINVAL) {
-			audit_log(current->audit_context, AUDIT_SELINUX_ERR,
+			audit_log(current->audit_context, GFP_KERNEL, AUDIT_SELINUX_ERR,
 				  "SELinux:  unrecognized netlink message"
 				  " type=%hu for sclass=%hu\n",
 				  nlh->nlmsg_type, isec->sclass);

security/selinux/ss/services.c

@@ -365,7 +365,7 @@ static int security_validtrans_handle_fail(struct context *ocontext,
 		goto out;
 	if (context_struct_to_string(tcontext, &t, &tlen) < 0)
 		goto out;
-	audit_log(current->audit_context, AUDIT_SELINUX_ERR,
+	audit_log(current->audit_context, GFP_ATOMIC, AUDIT_SELINUX_ERR,
 	          "security_validate_transition:  denied for"
 	          " oldcontext=%s newcontext=%s taskcontext=%s tclass=%s",
 	          o, n, t, policydb.p_class_val_to_name[tclass-1]);
@@ -742,7 +742,7 @@ static int compute_sid_handle_invalid_context(
 		goto out;
 	if (context_struct_to_string(newcontext, &n, &nlen) < 0)
 		goto out;
-	audit_log(current->audit_context, AUDIT_SELINUX_ERR,
+	audit_log(current->audit_context, GFP_ATOMIC, AUDIT_SELINUX_ERR,
 		  "security_compute_sid:  invalid context %s"
 		  " for scontext=%s"
 		  " tcontext=%s"