From: Daniel Harding <[email protected]>
To: Pavel Begunkov <[email protected]>
Cc: [email protected], [email protected],
[email protected],
Thorsten Leemhuis <[email protected]>,
Jens Axboe <[email protected]>,
Christian Brauner <[email protected]>
Subject: Re: [REGRESSION] lxc-stop hang on 5.17.x kernels
Date: Mon, 16 May 2022 16:57:05 +0300 [thread overview]
Message-ID: <[email protected]> (raw)
In-Reply-To: <[email protected]>
On 5/16/22 16:25, Pavel Begunkov wrote:
> On 5/16/22 13:12, Pavel Begunkov wrote:
>> On 5/15/22 19:34, Daniel Harding wrote:
>>> On 5/15/22 11:20, Thorsten Leemhuis wrote:
>>>> On 04.05.22 08:54, Daniel Harding wrote:
>>>>> On 5/3/22 17:14, Pavel Begunkov wrote:
>>>>>> On 5/3/22 08:37, Daniel Harding wrote:
>>>>>>> [Resend with a smaller trace]
>>>>>>> On 5/3/22 02:14, Pavel Begunkov wrote:
>>>>>>>> On 5/2/22 19:49, Daniel Harding wrote:
>>>>>>>>> On 5/2/22 20:40, Pavel Begunkov wrote:
>>>>>>>>>> On 5/2/22 18:00, Jens Axboe wrote:
>>>>>>>>>>> On 5/2/22 7:59 AM, Jens Axboe wrote:
>>>>>>>>>>>> On 5/2/22 7:36 AM, Daniel Harding wrote:
>>>>>>>>>>>>> On 5/2/22 16:26, Jens Axboe wrote:
>>>>>>>>>>>>>> On 5/2/22 7:17 AM, Daniel Harding wrote:
>>>>>>>>>>>>>>> I use lxc-4.0.12 on Gentoo, built with io-uring support
>>>>>>>>>>>>>>> (--enable-liburing), targeting liburing-2.1. My kernel
>>>>>>>>>>>>>>> config is a
>>>>>>>>>>>>>>> very lightly modified version of Fedora's generic kernel
>>>>>>>>>>>>>>> config. After
>>>>>>>>>>>>>>> moving from the 5.16.x series to the 5.17.x kernel
>>>>>>>>>>>>>>> series, I
>>>>>>>>>>>>>>> started
>>>>>>>>>>>>>>> noticed frequent hangs in lxc-stop. It doesn't happen 100%
>>>>>>>>>>>>>>> of the
>>>>>>>>>>>>>>> time, but definitely more than 50% of the time. Bisecting
>>>>>>>>>>>>>>> narrowed
>>>>>>>>>>>>>>> down the issue to commit
>>>>>>>>>>>>>>> aa43477b040251f451db0d844073ac00a8ab66ee:
>>>>>>>>>>>>>>> io_uring: poll rework. Testing indicates the problem is
>>>>>>>>>>>>>>> still
>>>>>>>>>>>>>>> present
>>>>>>>>>>>>>>> in 5.18-rc5. Unfortunately I do not have the expertise
>>>>>>>>>>>>>>> with the
>>>>>>>>>>>>>>> codebases of either lxc or io-uring to try to debug the
>>>>>>>>>>>>>>> problem
>>>>>>>>>>>>>>> further on my own, but I can easily apply patches to any
>>>>>>>>>>>>>>> of the
>>>>>>>>>>>>>>> involved components (lxc, liburing, kernel) and rebuild for
>>>>>>>>>>>>>>> testing or
>>>>>>>>>>>>>>> validation. I am also happy to provide any further
>>>>>>>>>>>>>>> information that
>>>>>>>>>>>>>>> would be helpful with reproducing or debugging the problem.
>>>>>>>>>>>>>> Do you have a recipe to reproduce the hang? That would
>>>>>>>>>>>>>> make it
>>>>>>>>>>>>>> significantly easier to figure out.
>>>>>>>>>>>>> I can reproduce it with just the following:
>>>>>>>>>>>>>
>>>>>>>>>>>>> sudo lxc-create --n lxc-test --template download --bdev
>>>>>>>>>>>>> dir --dir /var/lib/lxc/lxc-test/rootfs -- -d ubuntu -r bionic
>>>>>>>>>>>>> -a amd64
>>>>>>>>>>>>> sudo lxc-start -n lxc-test
>>>>>>>>>>>>> sudo lxc-stop -n lxc-test
>>>>>>>>>>>>>
>>>>>>>>>>>>> The lxc-stop command never exits and the container continues
>>>>>>>>>>>>> running.
>>>>>>>>>>>>> If that isn't sufficient to reproduce, please let me know.
>>>>>>>>>>>> Thanks, that's useful! I'm at a conference this week and
>>>>>>>>>>>> hence have
>>>>>>>>>>>> limited amount of time to debug, hopefully Pavel has time to
>>>>>>>>>>>> take a look
>>>>>>>>>>>> at this.
>>>>>>>>>>> Didn't manage to reproduce. Can you try, on both the good
>>>>>>>>>>> and bad
>>>>>>>>>>> kernel, to do:
>>>>>>>>>> Same here, it doesn't reproduce for me
>>>>>>>>> OK, sorry it wasn't something simple.
>>>>>>>>>> # echo 1 > /sys/kernel/debug/tracing/events/io_uring/enable
>>>>>>>>>>> run lxc-stop
>>>>>>>>>>>
>>>>>>>>>>> # cp /sys/kernel/debug/tracing/trace ~/iou-trace
>>>>>>>>>>>
>>>>>>>>>>> so we can see what's going on? Looking at the source, lxc is
>>>>>>>>>>> just
>>>>>>>>>>> using
>>>>>>>>>>> plain POLL_ADD, so I'm guessing it's not getting a notification
>>>>>>>>>>> when it
>>>>>>>>>>> expects to, or it's POLL_REMOVE not doing its job. If we have a
>>>>>>>>>>> trace
>>>>>>>>>>> from both a working and broken kernel, that might shed some
>>>>>>>>>>> light
>>>>>>>>>>> on it.
>>>>>>>>> It's late in my timezone, but I'll try to work on getting those
>>>>>>>>> traces tomorrow.
>>>>>>>> I think I got it, I've attached a trace.
>>>>>>>>
>>>>>>>> What's interesting is that it issues a multi shot poll but I don't
>>>>>>>> see any kind of cancellation, neither cancel requests nor
>>>>>>>> task/ring
>>>>>>>> exit. Perhaps have to go look at lxc to see how it's supposed
>>>>>>>> to work
>>>>>>> Yes, that looks exactly like my bad trace. I've attached good
>>>>>>> trace
>>>>>>> (captured with linux-5.16.19) and a bad trace (captured with
>>>>>>> linux-5.17.5). These are the differences I noticed with just a
>>>>>>> visual scan:
>>>>>>>
>>>>>>> * Both traces have three io_uring_submit_sqe calls at the very
>>>>>>> beginning, but in the good trace, there are further
>>>>>>> io_uring_submit_sqe calls throughout the trace, while in the bad
>>>>>>> trace, there are none.
>>>>>>> * The good trace uses a mask of c3 for io_uring_task_add much more
>>>>>>> often than the bad trace: the bad trace uses a mask of c3 only for
>>>>>>> the very last call to io_uring_task_add, but a mask of 41 for the
>>>>>>> other calls.
>>>>>>> * In the good trace, many of the io_uring_complete calls have a
>>>>>>> result of 195, while in the bad trace, they all have a result of 1.
>>>>>>>
>>>>>>> I don't know whether any of those things are significant or not,
>>>>>>> but
>>>>>>> that's what jumped out at me.
>>>>>>>
>>>>>>> I have also attached a copy of the script I used to generate the
>>>>>>> traces. If there is anything further I can to do help debug,
>>>>>>> please
>>>>>>> let me know.
>>>>>> Good observations! thanks for traces.
>>>>>>
>>>>>> It sounds like multi-shot poll requests were getting downgraded
>>>>>> to one-shot, which is a valid behaviour and was so because we
>>>>>> didn't fully support some cases. If that's the reason, than
>>>>>> the userspace/lxc is misusing the ABI. At least, that's the
>>>>>> working hypothesis for now, need to check lxc.
>>>>> So, I looked at the lxc source code, and it appears to at least
>>>>> try to
>>>>> handle the case of multi-shot being downgraded to one-shot. I don't
>>>>> know enough to know if the code is actually correct however:
>>>>>
>>>>> https://github.com/lxc/lxc/blob/7e37cc96bb94175a8e351025d26cc35dc2d10543/src/lxc/mainloop.c#L165-L189
>>>>>
>>>>> https://github.com/lxc/lxc/blob/7e37cc96bb94175a8e351025d26cc35dc2d10543/src/lxc/mainloop.c#L254
>>>>>
>>>>> https://github.com/lxc/lxc/blob/7e37cc96bb94175a8e351025d26cc35dc2d10543/src/lxc/mainloop.c#L288-L290
>>>>>
>>>> Hi, this is your Linux kernel regression tracker. Nothing happened
>>>> here
>>>> for round about ten days now afaics; or did the discussion continue
>>>> somewhere else.
>>>>
>>>> From what I gathered from this discussion is seems the root cause
>>>> might
>>>> be in LXC, but it was exposed by kernel change. That makes it sill a
>>>> kernel regression that should be fixed; or is there a strong reason
>>>> why
>>>> we should let this one slip?
>>>
>>> No, there hasn't been any discussion since the email you replied to.
>>> I've done a bit more testing on my end, but without anything
>>> conclusive. The one thing I can say is that my testing shows that
>>> LXC does correctly handle multi-shot poll requests which were being
>>> downgraded to one-shot in 5.16.x kernels, which I think invalidates
>>> Pavel's theory. In 5.17.x kernels, those same poll requests are no
>>> longer being downgraded to one-shot requests, and thus under 5.17.x
>>> LXC is no longer re-arming those poll requests (but also shouldn't
>>> need to, according to what is being returned by the kernel). I don't
>>> know if this change in kernel behavior is related to the hang, or if
>>> it is just a side effect of other io-uring changes that made it into
>>> 5.17. Nothing in the LXC's usage of io-uring seems obviously
>>> incorrect to me, but I am far from an expert. I also did some work
>>> toward creating a simpler reproducer, without success (I was able to
>>> get a simple program using io-uring running, but never could get it
>>> to hang). ISTM that this is still a kernel regression, unless
>>> someone can point out a definite fault in the way LXC is using
>>> io-uring.
>>
>> Haven't had time to debug it. Apparently LXC is stuck on
>> read(2) terminal fd. Not yet clear what is the reason.
>
> How it was with oneshots:
>
> 1: kernel: poll fires, add a CQE
> 2: kernel: remove poll
> 3: userspace: get CQE
> 4: userspace: read(terminal_fd);
> 5: userspace: add new poll
> 6: goto 1)
>
> What might happen and actually happens with multishot:
>
> 1: kernel: poll fires, add CQE1
> 2: kernel: poll fires again, add CQE2
> 3: userspace: get CQE1
> 4: userspace: read(terminal_fd); // reads all data, for both CQE1 and
> CQE2
> 5: userspace: get CQE2
> 6: userspace: read(terminal_fd); // nothing to read, hangs here
>
> It should be the read in lxc_terminal_ptx_io().
>
> IMHO, it's not a regression but a not perfect feature API and/or
> an API misuse.
>
> Cc: Christian Brauner
>
> Christian, in case you may have some input on the LXC side of things.
> Daniel reported an LXC problem when it uses io_uring multishot poll
> requests.
> Before aa43477b04025 ("io_uring: poll rework"), multishot poll
> requests for
> tty/pty and some other files were always downgraded to oneshots, which
> had
> been fixed by the commit and exposed the problem. I hope the example
> above
> explains it, but please let me know if it needs more details
Pavel, I had actually just started a draft email with the same theory
(although you stated it much more clearly than I could have). I'm
working on debugging the LXC side, but I'm pretty sure the issue is due
to LXC using blocking reads and getting stuck exactly as you describe.
If I can confirm this, I'll go ahead and mark this regression as invalid
and file an issue with LXC. Thanks for your help and patience.
--
Regards,
Daniel Harding
next prev parent reply other threads:[~2022-05-16 13:57 UTC|newest]
Thread overview: 26+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-05-02 13:17 [REGRESSION] lxc-stop hang on 5.17.x kernels Daniel Harding
2022-05-02 13:26 ` Jens Axboe
2022-05-02 13:36 ` Daniel Harding
2022-05-02 13:59 ` Jens Axboe
2022-05-02 17:00 ` Jens Axboe
2022-05-02 17:40 ` Pavel Begunkov
2022-05-02 18:49 ` Daniel Harding
2022-05-02 23:14 ` Pavel Begunkov
2022-05-03 7:37 ` Daniel Harding
2022-05-03 14:14 ` Pavel Begunkov
2022-05-04 6:54 ` Daniel Harding
2022-05-15 8:20 ` Thorsten Leemhuis
2022-05-15 18:34 ` Daniel Harding
2022-05-16 12:12 ` Pavel Begunkov
2022-05-16 13:25 ` Pavel Begunkov
2022-05-16 13:57 ` Daniel Harding [this message]
2022-05-16 15:13 ` Daniel Harding
2022-05-16 18:13 ` Pavel Begunkov
2022-05-17 8:19 ` Christian Brauner
2022-05-17 10:31 ` Pavel Begunkov
2022-05-16 18:17 ` Thorsten Leemhuis
2022-05-16 18:22 ` Jens Axboe
2022-05-16 18:34 ` Thorsten Leemhuis
2022-05-16 18:39 ` Jens Axboe
2022-05-16 19:07 ` Thorsten Leemhuis
2022-05-16 19:14 ` Jens Axboe
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
[email protected] \
[email protected] \
[email protected] \
[email protected] \
[email protected] \
[email protected] \
[email protected] \
[email protected] \
[email protected] \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox