Re: [PATCH v2] audit: report audit wait metric in audit status reply

On Wed, Jul 1, 2020 at 5:32 PM Max Englander <max.englander(a)gmail.com&gt; wrote: > > In environments where the preservation of audit events and predictable > usage of system memory are prioritized, admins may use a combination of > --backlog_wait_time and -b options at the risk of degraded performance > resulting from backlog waiting. In some cases, this risk may be > preferred to lost events or unbounded memory usage. Ideally, this risk > can be mitigated by making adjustments when backlog waiting is detected. > > However, detection can be diffult using the currently available metrics. > For example, an admin attempting to debug degraded performance may > falsely believe a full backlog indicates backlog waiting. It may turn > out the backlog frequently fills up but drains quickly. > > To make it easier to reliably track degraded performance to backlog > waiting, this patch makes the following changes: > > Add a new field backlog_wait_sum to the audit status reply. Initialize > this field to zero. Add to this field the total time spent by the > current task on scheduled timeouts while the backlog limit is exceeded. > > Tested on Ubuntu 18.04 using complementary changes to the audit > userspace: https://github.com/linux-audit/audit-userspace/pull/134. > > Signed-off-by: Max Englander <max.englander(a)gmail.com&gt; > --- > Patch changelogs between v1 and v2: > - Instead of printing a warning when backlog waiting occurs, add > duration of backlog waiting to cumulative sum, and report this > sum in audit status reply. > > include/uapi/linux/audit.h | 7 ++++++- > kernel/audit.c | 9 +++++++++ > 2 files changed, 15 insertions(+), 1 deletion(-) Hi Max, In general this looks better than the previous approach, but I do have a few specific comments (inline). It also important that in addition to the requisite userspace patch, we also need a test added to the audit-testsuite project so we can verify this functionality in the future. * https://github.com/linux-audit/audit-testsuite > diff --git a/include/uapi/linux/audit.h b/include/uapi/linux/audit.h > index a534d71e689a..ea0cc364beca 100644 > --- a/include/uapi/linux/audit.h > +++ b/include/uapi/linux/audit.h > @@ -340,6 +340,7 @@ enum { > #define AUDIT_STATUS_BACKLOG_LIMIT 0x0010 > #define AUDIT_STATUS_BACKLOG_WAIT_TIME 0x0020 > #define AUDIT_STATUS_LOST 0x0040 > +#define AUDIT_STATUS_BACKLOG_WAIT_SUM 0x0080 Sooo ... you've defined this, but I don't see any of the corresponding AUDIT_SET code that I would expect, was that an oversight? If not, it is something we should support in the kernel as I'm sure admins will want to reset this value at some point.

> #define AUDIT_FEATURE_BITMAP_BACKLOG_LIMIT 0x00000001 > #define AUDIT_FEATURE_BITMAP_BACKLOG_WAIT_TIME 0x00000002 > @@ -348,6 +349,7 @@ enum { > #define AUDIT_FEATURE_BITMAP_SESSIONID_FILTER 0x00000010 > #define AUDIT_FEATURE_BITMAP_LOST_RESET 0x00000020 > #define AUDIT_FEATURE_BITMAP_FILTER_FS 0x00000040 > +#define AUDIT_FEATURE_BITMAP_BACKLOG_WAIT_SUM 0x00000080 In an effort not to exhaust the feature bitmap too quickly, I've been restricting it to only those features that would cause breakage with userspace. I haven't looked closely at Steve's userspace in quite a while, but I'm guessing it can key off the structure size and doesn't need this entry in the bitmap, right? Let me rephrase, if userspace needs to key off anything, it *should* key off the structure size and not a new flag in the bitmask ;)

Also, I'm assuming that older userspace doesn't blow-up if it sees the larger structure size? That's even more important.

> #define AUDIT_FEATURE_BITMAP_ALL (AUDIT_FEATURE_BITMAP_BACKLOG_LIMIT | \ > AUDIT_FEATURE_BITMAP_BACKLOG_WAIT_TIME | \ > @@ -355,12 +357,14 @@ enum { > AUDIT_FEATURE_BITMAP_EXCLUDE_EXTEND | \ > AUDIT_FEATURE_BITMAP_SESSIONID_FILTER | \ > AUDIT_FEATURE_BITMAP_LOST_RESET | \ > - AUDIT_FEATURE_BITMAP_FILTER_FS) > + AUDIT_FEATURE_BITMAP_FILTER_FS | \ > + AUDIT_FEATURE_BITMAP_BACKLOG_WAIT_SUM) > > /* deprecated: AUDIT_VERSION_* */ > #define AUDIT_VERSION_LATEST AUDIT_FEATURE_BITMAP_ALL > #define AUDIT_VERSION_BACKLOG_LIMIT AUDIT_FEATURE_BITMAP_BACKLOG_LIMIT > #define AUDIT_VERSION_BACKLOG_WAIT_TIME AUDIT_FEATURE_BITMAP_BACKLOG_WAIT_TIME > +#define AUDIT_VERSION_BACKLOG_WAIT_SUM AUDIT_FEATURE_BITMAP_BACKLOG_WAIT_SUM > > /* Failure-to-log actions */ > #define AUDIT_FAIL_SILENT 0 > @@ -466,6 +470,7 @@ struct audit_status { > __u32 feature_bitmap; /* bitmap of kernel audit features */ > }; > __u32 backlog_wait_time;/* message queue wait timeout */ > + __u32 backlog_wait_sum;/* time spent waiting while message limit exceeded */ This is very nitpicky, but how about a rename to 'backlog_wait_time_actual'?

> diff --git a/kernel/audit.c b/kernel/audit.c > index 87f31bf1f0a0..301ea4f3d750 100644 > --- a/kernel/audit.c > +++ b/kernel/audit.c > @@ -136,6 +136,11 @@ u32 audit_sig_sid = 0; > */ > static atomic_t audit_lost = ATOMIC_INIT(0); > > +/* Monotonically increasing sum of time the kernel has spent > + * waiting while the backlog limit is exceeded. > + */ > +static atomic_t audit_backlog_wait_sum = ATOMIC_INIT(0); Needless to say, this should be renamed too so we don't go crazy. > /* Hash for inode-based rules */ > struct list_head audit_inode_hash[AUDIT_INODE_BUCKETS]; > > @@ -1204,6 +1209,7 @@ static int audit_receive_msg(struct sk_buff *skb, struct nlmsghdr *nlh) > s.backlog = skb_queue_len(&audit_queue); > s.feature_bitmap = AUDIT_FEATURE_BITMAP_ALL; > s.backlog_wait_time = audit_backlog_wait_time; > + s.backlog_wait_sum = atomic_read(&audit_backlog_wait_sum); > audit_send_reply(skb, seq, AUDIT_GET, 0, 0, &s, sizeof(s)); > break; > } > @@ -1794,6 +1800,9 @@ struct audit_buffer *audit_log_start(struct audit_context *ctx, gfp_t gfp_mask, > return NULL; > } > } > + > + if (stime != audit_backlog_wait_time) > + atomic_add(audit_backlog_wait_time - stime, &audit_backlog_wait_sum); Since stime can only be different in one place in the code above (after the schedule_timeout() call), why not move the atomic_add() up there and drop the "if"? Yes there is the potential of calling atomic_add() multiple times in this case, but the thread is waiting anyway and this way we don't impact other code paths. > } > > ab = audit_buffer_alloc(ctx, gfp_mask, type); paul moore