Re: /var/log/messages: backlog limit exceeded

On Wed, 2005-06-15 at 13:10 -0600, Denise Garrett wrote: I think the answer to this problem is to make the auditable processes _wait_ until they can get a slot in the backlog, whenever that's possible. Obviously, some callers of audit_log_start() cannot sleep, but most of the high-bandwidth callers can... Assuming this approach is satisfactory we may want to look for more callers which can be converted to audit_log_start_wait(), and perhaps give a few more slots to the atomic callers, so there's always space for them. --- linux-2.6.9/kernel/auditsc.c.orig 2005-06-20 00:21:52.000000000 +0100 +++ linux-2.6.9/kernel/auditsc.c 2005-06-20 01:14:05.000000000 +0100 @@ -728,7 +734,7 @@ static void audit_log_exit(struct audit_ struct audit_watch_info *winfo; struct hlist_node *pos; - ab = audit_log_start(context, AUDIT_SYSCALL); + ab = audit_log_start_wait(context, AUDIT_SYSCALL); if (!ab) return; /* audit_panic has been called */ audit_log_format(ab, "arch=%x syscall=%d", @@ -759,7 +765,7 @@ static void audit_log_exit(struct audit_ audit_log_end(ab); for (aux = context->aux; aux; aux = aux->next) { - ab = audit_log_start(context, aux->type); + ab = audit_log_start_wait(context, aux->type); if (!ab) continue; /* audit_panic has been called */ @@ -801,7 +807,7 @@ static void audit_log_exit(struct audit_ MAJOR(axi->dev), MINOR(axi->dev), MAJOR(axi->rdev), MINOR(axi->rdev)); hlist_for_each_entry(winfo, pos, &axi->watches, node) { - sub_ab = audit_log_start(context, AUDIT_FS_WATCH); + sub_ab = audit_log_start_wait(context, AUDIT_FS_WATCH); if (!sub_ab) return; /* audit_panic has been called */ audit_log_format(sub_ab, "watch_inode=%lu", axi->ino); @@ -819,14 +825,14 @@ static void audit_log_exit(struct audit_ } if (context->pwd && context->pwdmnt) { - ab = audit_log_start(context, AUDIT_CWD); + ab = audit_log_start_wait(context, 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_wait(context, AUDIT_PATH); if (!ab) continue; /* audit_panic has been called */ --- linux-2.6.9/kernel/audit.c.orig 2005-06-20 00:21:52.000000000 +0100 +++ linux-2.6.9/kernel/audit.c 2005-06-20 01:14:41.000000000 +0100 @@ -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, and watch insertions never happen @@ -280,6 +281,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); @@ -694,7 +696,8 @@ static inline void audit_get_stamp(struc * 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 type, int wait) { struct audit_buffer *ab = NULL; struct timespec t; @@ -703,8 +706,24 @@ struct audit_buffer *audit_log_start(str if (!audit_initialized) return NULL; - if (audit_backlog_limit + while (audit_backlog_limit && skb_queue_len(&audit_skb_queue) > audit_backlog_limit) { + if (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 > " @@ -715,7 +734,7 @@ struct audit_buffer *audit_log_start(str return NULL; } - ab = audit_buffer_alloc(ctx, GFP_ATOMIC, type); + ab = audit_buffer_alloc(ctx, wait?GFP_KERNEL:GFP_ATOMIC, type); if (!ab) { audit_log_lost("out of memory in audit_log_start"); return NULL; @@ -728,6 +747,16 @@ struct audit_buffer *audit_log_start(str return ab; } +struct audit_buffer *audit_log_start(struct audit_context *ctx, int type) +{ + return __audit_log_start(ctx, type, 0); +} + +struct audit_buffer *audit_log_start_wait(struct audit_context *ctx, int type) +{ + return __audit_log_start(ctx, type, 1); +} + /** * audit_expand - expand skb in the audit buffer * @ab: audit_buffer --- linux-2.6.9/include/linux/audit.h.orig 2005-06-20 01:15:24.000000000 +0100 +++ linux-2.6.9/include/linux/audit.h 2005-06-20 01:15:45.000000000 +0100 @@ -337,6 +337,7 @@ extern void audit_log(struct audit_ __attribute__((format(printf,3,4))); extern struct audit_buffer *audit_log_start(struct audit_context *ctx,int type); +extern struct audit_buffer *audit_log_start_wait(struct audit_context *ctx,int type); extern void audit_log_format(struct audit_buffer *ab, const char *fmt, ...) __attribute__((format(printf,2,3))); -- dwmw2