Two notes based on my past experimentation:

1) These messages are rate-limited, which makes them even less useful for debugging.  For every one denial you see, there are 1000 more that are never printed.

2) If you drop all messages containing "permissive=1" you'll still get spammed with audit messages from Android.  These will also be rate-limited (and therefore they aren't useful for identifying/diagnosing specific failures).

This is pretty annoying, and it inspires erroneous bug reports, where people don't notice the "permissive=1", meaning nothing was actually rejected. It also can make feedback report logs less useful. Anybody see a good path to resolving this bug?

My suggestions:

If (as claimed above) these messages aren't really useful, can't we just disable the prints entirely? Is anybody relying on them?

Or if they are useful, can we spin up a user-space daemon to take care of them instead? e.g., auditd [1]? It looks to me like the kernel auditing framework will stop printk()'ing them if it knows someone's listening via netlink [2].

[1] https://linux.die.net/man/8/auditd
[2] See code like this:
https://chromium.googlesource.com/chromiumos/third_party/kernel/+/chromeos-4.4/kernel/audit.c#529

			if (audit_pid)
				kauditd_send_skb(skb);
			else
				audit_printk_skb(skb);

Disabling the prints seems sane to me...  They are quite annoying.

Here's a patch that aborts the 'slow' part of the audit in the permissive=1 case (ie the part that generates the messages that are spamming the log):
  https://chromium-review.googlesource.com/413144

This shuts up the Chrome OS messages, but doesn't address cernekee's point 2 from #1.

@lhchavez - I saw in an email recently that you are now the SELinux policy guru.  What do you think of the patch in #4?

fwiw, people often use permissive=1 audit messages when developing SELinux policy (by running their app with SELinux in permissive mode then collecting all the denials that would have happened with SELinux enforcing). It might be nice to make this a knob to support that usecase with recompiling the kernel - two options could be having something like a sysctl or it would probably also be fine to enable these logs if SELinux is permissive globally across the system (as opposed to just in one domain).

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/1456e8755f19355e2d06430f6f378399b52571aa

commit 1456e8755f19355e2d06430f6f378399b52571aa
Author: Daniel Kurtz <djkurtz@chromium.org>
Date: Mon Nov 21 04:06:29 2016

CHROMIUM: selinux: Do not log "permissive" denials

If an access triggers an denial, but it was allowed due to a global or
per-domain permissive mode, (ie the message would have a "permissive=1"
field), don't even bother going through the slow audit path to print the
message.

The permissive=1 messages spam the kernel logs making it much harder to
see other useful messages.

On elm, each slow_avc_audit() call consumes ~10-60 us.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>

BUG= chromium:653575 
TEST=Boot, inspect /var/log/messages, no more messages like:
  [    1.372604] audit: type=1400 audit(1475767701.728:4): avc:  denied  { read } for  pid=1 comm="init" name="ld-linux-armhf.so.3" dev="dm-0" ino=40094 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=lnk_file permissive=1
  [    1.372640] audit: type=1400 audit(1475767701.728:5): avc:  denied  { execute } for  pid=1 comm="init" name="ld-2.19.so" dev="dm-0" ino=40084 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=file permissive=1

Change-Id: Ic5b0630299f6bcac53659771b6c0cfef9cc13e2e
Reviewed-on: https://chromium-review.googlesource.com/413144
Commit-Ready: Daniel Kurtz <djkurtz@chromium.org>
Tested-by: Daniel Kurtz <djkurtz@chromium.org>
Reviewed-by: Luis Hector Chavez <lhchavez@google.com>
Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org>

[modify] https://crrev.com/1456e8755f19355e2d06430f6f378399b52571aa/security/selinux/avc.c

Wait, is the CL from #7 supposed to be a solution to this bug? That does something only when !IS_ENABLED(CONFIG_SECURITY_SELINUX_DEVELOP), but elm (and all other new boards) have USE=android_test, which means CONFIG_SECURITY_SELINUX_DEVELOP is enabled...

Correction: I didn't see this:

https://chromium-review.googlesource.com/#/c/413167/

Never mind me. (And thanks Dan!)

Ooh, but that doesn't quite work for kernel 4.4 at least. b/30375666 never happened for kernel 4.4, so the 'android_test' USE flag still means we accept the default value for SECURITY_SELINUX_DEVELOP, which is =y.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/741fdb68030d96fe8e4b159abd87c1d210e381d5

commit 741fdb68030d96fe8e4b159abd87c1d210e381d5
Author: Daniel Kurtz <djkurtz@chromium.org>
Date: Mon Nov 21 04:06:29 2016

CHROMIUM: selinux: Do not log "permissive" denials

If an access triggers an denial, but it was allowed due to a global or
per-domain permissive mode, (ie the message would have a "permissive=1"
field), don't even bother going through the slow audit path to print the
message.

The permissive=1 messages spam the kernel logs making it much harder to
see other useful messages.

On elm, each slow_avc_audit() call consumes ~10-60 us.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>

BUG= chromium:653575 
TEST=Boot, inspect /var/log/messages, no more messages like:
  [    1.372604] audit: type=1400 audit(1475767701.728:4): avc:  denied  { read } for  pid=1 comm="init" name="ld-linux-armhf.so.3" dev="dm-0" ino=40094 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=lnk_file permissive=1
  [    1.372640] audit: type=1400 audit(1475767701.728:5): avc:  denied  { execute } for  pid=1 comm="init" name="ld-2.19.so" dev="dm-0" ino=40084 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=file permissive=1

Change-Id: Ic5b0630299f6bcac53659771b6c0cfef9cc13e2e
Reviewed-on: https://chromium-review.googlesource.com/413144
Commit-Ready: Daniel Kurtz <djkurtz@chromium.org>
Tested-by: Daniel Kurtz <djkurtz@chromium.org>
Reviewed-by: Luis Hector Chavez <lhchavez@google.com>
Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org>
(cherry picked from commit 1456e8755f19355e2d06430f6f378399b52571aa)
Reviewed-on: https://chromium-review.googlesource.com/414285
Commit-Ready: Brian Norris <briannorris@chromium.org>
Tested-by: Brian Norris <briannorris@chromium.org>

[modify] https://crrev.com/741fdb68030d96fe8e4b159abd87c1d210e381d5/security/selinux/avc.c

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/7711edc3c7a1d69d0c14c065260b862083723025

commit 7711edc3c7a1d69d0c14c065260b862083723025
Author: Brian Norris <briannorris@chromium.org>
Date: Wed Nov 23 19:40:42 2016

cros-kernel2: disable SECURITY_SELINUX_DEVELOP by default

USE=android_test is mostly getting merged into the default kernel
builds, but kernel 4.4 hasn't caught up yet. In the meantime, we moved
SECURITY_SELINUX_DEVELOP=y out into a separate USE=selinux_develop flag.
This works for kernels which chose to explicitly disable this in their
configs, but we haven't done that yet in 4.4.

Let's explicitly disable it in USE=android_test and let
USE=selinux_develop still add it back in.

BUG= chromium:653575 
TEST=emerge-kevin chromeos-kernel-4_4 with and without
     USE=selinux_develop, check /proc/config.gz

Change-Id: I40102aa5311a9485e18abd6598652d10723b2196
Signed-off-by: Brian Norris <briannorris@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/414404
Commit-Ready: Nicolas Boichat <drinkcat@chromium.org>
Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org>
Reviewed-by: Mike Frysinger <vapier@chromium.org>

[modify] https://crrev.com/7711edc3c7a1d69d0c14c065260b862083723025/eclass/cros-kernel2.eclass

I guess we should keep this open until all patches are merged to 4.4 (and 3.14)?

These patches are also required, were incorrectly labeled (for  issue 662450 ), and are requested for merge to 56:

https://chromium-review.googlesource.com/412625
https://chromium-review.googlesource.com/413167

Your change meets the bar and is auto-approved for M56 (branch: 2924)

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/80b78a0c55651d9beab6f98cb33a19022efd6c96

commit 80b78a0c55651d9beab6f98cb33a19022efd6c96
Author: Daniel Kurtz <djkurtz@chromium.org>
Date: Mon Nov 21 04:06:29 2016

CHROMIUM: selinux: Do not log "permissive" denials

If an access triggers an denial, but it was allowed due to a global or
per-domain permissive mode, (ie the message would have a "permissive=1"
field), don't even bother going through the slow audit path to print the
message.

The permissive=1 messages spam the kernel logs making it much harder to
see other useful messages.

On elm, each slow_avc_audit() call consumes ~10-60 us.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>

BUG= chromium:653575 
TEST=Boot, inspect /var/log/messages, no more messages like:
  [    1.372604] audit: type=1400 audit(1475767701.728:4): avc:  denied  { read } for  pid=1 comm="init" name="ld-linux-armhf.so.3" dev="dm-0" ino=40094 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=lnk_file permissive=1
  [    1.372640] audit: type=1400 audit(1475767701.728:5): avc:  denied  { execute } for  pid=1 comm="init" name="ld-2.19.so" dev="dm-0" ino=40084 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=file permissive=1

Change-Id: Ic5b0630299f6bcac53659771b6c0cfef9cc13e2e
Previous-Reviewed-on: https://chromium-review.googlesource.com/413144
(cherry picked from commit 8100c29529c3cb8ec8b4a43a28874c8f301b5a27)
Reviewed-on: https://chromium-review.googlesource.com/414677
Trybot-Ready: Daniel Kurtz <djkurtz@chromium.org>
Commit-Queue: Daniel Kurtz <djkurtz@chromium.org>
Tested-by: Daniel Kurtz <djkurtz@chromium.org>
Reviewed-by: Daniel Kurtz <djkurtz@chromium.org>

[modify] https://crrev.com/80b78a0c55651d9beab6f98cb33a19022efd6c96/security/selinux/avc.c

I ported to chromeos-3.14, and verified on samus:

I cherry-picked the eclass change to R56:
https://chromium-review.googlesource.com/#/c/414714/

I cherry-picked the 3.18 patches to R56 (release-R56-9000.B-chromeos-3.18):
https://chromium-review.googlesource.com/414772
https://chromium-review.googlesource.com/414677

I cherry-picked the 3.14 patches to R56 (release-R56-9000.B-chromeos-3.14):
https://chromium-review.googlesource.com/415008
https://chromium-review.googlesource.com/414833

Brian, can you cherry-pick to R56 any patches that are needed for 4.4?

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/9df9639fd8581d82694d3dbdc6ba8ef767c09102

commit 9df9639fd8581d82694d3dbdc6ba8ef767c09102
Author: Daniel Kurtz <djkurtz@chromium.org>
Date: Mon Nov 21 04:06:29 2016

CHROMIUM: selinux: Do not log "permissive" denials

If an access triggers an denial, but it was allowed due to a global or
per-domain permissive mode, (ie the message would have a "permissive=1"
field), don't even bother going through the slow audit path to print the
message.

The permissive=1 messages spam the kernel logs making it much harder to
see other useful messages.

On elm, each slow_avc_audit() call consumes ~10-60 us.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>

BUG= chromium:653575 
TEST=Boot, inspect /var/log/messages, no more messages like:
  [    1.372604] audit: type=1400 audit(1475767701.728:4): avc:  denied  { read } for  pid=1 comm="init" name="ld-linux-armhf.so.3" dev="dm-0" ino=40094 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=lnk_file permissive=1
  [    1.372640] audit: type=1400 audit(1475767701.728:5): avc:  denied  { execute } for  pid=1 comm="init" name="ld-2.19.so" dev="dm-0" ino=40084 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=file permissive=1

Change-Id: Ic5b0630299f6bcac53659771b6c0cfef9cc13e2e
Reviewed-on: https://chromium-review.googlesource.com/413144
Commit-Ready: Daniel Kurtz <djkurtz@chromium.org>
Tested-by: Daniel Kurtz <djkurtz@chromium.org>
Reviewed-by: Luis Hector Chavez <lhchavez@google.com>
Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org>
(cherry picked from commit 1456e8755f19355e2d06430f6f378399b52571aa)
Reviewed-on: https://chromium-review.googlesource.com/415124
Reviewed-by: Daniel Kurtz <djkurtz@chromium.org>

[modify] https://crrev.com/9df9639fd8581d82694d3dbdc6ba8ef767c09102/security/selinux/avc.c

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/8bf6d9dbf55c73aca2f8073a46397bb502b37e47

commit 8bf6d9dbf55c73aca2f8073a46397bb502b37e47
Author: Daniel Kurtz <djkurtz@chromium.org>
Date: Mon Nov 21 04:06:29 2016

CHROMIUM: selinux: Do not log "permissive" denials

If an access triggers an denial, but it was allowed due to a global or
per-domain permissive mode, (ie the message would have a "permissive=1"
field), don't even bother going through the slow audit path to print the
message.

The permissive=1 messages spam the kernel logs making it much harder to
see other useful messages.

On elm, each slow_avc_audit() call consumes ~10-60 us.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>

BUG= chromium:653575 
TEST=Boot, inspect /var/log/messages, no more messages like:
  [    1.372604] audit: type=1400 audit(1475767701.728:4): avc:  denied  { read } for  pid=1 comm="init" name="ld-linux-armhf.so.3" dev="dm-0" ino=40094 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=lnk_file permissive=1
  [    1.372640] audit: type=1400 audit(1475767701.728:5): avc:  denied  { execute } for  pid=1 comm="init" name="ld-2.19.so" dev="dm-0" ino=40084 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=file permissive=1

Change-Id: Ic5b0630299f6bcac53659771b6c0cfef9cc13e2e
Reviewed-on: https://chromium-review.googlesource.com/413144
Commit-Ready: Daniel Kurtz <djkurtz@chromium.org>
Tested-by: Daniel Kurtz <djkurtz@chromium.org>
Reviewed-by: Luis Hector Chavez <lhchavez@google.com>
Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org>
(cherry picked from commit 1456e8755f19355e2d06430f6f378399b52571aa)
Reviewed-on: https://chromium-review.googlesource.com/414285
Commit-Ready: Brian Norris <briannorris@chromium.org>
Tested-by: Brian Norris <briannorris@chromium.org>
(cherry picked from commit 741fdb68030d96fe8e4b159abd87c1d210e381d5)
Reviewed-on: https://chromium-review.googlesource.com/415028
Reviewed-by: Brian Norris <briannorris@chromium.org>
Commit-Queue: Brian Norris <briannorris@chromium.org>

[modify] https://crrev.com/8bf6d9dbf55c73aca2f8073a46397bb502b37e47/security/selinux/avc.c

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/05deaf023e440452397d17117eb21789687ddc34

commit 05deaf023e440452397d17117eb21789687ddc34
Author: Brian Norris <briannorris@chromium.org>
Date: Wed Nov 23 19:40:42 2016

cros-kernel2: disable SECURITY_SELINUX_DEVELOP by default

USE=android_test is mostly getting merged into the default kernel
builds, but kernel 4.4 hasn't caught up yet. In the meantime, we moved
SECURITY_SELINUX_DEVELOP=y out into a separate USE=selinux_develop flag.
This works for kernels which chose to explicitly disable this in their
configs, but we haven't done that yet in 4.4.

Let's explicitly disable it in USE=android_test and let
USE=selinux_develop still add it back in.

BUG= chromium:653575 
TEST=emerge-kevin chromeos-kernel-4_4 with and without
     USE=selinux_develop, check /proc/config.gz

Change-Id: I40102aa5311a9485e18abd6598652d10723b2196
Signed-off-by: Brian Norris <briannorris@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/414404
Commit-Ready: Nicolas Boichat <drinkcat@chromium.org>
Reviewed-by: Jorge Lucangeli Obes <jorgelo@chromium.org>
Reviewed-by: Mike Frysinger <vapier@chromium.org>
(cherry picked from commit 7711edc3c7a1d69d0c14c065260b862083723025)
Reviewed-on: https://chromium-review.googlesource.com/414251

[modify] https://crrev.com/05deaf023e440452397d17117eb21789687ddc34/eclass/cros-kernel2.eclass

OK, it looks like 3.18 and 4.4 are ready on R56.

Daniel, you haven't landed the changes in #19 for kernel 3.14 on R56. Were you still intending to?

@briannorris - yes, but I wanted to wait for them to land on ToT first, which they now have.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/f7a4d1d43efc2f767002307b4e892220ac4c36aa

commit f7a4d1d43efc2f767002307b4e892220ac4c36aa
Author: Daniel Kurtz <djkurtz@chromium.org>
Date: Mon Nov 21 04:06:29 2016

CHROMIUM: selinux: Do not log "permissive" denials

If an access triggers an denial, but it was allowed due to a global or
per-domain permissive mode, (ie the message would have a "permissive=1"
field), don't even bother going through the slow audit path to print the
message.

The permissive=1 messages spam the kernel logs making it much harder to
see other useful messages.

On elm, each slow_avc_audit() call consumes ~10-60 us.

Signed-off-by: Daniel Kurtz <djkurtz@chromium.org>

BUG= chromium:653575 
TEST=Boot, inspect /var/log/messages, no more messages like:
  [    1.372604] audit: type=1400 audit(1475767701.728:4): avc:  denied  { read } for  pid=1 comm="init" name="ld-linux-armhf.so.3" dev="dm-0" ino=40094 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=lnk_file permissive=1
  [    1.372640] audit: type=1400 audit(1475767701.728:5): avc:  denied  { execute } for  pid=1 comm="init" name="ld-2.19.so" dev="dm-0" ino=40084 scontext=u:r:kernel:s0 tcontext=u:object_r:unlabeled:s0 tclass=file permissive=1

Change-Id: Ic5b0630299f6bcac53659771b6c0cfef9cc13e2e
Previous-Reviewed-on: https://chromium-review.googlesource.com/413144
(cherry picked from commit 1456e8755f19355e2d06430f6f378399b52571aa)
Previous-Reviewed-on: https://chromium-review.googlesource.com/415124
(cherry picked from commit 8114788258362509b7a9481de5c1aa71145a1680)
Reviewed-on: https://chromium-review.googlesource.com/414833
Reviewed-by: Daniel Kurtz <djkurtz@chromium.org>
Commit-Queue: Daniel Kurtz <djkurtz@chromium.org>
Tested-by: Daniel Kurtz <djkurtz@chromium.org>
Trybot-Ready: Daniel Kurtz <djkurtz@chromium.org>

[modify] https://crrev.com/f7a4d1d43efc2f767002307b4e892220ac4c36aa/security/selinux/avc.c

Bulk-Verify

 Issue 681859  has been merged into this issue.