diff mbox series

[RESEND,2/2] selinux: provide matching audit timestamp in the AVC trace event

Message ID 20221219180024.1659268-3-omosnace@redhat.com (mailing list archive)
State Handled Elsewhere
Headers show
Series Provide matching audit timestamp in the SELinux AVC trace event | expand

Commit Message

Ondrej Mosnacek Dec. 19, 2022, 6 p.m. UTC 
In order to make it possible for the users and tooling to associate an
SELinux AVC trace event with the corresponding audit event, make it
include the audit timestamp (including the "serial number") of the
event.

First make audit_log_start() include the timestamp in the audit_buffer
struct and add a public helper to retrieve it from an audit_buffer
instance. Then retrieve it in SELinux's avc_audit_post_callback() and
include it in the "avc:selinux_audited" trace event.

After this patch the even includes the numeric fields that make up the
timestamp and the text representation includes the timestamp in the same
format as used in the audit log - e.g. "audit_ts=1671454430.092:1671".

Signed-off-by: Ondrej Mosnacek <omosnace@redhat.com>
---
 include/linux/audit.h      |  8 ++++++++
 include/trace/events/avc.h | 25 +++++++++++++++++--------
 kernel/audit.c             | 15 +++++++++++----
 security/selinux/avc.c     |  4 +++-
 4 files changed, 39 insertions(+), 13 deletions(-)

Comments

Paul Moore Dec. 19, 2022, 10:20 p.m. UTC | #1 
On Mon, Dec 19, 2022 at 1:00 PM Ondrej Mosnacek <omosnace@redhat.com> wrote:
>
> In order to make it possible for the users and tooling to associate an
> SELinux AVC trace event with the corresponding audit event, make it
> include the audit timestamp (including the "serial number") of the
> event.
>
> First make audit_log_start() include the timestamp in the audit_buffer
> struct and add a public helper to retrieve it from an audit_buffer
> instance. Then retrieve it in SELinux's avc_audit_post_callback() and
> include it in the "avc:selinux_audited" trace event.
>
> After this patch the even includes the numeric fields that make up the
> timestamp and the text representation includes the timestamp in the same
> format as used in the audit log - e.g. "audit_ts=1671454430.092:1671".
>
> Signed-off-by: Ondrej Mosnacek <omosnace@redhat.com>
> ---
>  include/linux/audit.h      |  8 ++++++++
>  include/trace/events/avc.h | 25 +++++++++++++++++--------
>  kernel/audit.c             | 15 +++++++++++----
>  security/selinux/avc.c     |  4 +++-
>  4 files changed, 39 insertions(+), 13 deletions(-)

I'm not really liking the idea of exposing the audit timestamp for use
in other subsystems, even if it is just for use in a trace event.  I
generally take the approach that audit's charter is to capture and log
security relevant events to userspace where admins and security
officers can use the events to help meet their security goals.  While
audit may have some value to developers as a debugging tool, that is
not its primary purpose, and at this point in time I'm not supportive
of adding additional burdens to the audit subsystem to support a
debugging use case (I view exporting and maintaining a proper
timestamp value/struct an additional requirement on the audit
subsystem).
diff mbox series

Patch

diff --git a/include/linux/audit.h b/include/linux/audit.h
index 788ab93c3be4..d6d7acc1b623 100644
--- a/include/linux/audit.h
+++ b/include/linux/audit.h
@@ -162,6 +162,9 @@  extern __printf(4, 5)
 void audit_log(struct audit_context *ctx, gfp_t gfp_mask, int type,
 	       const char *fmt, ...);
 
+extern void audit_buffer_get_timestamp(struct audit_buffer *ab,
+				       struct audit_timestamp *ts);
+
 extern struct audit_buffer *audit_log_start(struct audit_context *ctx, gfp_t gfp_mask, int type);
 extern __printf(2, 3)
 void audit_log_format(struct audit_buffer *ab, const char *fmt, ...);
@@ -218,6 +221,11 @@  static inline __printf(4, 5)
 void audit_log(struct audit_context *ctx, gfp_t gfp_mask, int type,
 	       const char *fmt, ...)
 { }
+static inline void audit_buffer_get_timestamp(struct audit_buffer *ab,
+					      struct audit_timestamp *ts)
+{
+	*ts = (struct audit_timestamp){};
+}
 static inline struct audit_buffer *audit_log_start(struct audit_context *ctx,
 						   gfp_t gfp_mask, int type)
 {
diff --git a/include/trace/events/avc.h b/include/trace/events/avc.h
index b55fda2e0773..8cac14ae22ae 100644
--- a/include/trace/events/avc.h
+++ b/include/trace/events/avc.h
@@ -16,34 +16,43 @@  TRACE_EVENT(selinux_audited,
 	TP_PROTO(struct selinux_audit_data *sad,
 		char *scontext,
 		char *tcontext,
-		const char *tclass
+		const char *tclass,
+		const struct audit_timestamp *ts
 	),
 
-	TP_ARGS(sad, scontext, tcontext, tclass),
+	TP_ARGS(sad, scontext, tcontext, tclass, ts),
 
 	TP_STRUCT__entry(
 		__field(u32, requested)
 		__field(u32, denied)
 		__field(u32, audited)
 		__field(int, result)
+		__field(u64, audit_stamp_sec)
+		__field(u32, audit_stamp_msec)
+		__field(u32, audit_stamp_serial)
 		__string(scontext, scontext)
 		__string(tcontext, tcontext)
 		__string(tclass, tclass)
 	),
 
 	TP_fast_assign(
-		__entry->requested	= sad->requested;
-		__entry->denied		= sad->denied;
-		__entry->audited	= sad->audited;
-		__entry->result		= sad->result;
+		__entry->requested		= sad->requested;
+		__entry->denied			= sad->denied;
+		__entry->audited		= sad->audited;
+		__entry->result			= sad->result;
+		__entry->audit_stamp_sec	= ts->t.tv_sec;
+		__entry->audit_stamp_msec	= ts->t.tv_nsec / 1000000;
+		__entry->audit_stamp_serial	= ts->serial;
 		__assign_str(tcontext, tcontext);
 		__assign_str(scontext, scontext);
 		__assign_str(tclass, tclass);
 	),
 
-	TP_printk("requested=0x%x denied=0x%x audited=0x%x result=%d scontext=%s tcontext=%s tclass=%s",
+	TP_printk("requested=0x%x denied=0x%x audited=0x%x result=%d scontext=%s tcontext=%s tclass=%s audit_ts=%llu.%03u:%u",
 		__entry->requested, __entry->denied, __entry->audited, __entry->result,
-		__get_str(scontext), __get_str(tcontext), __get_str(tclass)
+		__get_str(scontext), __get_str(tcontext), __get_str(tclass),
+		__entry->audit_stamp_sec, __entry->audit_stamp_msec,
+		__entry->audit_stamp_serial
 	)
 );
 
diff --git a/kernel/audit.c b/kernel/audit.c
index aded2d69ea69..ad21d148704a 100644
--- a/kernel/audit.c
+++ b/kernel/audit.c
@@ -199,6 +199,7 @@  static struct audit_ctl_mutex {
 struct audit_buffer {
 	struct sk_buff       *skb;	/* formatted skb ready to send */
 	struct audit_context *ctx;	/* NULL or associated context */
+	struct audit_timestamp ts;	/* the timestamp of this record */
 	gfp_t		     gfp_mask;
 };
 
@@ -1826,6 +1827,12 @@  static inline void audit_get_stamp(struct audit_context *ctx,
 	}
 }
 
+void audit_buffer_get_timestamp(struct audit_buffer *ab,
+				struct audit_timestamp *ts)
+{
+	*ts = ab->ts;
+}
+
 /**
  * audit_log_start - obtain an audit buffer
  * @ctx: audit_context (may be NULL)
@@ -1845,7 +1852,6 @@  struct audit_buffer *audit_log_start(struct audit_context *ctx, gfp_t gfp_mask,
 				     int type)
 {
 	struct audit_buffer *ab;
-	struct audit_timestamp ts;
 
 	if (audit_initialized != AUDIT_INITIALIZED)
 		return NULL;
@@ -1900,13 +1906,14 @@  struct audit_buffer *audit_log_start(struct audit_context *ctx, gfp_t gfp_mask,
 		return NULL;
 	}
 
-	audit_get_stamp(ab->ctx, &ts);
+	audit_get_stamp(ab->ctx, &ab->ts);
 	/* cancel dummy context to enable supporting records */
 	if (ctx)
 		ctx->dummy = 0;
 	audit_log_format(ab, "audit(%llu.%03lu:%u): ",
-			 (unsigned long long)ts.t.tv_sec, ts.t.tv_nsec/1000000,
-			 ts.serial);
+			 (unsigned long long)ab->ts.t.tv_sec,
+			 ab->ts.t.tv_nsec/1000000,
+			 ab->ts.serial);
 
 	return ab;
 }
diff --git a/security/selinux/avc.c b/security/selinux/avc.c
index 9a43af0ebd7d..e59c91eb3228 100644
--- a/security/selinux/avc.c
+++ b/security/selinux/avc.c
@@ -708,6 +708,7 @@  static void avc_audit_post_callback(struct audit_buffer *ab, void *a)
 {
 	struct common_audit_data *ad = a;
 	struct selinux_audit_data *sad = ad->selinux_audit_data;
+	struct audit_timestamp ts;
 	char *scontext = NULL;
 	char *tcontext = NULL;
 	const char *tclass = NULL;
@@ -735,7 +736,8 @@  static void avc_audit_post_callback(struct audit_buffer *ab, void *a)
 	if (sad->denied)
 		audit_log_format(ab, " permissive=%u", sad->result ? 0 : 1);
 
-	trace_selinux_audited(sad, scontext, tcontext, tclass);
+	audit_buffer_get_timestamp(ab, &ts);
+	trace_selinux_audited(sad, scontext, tcontext, tclass, &ts);
 	kfree(tcontext);
 	kfree(scontext);