Fix for audit records on the console (RHBZ #1459326)

[Paul Moore]

First a quick link to the BZ, as it provides more detail and a link to
the patch:

* https://bugzilla.redhat.com/show_bug.cgi?id=1459326

Dusty and Adam reported a problem where audit records were
occasionally appearing on the system's console (via KERN_NOTICE) using
F26.  It took a couple of days to track down the problem and get a
reasonable fix in place, but it is now in the audit/next branch and
I'll be sending it to Linus during the next merge window.

I'm mixed as to if it is important enough to warrant a backport, but
if you do decide on the backport it should be relatively easy as the
patch is quite small and non-intrusive.

  commit c81be52a3ac0267aa830a2c4cb769030ea3483c9
  Author: Paul Moore <paul(a)paul-moore.com&gt;
  Date:   Mon Jun 12 09:35:24 2017 -0400

   audit: fix a race condition with the auditd tracking code

   Originally reported by Adam and Dusty, it appears we have a small
   race window in kauditd_thread(), as documented in the Fedora BZ:

    * https://bugzilla.redhat.com/show_bug.cgi?id=1459326#c35

    "This issue is partly due to the read-copy nature of RCU, and
     partly due to how we sync the auditd_connection state across
     kauditd_thread and the audit control channel.  The kauditd_thread
     thread is always running so it can service the record queues and
     emit the multicast messages, if it happens to be just past the
     "main_queue" label, but before the "if (sk == NULL || ...)"
     if-statement which calls auditd_reset() when the new auditd
     connection is registered it could end up resetting the auditd
     connection, regardless of if it is valid or not.  This is a rather
     small window and the variable nature of multi-core scheduling
     explains why this is proving rather difficult to reproduce."

   The fix is to have functions only call auditd_reset() when they
   believe that the kernel/auditd connection is still valid, e.g.
   non-NULL, and to have these callers pass their local copy of the
   auditd_connection pointer to auditd_reset() where it can be compared
   with the current connection state before resetting.  If the caller
   has a stale state tracking pointer then the reset is ignored.

   We also make a small change to kauditd_thread() so that if the
   kernel/auditd connection is dead we skip the retry queue and send the
   records straight to the hold queue.  This is necessary as we used to
   rely on auditd_reset() to occasionally purge the retry queue but we
   are going to be calling the reset function much less now and we want
   to make sure the retry queue doesn't grow unbounded.

   Reported-by: Adam Williamson <awilliam(a)redhat.com&gt;
   Reported-by: Dusty Mabe <dustymabe(a)redhat.com&gt;
   Reviewed-by: Richard Guy Briggs <rgb(a)redhat.com&gt;
   Signed-off-by: Paul Moore <paul(a)paul-moore.com&gt;

   audit.c |   36 +++++++++++++++++++++++-------------
   1 file changed, 23 insertions(+), 13 deletions(-)

-- 
paul moore
security @ redhat

[Laura Abbott]

On 06/16/2017 09:28 AM, Paul Moore wrote:
>  First a quick link to the BZ, as it provides more detail and a link
> to
>  the patch:
>  
>  * https://bugzilla.redhat.com/show_bug.cgi?id=1459326
>  
>  Dusty and Adam reported a problem where audit records were
>  occasionally appearing on the system's console (via KERN_NOTICE) using
>  F26.  It took a couple of days to track down the problem and get a
>  reasonable fix in place, but it is now in the audit/next branch and
>  I'll be sending it to Linus during the next merge window.
>  
>  I'm mixed as to if it is important enough to warrant a backport, but
>  if you do decide on the backport it should be relatively easy as the
>  patch is quite small and non-intrusive. 
Given it was important enough to file a bugzilla, I went ahead and
applied it to F24/F25/F26 since it went cleanly. It should show up
in the next kernel version.

>  
>    commit c81be52a3ac0267aa830a2c4cb769030ea3483c9
>    Author: Paul Moore <paul(a)paul-moore.com&gt;
>    Date:   Mon Jun 12 09:35:24 2017 -0400
>  
>     audit: fix a race condition with the auditd tracking code
>  
>     Originally reported by Adam and Dusty, it appears we have a small
>     race window in kauditd_thread(), as documented in the Fedora BZ:
>  
>      * https://bugzilla.redhat.com/show_bug.cgi?id=1459326#c35
>  
>      "This issue is partly due to the read-copy nature of RCU, and
>       partly due to how we sync the auditd_connection state across
>       kauditd_thread and the audit control channel.  The kauditd_thread
>       thread is always running so it can service the record queues and
>       emit the multicast messages, if it happens to be just past the
>       "main_queue" label, but before the "if (sk == NULL || ...)"
>       if-statement which calls auditd_reset() when the new auditd
>       connection is registered it could end up resetting the auditd
>       connection, regardless of if it is valid or not.  This is a rather
>       small window and the variable nature of multi-core scheduling
>       explains why this is proving rather difficult to reproduce."
>  
>     The fix is to have functions only call auditd_reset() when they
>     believe that the kernel/auditd connection is still valid, e.g.
>     non-NULL, and to have these callers pass their local copy of the
>     auditd_connection pointer to auditd_reset() where it can be compared
>     with the current connection state before resetting.  If the caller
>     has a stale state tracking pointer then the reset is ignored.
>  
>     We also make a small change to kauditd_thread() so that if the
>     kernel/auditd connection is dead we skip the retry queue and send the
>     records straight to the hold queue.  This is necessary as we used to
>     rely on auditd_reset() to occasionally purge the retry queue but we
>     are going to be calling the reset function much less now and we want
>     to make sure the retry queue doesn't grow unbounded.
>  
>     Reported-by: Adam Williamson <awilliam(a)redhat.com&gt;
>     Reported-by: Dusty Mabe <dustymabe(a)redhat.com&gt;
>     Reviewed-by: Richard Guy Briggs <rgb(a)redhat.com&gt;
>     Signed-off-by: Paul Moore <paul(a)paul-moore.com&gt;
>  
>     audit.c |   36 +++++++++++++++++++++++-------------
>     1 file changed, 23 insertions(+), 13 deletions(-)
>

[Adam Williamson]

On Fri, 2017-06-16 at 10:00 -0700, Laura Abbott wrote:
>  On 06/16/2017 09:28 AM, Paul Moore wrote:
>  > First a quick link to the BZ, as it provides more detail and a link to
>  > the patch:
>  > 
>  > * https://bugzilla.redhat.com/show_bug.cgi?id=1459326
>  > 
>  > Dusty and Adam reported a problem where audit records were
>  > occasionally appearing on the system's console (via KERN_NOTICE) using
>  > F26.  It took a couple of days to track down the problem and get a
>  > reasonable fix in place, but it is now in the audit/next branch and
>  > I'll be sending it to Linus during the next merge window.
>  > 
>  > I'm mixed as to if it is important enough to warrant a backport, but
>  > if you do decide on the backport it should be relatively easy as the
>  > patch is quite small and non-intrusive.
>  
>  Given it was important enough to file a bugzilla, I went ahead and
>  applied it to F24/F25/F26 since it went cleanly. It should show up
>  in the next kernel version. 
Thanks to both of you!
-- 
Adam Williamson
Fedora QA Community Monkey
IRC: adamw | Twitter: AdamW_Fedora | XMPP: adamw AT happyassassin . net
http://www.happyassassin.net