Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
MIME-Version: 1.0
References: <20230508075812.76077-1-eiichi.tsukata@nutanix.com>
 <CAHC9VhSh3_hiwzKN_YPKyO-s2tE5V0URTMrg_tbR5=cKkjzLrw@mail.gmail.com>
 <506299C8-B1D0-457D-881B-BF639224A3AD@nutanix.com> <0BA588DC-1E53-4BCE-B124-77C5C730C267@nutanix.com>
In-Reply-To: <0BA588DC-1E53-4BCE-B124-77C5C730C267@nutanix.com>
From:   Paul Moore <paul@paul-moore.com>
Date:   Wed, 17 May 2023 12:15:37 -0400
Message-ID: <CAHC9VhQaWvgwHGVv==FTdoEZhSqak02ijR7vt4h2pBU5Xs7-2A@mail.gmail.com>
Subject: Re: [PATCH 0/4] audit: refactor and fix for potential deadlock
To:     Eiichi Tsukata <eiichi.tsukata@nutanix.com>
Cc:     "eparis@redhat.com" <eparis@redhat.com>,
        "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
        "audit@vger.kernel.org" <audit@vger.kernel.org>
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
Precedence: bulk

On Wed, May 10, 2023 at 4:09=E2=80=AFAM Eiichi Tsukata
<eiichi.tsukata@nutanix.com> wrote:
> > On May 9, 2023, at 10:34, Eiichi Tsukata <eiichi.tsukata@nutanix.com> w=
rote:
> >> On May 8, 2023, at 23:07, Paul Moore <paul@paul-moore.com> wrote:
> >> On Mon, May 8, 2023 at 3:58=E2=80=AFAM Eiichi Tsukata
> >> <eiichi.tsukata@nutanix.com> wrote:
> >>> Commit 7ffb8e317bae ("audit: we don't need to
> >>> __set_current_state(TASK_RUNNING)") accidentally moved queue full che=
ck
> >>> before add_wait_queue_exclusive() which introduced the following race=
:
> >>>
> >>>   CPU1                           CPU2
> >>> =3D=3D=3D=3D=3D=3D=3D=3D                       =3D=3D=3D=3D=3D=3D=3D=
=3D
> >>> (in audit_log_start())         (in kauditd_thread())
> >>>
> >>> queue is full
> >>>                                wake_up(&audit_backlog_wait)
> >>>                                wait_event_freezable()
> >>> add_wait_queue_exclusive()
> >>> ...
> >>> schedule_timeout()
> >>>
> >>> Once this happens, both audit_log_start() and kauditd_thread() can ca=
use
> >>> deadlock for up to backlog_wait_time waiting for each other. To preve=
nt
> >>> the race, this patch adds queue full check after
> >>> prepare_to_wait_exclusive().
> >>
> >> Have you seen this occur in practice?
> >
> > Yes, we hit this issue multiple times, though it=E2=80=99s pretty rare =
as you are mentioning.
> > In our case, sshd got stuck in audit_log_user_message(), which caused S=
SH connection
> > timeout.
> >
>
> I found another case.
>
> kauditd_thread issues wake_up(&audit_backlog_wait) once after wake up.
> As waiter side is using add_wait_queue_exclusive() it only wakes up one p=
rocess at once.
>
> If kauditd wakes up a process which is sleeping in audit_log_start(), the=
n the process will
> queue skb and issue wake_up_interruptible(&kauditd_wait). No problem.
> But if kauditd wakes up a process which is sleeping in audit_receive(), t=
hen the process
> won=E2=80=99t try to wake up kauditd. In this case other processes sleepi=
ng in audit_log_start()
> keep sleeping even if kauditd have flushed the queue.
>
> At this point I=E2=80=99m planning to use non-exclusive wait in audit_rec=
eive() in v2.
> Let me know if we should use wake_up_all() in kauditd or you have better =
solution.

The nice part about marking the waiters as WQ_FLAG_EXCLUSIVE is that
we avoid the thundering herd problem.  The waiter was held in the
first place because the system was under high levels of audit
pressure, so it stands to reason that a slow wake-up of the waiters is
a wise choice to avoid re-entering another audit pressure state.

I'll take a look at your v2 patch, but as things stand I still believe
that this is better addressed via runtime configuration (see my
previous email).  However, some of the refactoring you've done might
be nice, I'll reply back on that in your v2 patch.

Thanks.

--=20
paul-moore.com