[PATCH v4 0/2] selinux: add detailed tracepoint on audited events

[PATCH v4 0/2] selinux: add detailed tracepoint on audited events

[Thiébaud Weksteen]

The audit data currently captures which process and which target
is responsible for a denial. There is no data on where exactly in the
process that call occurred. Debugging can be made easier by adding a
trace point when an event is audited.

This series of patch defines this new trace point and extra attributes
to easily match the tracepoint event with the audit event. It is also
possible to filter the events based on these attributes.

Changes since v3
================
- Remove patch to include decoded permissions.
- Remove extra braces in patch 2.

Changes since v2
================
- Add patch to include decoded permissions.
- Remove ssid and tsid from attributes list.
- Update commit log with more context.

Peter Enderborg (1):
  selinux: add basic filtering for audit trace events

Thiébaud Weksteen (1):
  selinux: add tracepoint on audited events

 MAINTAINERS                |  1 +
 include/trace/events/avc.h | 53 ++++++++++++++++++++++++++++++++++++++
 security/selinux/avc.c     | 29 +++++++++++++--------
 3 files changed, 72 insertions(+), 11 deletions(-)
 create mode 100644 include/trace/events/avc.h

-- 
2.28.0.297.g1956fa8f8d-goog

[PATCH v4 1/2] selinux: add tracepoint on audited events

[Thiébaud Weksteen]

The audit data currently captures which process and which target
is responsible for a denial. There is no data on where exactly in the
process that call occurred. Debugging can be made easier by being able to
reconstruct the unified kernel and userland stack traces [1]. Add a
tracepoint on the SELinux denials which can then be used by userland
(i.e. perf).

Although this patch could manually be added by each OS developer to
trouble shoot a denial, adding it to the kernel streamlines the
developers workflow.

It is possible to use perf for monitoring the event:
  # perf record -e avc:selinux_audited -g -a
  ^C
  # perf report -g
  [...]
      6.40%     6.40%  audited=800000 tclass=4
               |
                  __libc_start_main
                  |
                  |--4.60%--__GI___ioctl
                  |          entry_SYSCALL_64
                  |          do_syscall_64
                  |          __x64_sys_ioctl
                  |          ksys_ioctl
                  |          binder_ioctl
                  |          binder_set_nice
                  |          can_nice
                  |          capable
                  |          security_capable
                  |          cred_has_capability.isra.0
                  |          slow_avc_audit
                  |          common_lsm_audit
                  |          avc_audit_post_callback
                  |          avc_audit_post_callback
                  |

It is also possible to use the ftrace interface:
  # echo 1 > /sys/kernel/debug/tracing/events/avc/selinux_audited/enable
  # cat /sys/kernel/debug/tracing/trace
  tracer: nop
  entries-in-buffer/entries-written: 1/1   #P:8
  [...]
  dmesg-3624  [001] 13072.325358: selinux_denied: audited=800000 tclass=4

The tclass value can be mapped to a class by searching
security/selinux/flask.h. The audited value is a bit field of the
permissions described in security/selinux/av_permissions.h for the
corresponding class.

[1] https://source.android.com/devices/tech/debug/native_stack_dump

Signed-off-by: Thiébaud Weksteen <tweek@google.com>
Suggested-by: Joel Fernandes <joelaf@google.com>
Reviewed-by: Peter Enderborg <peter.enderborg@sony.com>
---
 MAINTAINERS                |  1 +
 include/trace/events/avc.h | 37 +++++++++++++++++++++++++++++++++++++
 security/selinux/avc.c     |  5 +++++
 3 files changed, 43 insertions(+)
 create mode 100644 include/trace/events/avc.h

diff --git a/MAINTAINERS b/MAINTAINERS
index c8e8232c65da..0efaea0e144c 100644
--- a/MAINTAINERS
+++ b/MAINTAINERS
@@ -15426,6 +15426,7 @@ T:	git git://git.kernel.org/pub/scm/linux/kernel/git/pcmoore/selinux.git
 F:	Documentation/ABI/obsolete/sysfs-selinux-checkreqprot
 F:	Documentation/ABI/obsolete/sysfs-selinux-disable
 F:	Documentation/admin-guide/LSM/SELinux.rst
+F:	include/trace/events/avc.h
 F:	include/uapi/linux/selinux_netlink.h
 F:	scripts/selinux/
 F:	security/selinux/
diff --git a/include/trace/events/avc.h b/include/trace/events/avc.h
new file mode 100644
index 000000000000..07c058a9bbcd
--- /dev/null
+++ b/include/trace/events/avc.h
@@ -0,0 +1,37 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+/*
+ * Author: Thiébaud Weksteen <tweek@google.com>
+ */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM avc
+
+#if !defined(_TRACE_SELINUX_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_SELINUX_H
+
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(selinux_audited,
+
+	TP_PROTO(struct selinux_audit_data *sad),
+
+	TP_ARGS(sad),
+
+	TP_STRUCT__entry(
+		__field(unsigned int, tclass)
+		__field(unsigned int, audited)
+	),
+
+	TP_fast_assign(
+		__entry->tclass = sad->tclass;
+		__entry->audited = sad->audited;
+	),
+
+	TP_printk("tclass=%u audited=%x",
+		__entry->tclass,
+		__entry->audited)
+);
+
+#endif
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/security/selinux/avc.c b/security/selinux/avc.c
index d18cb32a242a..b0a0af778b70 100644
--- a/security/selinux/avc.c
+++ b/security/selinux/avc.c
@@ -31,6 +31,9 @@
 #include "avc_ss.h"
 #include "classmap.h"
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/avc.h>
+
 #define AVC_CACHE_SLOTS			512
 #define AVC_DEF_CACHE_THRESHOLD		512
 #define AVC_CACHE_RECLAIM		16
@@ -706,6 +709,8 @@ static void avc_audit_post_callback(struct audit_buffer *ab, void *a)
 	u32 scontext_len;
 	int rc;
 
+	trace_selinux_audited(sad);
+
 	rc = security_sid_to_context(sad->state, sad->ssid, &scontext,
 				     &scontext_len);
 	if (rc)
-- 
2.28.0.297.g1956fa8f8d-goog

Re: [PATCH v4 1/2] selinux: add tracepoint on audited events

[Stephen Smalley]

On Fri, Aug 21, 2020 at 10:09 AM Thiébaud Weksteen <tweek@google.com> wrote:
>
> The audit data currently captures which process and which target
> is responsible for a denial. There is no data on where exactly in the
> process that call occurred. Debugging can be made easier by being able to
> reconstruct the unified kernel and userland stack traces [1]. Add a
> tracepoint on the SELinux denials which can then be used by userland
> (i.e. perf).
>
> Although this patch could manually be added by each OS developer to
> trouble shoot a denial, adding it to the kernel streamlines the
> developers workflow.
>
> It is possible to use perf for monitoring the event:
>   # perf record -e avc:selinux_audited -g -a
>   ^C
>   # perf report -g
>   [...]
>       6.40%     6.40%  audited=800000 tclass=4
>                |
>                   __libc_start_main
>                   |
>                   |--4.60%--__GI___ioctl
>                   |          entry_SYSCALL_64
>                   |          do_syscall_64
>                   |          __x64_sys_ioctl
>                   |          ksys_ioctl
>                   |          binder_ioctl
>                   |          binder_set_nice
>                   |          can_nice
>                   |          capable
>                   |          security_capable
>                   |          cred_has_capability.isra.0
>                   |          slow_avc_audit
>                   |          common_lsm_audit
>                   |          avc_audit_post_callback
>                   |          avc_audit_post_callback
>                   |
>
> It is also possible to use the ftrace interface:
>   # echo 1 > /sys/kernel/debug/tracing/events/avc/selinux_audited/enable
>   # cat /sys/kernel/debug/tracing/trace
>   tracer: nop
>   entries-in-buffer/entries-written: 1/1   #P:8
>   [...]
>   dmesg-3624  [001] 13072.325358: selinux_denied: audited=800000 tclass=4
>
> The tclass value can be mapped to a class by searching
> security/selinux/flask.h. The audited value is a bit field of the
> permissions described in security/selinux/av_permissions.h for the
> corresponding class.
>
> [1] https://source.android.com/devices/tech/debug/native_stack_dump
>
> Signed-off-by: Thiébaud Weksteen <tweek@google.com>
> Suggested-by: Joel Fernandes <joelaf@google.com>
> Reviewed-by: Peter Enderborg <peter.enderborg@sony.com>

Acked-by: Stephen Smalley <stephen.smalley.work@gmail.com>

Re: [PATCH v4 1/2] selinux: add tracepoint on audited events

[Paul Moore]

On Fri, Aug 21, 2020 at 10:09 AM Thiébaud Weksteen <tweek@google.com> wrote:
>
> The audit data currently captures which process and which target
> is responsible for a denial. There is no data on where exactly in the
> process that call occurred. Debugging can be made easier by being able to
> reconstruct the unified kernel and userland stack traces [1]. Add a
> tracepoint on the SELinux denials which can then be used by userland
> (i.e. perf).
>
> Although this patch could manually be added by each OS developer to
> trouble shoot a denial, adding it to the kernel streamlines the
> developers workflow.
>
> It is possible to use perf for monitoring the event:
>   # perf record -e avc:selinux_audited -g -a
>   ^C
>   # perf report -g
>   [...]
>       6.40%     6.40%  audited=800000 tclass=4
>                |
>                   __libc_start_main
>                   |
>                   |--4.60%--__GI___ioctl
>                   |          entry_SYSCALL_64
>                   |          do_syscall_64
>                   |          __x64_sys_ioctl
>                   |          ksys_ioctl
>                   |          binder_ioctl
>                   |          binder_set_nice
>                   |          can_nice
>                   |          capable
>                   |          security_capable
>                   |          cred_has_capability.isra.0
>                   |          slow_avc_audit
>                   |          common_lsm_audit
>                   |          avc_audit_post_callback
>                   |          avc_audit_post_callback
>                   |
>
> It is also possible to use the ftrace interface:
>   # echo 1 > /sys/kernel/debug/tracing/events/avc/selinux_audited/enable
>   # cat /sys/kernel/debug/tracing/trace
>   tracer: nop
>   entries-in-buffer/entries-written: 1/1   #P:8
>   [...]
>   dmesg-3624  [001] 13072.325358: selinux_denied: audited=800000 tclass=4
>
> The tclass value can be mapped to a class by searching
> security/selinux/flask.h. The audited value is a bit field of the
> permissions described in security/selinux/av_permissions.h for the
> corresponding class.
>
> [1] https://source.android.com/devices/tech/debug/native_stack_dump
>
> Signed-off-by: Thiébaud Weksteen <tweek@google.com>
> Suggested-by: Joel Fernandes <joelaf@google.com>
> Reviewed-by: Peter Enderborg <peter.enderborg@sony.com>
> ---
>  MAINTAINERS                |  1 +
>  include/trace/events/avc.h | 37 +++++++++++++++++++++++++++++++++++++
>  security/selinux/avc.c     |  5 +++++
>  3 files changed, 43 insertions(+)
>  create mode 100644 include/trace/events/avc.h

Merged into selinux/next, thanks!

-- 
paul moore
www.paul-moore.com

Re: [PATCH v4 1/2] selinux: add tracepoint on audited events

[Thiébaud Weksteen]

> Merged into selinux/next, thanks!

Thanks everyone for the reviews and constructive feedback!

[PATCH v4 2/2] selinux: add basic filtering for audit trace events

[Thiébaud Weksteen]

From: Peter Enderborg <peter.enderborg@sony.com>

This patch adds further attributes to the event. These attributes are
helpful to understand the context of the message and can be used
to filter the events.

There are three common items. Source context, target context and tclass.
There are also items from the outcome of operation performed.

An event is similar to:
           <...>-1309  [002] ....  6346.691689: selinux_audited:
       requested=0x4000000 denied=0x4000000 audited=0x4000000
       result=-13
       scontext=system_u:system_r:cupsd_t:s0-s0:c0.c1023
       tcontext=system_u:object_r:bin_t:s0 tclass=file

With systems where many denials are occurring, it is useful to apply a
filter. The filtering is a set of logic that is inserted with
the filter file. Example:
 echo "tclass==\"file\" " > events/avc/selinux_audited/filter

This adds that we only get tclass=file.

The trace can also have extra properties. Adding the user stack
can be done with
   echo 1 > options/userstacktrace

Now the output will be
         runcon-1365  [003] ....  6960.955530: selinux_audited:
     requested=0x4000000 denied=0x4000000 audited=0x4000000
     result=-13
     scontext=system_u:system_r:cupsd_t:s0-s0:c0.c1023
     tcontext=system_u:object_r:bin_t:s0 tclass=file
          runcon-1365  [003] ....  6960.955560: <user stack trace>
 =>  <00007f325b4ce45b>
 =>  <00005607093efa57>

Signed-off-by: Peter Enderborg <peter.enderborg@sony.com>
Reviewed-by: Thiébaud Weksteen <tweek@google.com>
---
 include/trace/events/avc.h | 36 ++++++++++++++++++++++++++----------
 security/selinux/avc.c     | 28 +++++++++++++++-------------
 2 files changed, 41 insertions(+), 23 deletions(-)

diff --git a/include/trace/events/avc.h b/include/trace/events/avc.h
index 07c058a9bbcd..b55fda2e0773 100644
--- a/include/trace/events/avc.h
+++ b/include/trace/events/avc.h
@@ -1,6 +1,7 @@
 /* SPDX-License-Identifier: GPL-2.0 */
 /*
- * Author: Thiébaud Weksteen <tweek@google.com>
+ * Authors:	Thiébaud Weksteen <tweek@google.com>
+ *		Peter Enderborg <Peter.Enderborg@sony.com>
  */
 #undef TRACE_SYSTEM
 #define TRACE_SYSTEM avc
@@ -12,23 +13,38 @@
 
 TRACE_EVENT(selinux_audited,
 
-	TP_PROTO(struct selinux_audit_data *sad),
+	TP_PROTO(struct selinux_audit_data *sad,
+		char *scontext,
+		char *tcontext,
+		const char *tclass
+	),
 
-	TP_ARGS(sad),
+	TP_ARGS(sad, scontext, tcontext, tclass),
 
 	TP_STRUCT__entry(
-		__field(unsigned int, tclass)
-		__field(unsigned int, audited)
+		__field(u32, requested)
+		__field(u32, denied)
+		__field(u32, audited)
+		__field(int, result)
+		__string(scontext, scontext)
+		__string(tcontext, tcontext)
+		__string(tclass, tclass)
 	),
 
 	TP_fast_assign(
-		__entry->tclass = sad->tclass;
-		__entry->audited = sad->audited;
+		__entry->requested	= sad->requested;
+		__entry->denied		= sad->denied;
+		__entry->audited	= sad->audited;
+		__entry->result		= sad->result;
+		__assign_str(tcontext, tcontext);
+		__assign_str(scontext, scontext);
+		__assign_str(tclass, tclass);
 	),
 
-	TP_printk("tclass=%u audited=%x",
-		__entry->tclass,
-		__entry->audited)
+	TP_printk("requested=0x%x denied=0x%x audited=0x%x result=%d scontext=%s tcontext=%s tclass=%s",
+		__entry->requested, __entry->denied, __entry->audited, __entry->result,
+		__get_str(scontext), __get_str(tcontext), __get_str(tclass)
+	)
 );
 
 #endif
diff --git a/security/selinux/avc.c b/security/selinux/avc.c
index b0a0af778b70..3c05827608b6 100644
--- a/security/selinux/avc.c
+++ b/security/selinux/avc.c
@@ -705,35 +705,37 @@ 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;
-	char *scontext;
+	char *scontext = NULL;
+	char *tcontext = NULL;
+	const char *tclass = NULL;
 	u32 scontext_len;
+	u32 tcontext_len;
 	int rc;
 
-	trace_selinux_audited(sad);
-
 	rc = security_sid_to_context(sad->state, sad->ssid, &scontext,
 				     &scontext_len);
 	if (rc)
 		audit_log_format(ab, " ssid=%d", sad->ssid);
-	else {
+	else
 		audit_log_format(ab, " scontext=%s", scontext);
-		kfree(scontext);
-	}
 
-	rc = security_sid_to_context(sad->state, sad->tsid, &scontext,
-				     &scontext_len);
+	rc = security_sid_to_context(sad->state, sad->tsid, &tcontext,
+				     &tcontext_len);
 	if (rc)
 		audit_log_format(ab, " tsid=%d", sad->tsid);
-	else {
-		audit_log_format(ab, " tcontext=%s", scontext);
-		kfree(scontext);
-	}
+	else
+		audit_log_format(ab, " tcontext=%s", tcontext);
 
-	audit_log_format(ab, " tclass=%s", secclass_map[sad->tclass-1].name);
+	tclass = secclass_map[sad->tclass-1].name;
+	audit_log_format(ab, " tclass=%s", tclass);
 
 	if (sad->denied)
 		audit_log_format(ab, " permissive=%u", sad->result ? 0 : 1);
 
+	trace_selinux_audited(sad, scontext, tcontext, tclass);
+	kfree(tcontext);
+	kfree(scontext);
+
 	/* in case of invalid context report also the actual context string */
 	rc = security_sid_to_context_inval(sad->state, sad->ssid, &scontext,
 					   &scontext_len);
-- 
2.28.0.297.g1956fa8f8d-goog

Re: [PATCH v4 2/2] selinux: add basic filtering for audit trace events

[Stephen Smalley]

On Fri, Aug 21, 2020 at 10:09 AM Thiébaud Weksteen <tweek@google.com> wrote:
>
> From: Peter Enderborg <peter.enderborg@sony.com>
>
> This patch adds further attributes to the event. These attributes are
> helpful to understand the context of the message and can be used
> to filter the events.
>
> There are three common items. Source context, target context and tclass.
> There are also items from the outcome of operation performed.
>
> An event is similar to:
>            <...>-1309  [002] ....  6346.691689: selinux_audited:
>        requested=0x4000000 denied=0x4000000 audited=0x4000000
>        result=-13
>        scontext=system_u:system_r:cupsd_t:s0-s0:c0.c1023
>        tcontext=system_u:object_r:bin_t:s0 tclass=file
>
> With systems where many denials are occurring, it is useful to apply a
> filter. The filtering is a set of logic that is inserted with
> the filter file. Example:
>  echo "tclass==\"file\" " > events/avc/selinux_audited/filter
>
> This adds that we only get tclass=file.
>
> The trace can also have extra properties. Adding the user stack
> can be done with
>    echo 1 > options/userstacktrace
>
> Now the output will be
>          runcon-1365  [003] ....  6960.955530: selinux_audited:
>      requested=0x4000000 denied=0x4000000 audited=0x4000000
>      result=-13
>      scontext=system_u:system_r:cupsd_t:s0-s0:c0.c1023
>      tcontext=system_u:object_r:bin_t:s0 tclass=file
>           runcon-1365  [003] ....  6960.955560: <user stack trace>
>  =>  <00007f325b4ce45b>
>  =>  <00005607093efa57>
>
> Signed-off-by: Peter Enderborg <peter.enderborg@sony.com>
> Reviewed-by: Thiébaud Weksteen <tweek@google.com>

Acked-by: Stephen Smalley <stephen.smalley.work@gmail.com>

Re: [PATCH v4 2/2] selinux: add basic filtering for audit trace events

[Paul Moore]

On Fri, Aug 21, 2020 at 10:09 AM Thiébaud Weksteen <tweek@google.com> wrote:
>
> From: Peter Enderborg <peter.enderborg@sony.com>
>
> This patch adds further attributes to the event. These attributes are
> helpful to understand the context of the message and can be used
> to filter the events.
>
> There are three common items. Source context, target context and tclass.
> There are also items from the outcome of operation performed.
>
> An event is similar to:
>            <...>-1309  [002] ....  6346.691689: selinux_audited:
>        requested=0x4000000 denied=0x4000000 audited=0x4000000
>        result=-13
>        scontext=system_u:system_r:cupsd_t:s0-s0:c0.c1023
>        tcontext=system_u:object_r:bin_t:s0 tclass=file
>
> With systems where many denials are occurring, it is useful to apply a
> filter. The filtering is a set of logic that is inserted with
> the filter file. Example:
>  echo "tclass==\"file\" " > events/avc/selinux_audited/filter
>
> This adds that we only get tclass=file.
>
> The trace can also have extra properties. Adding the user stack
> can be done with
>    echo 1 > options/userstacktrace
>
> Now the output will be
>          runcon-1365  [003] ....  6960.955530: selinux_audited:
>      requested=0x4000000 denied=0x4000000 audited=0x4000000
>      result=-13
>      scontext=system_u:system_r:cupsd_t:s0-s0:c0.c1023
>      tcontext=system_u:object_r:bin_t:s0 tclass=file
>           runcon-1365  [003] ....  6960.955560: <user stack trace>
>  =>  <00007f325b4ce45b>
>  =>  <00005607093efa57>
>
> Signed-off-by: Peter Enderborg <peter.enderborg@sony.com>
> Reviewed-by: Thiébaud Weksteen <tweek@google.com>
> ---
>  include/trace/events/avc.h | 36 ++++++++++++++++++++++++++----------
>  security/selinux/avc.c     | 28 +++++++++++++++-------------
>  2 files changed, 41 insertions(+), 23 deletions(-)

... also merged into selinux/next, thanks everyone!

-- 
paul moore
www.paul-moore.com