autotune inside qemu: early shot and segfault

autotune inside qemu: early shot and segfault

[Florian Bezdeka]

Hi all,

first issue:

maybe someone can explain what's going on here. I'm running autotune 
inside qemu (ARM) on an x86_64 host and get the error below. The 
kernel in use is 4.19 (ipipe) build with current "next" branch.

root@demo:~# autotune2 
== auto-tuning started, period=1000000 ns (may take a while)
irq gravity... 0 ns
kernel gravity... autotune: tuning failed (kernel): Resource temporarily unavailable

dmesg tells me

[   92.800781] [Xenomai] autotune(irqhand) started
[  102.499494] [Xenomai] autotune(kthread) started
[  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
[  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]


Any idea why / how this early shot can happen? I'm unable to 
reproduce it on a real hardware like the beagle bone black. 
I wonder why it seems to work in the CI setup...



Second issue: From time to time autotune produces a segfault:

root@demo:~# autotune 
== auto-tuning started, period=1000000 ns (may take a while)
irq gravity... 1984 ns
kernel gravity... 10912ns
user gravity... Segmentation fault

I haven't seen the segfault with a dovetail enabled kernel yet.
So it might be ipipe related...

I was able to reproduce once with gdb attached. We seem to crash 
in rtmd.c line 170 (do_ioctl, XENOMAI_SYSCALL3()). GDB was 
unable to present a backtrace. ("previous frame identical to this 
frame (corrupt stack?")


TIA,
Florian

-- 
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux

Re: autotune inside qemu: early shot and segfault

[Jan Kiszka]

On 27.08.21 11:57, Florian Bezdeka wrote:
> Hi all,
> 
> first issue:
> 
> maybe someone can explain what's going on here. I'm running autotune 
> inside qemu (ARM) on an x86_64 host and get the error below. The 
> kernel in use is 4.19 (ipipe) build with current "next" branch.
> 
> root@demo:~# autotune2 
> == auto-tuning started, period=1000000 ns (may take a while)
> irq gravity... 0 ns
> kernel gravity... autotune: tuning failed (kernel): Resource temporarily unavailable
> 
> dmesg tells me
> 
> [   92.800781] [Xenomai] autotune(irqhand) started
> [  102.499494] [Xenomai] autotune(kthread) started
> [  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
> [  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]
> 
> 
> Any idea why / how this early shot can happen? I'm unable to 
> reproduce it on a real hardware like the beagle bone black. 
> I wonder why it seems to work in the CI setup...
> 
> 
> 
> Second issue: From time to time autotune produces a segfault:
> 
> root@demo:~# autotune 
> == auto-tuning started, period=1000000 ns (may take a while)
> irq gravity... 1984 ns
> kernel gravity... 10912ns
> user gravity... Segmentation fault
> 
> I haven't seen the segfault with a dovetail enabled kernel yet.
> So it might be ipipe related...
> 
> I was able to reproduce once with gdb attached. We seem to crash 
> in rtmd.c line 170 (do_ioctl, XENOMAI_SYSCALL3()). GDB was 
> unable to present a backtrace. ("previous frame identical to this 
> frame (corrupt stack?")
> 

Does corectl provide some hints? Is the kernel reporting a userspace or
a kernel space fault?

Jan

-- 
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux

Re: autotune inside qemu: early shot and segfault

[Bezdeka, Florian]

On Fri, 2021-08-27 at 12:03 +0200, Jan Kiszka wrote:
> On 27.08.21 11:57, Florian Bezdeka wrote:
> > Hi all,
> > 
> > first issue:
> > 
> > maybe someone can explain what's going on here. I'm running autotune 
> > inside qemu (ARM) on an x86_64 host and get the error below. The 
> > kernel in use is 4.19 (ipipe) build with current "next" branch.
> > 
> > root@demo:~# autotune2 
> > == auto-tuning started, period=1000000 ns (may take a while)
> > irq gravity... 0 ns
> > kernel gravity... autotune: tuning failed (kernel): Resource temporarily unavailable
> > 
> > dmesg tells me
> > 
> > [   92.800781] [Xenomai] autotune(irqhand) started
> > [  102.499494] [Xenomai] autotune(kthread) started
> > [  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
> > [  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]
> > 
> > 
> > Any idea why / how this early shot can happen? I'm unable to 
> > reproduce it on a real hardware like the beagle bone black. 
> > I wonder why it seems to work in the CI setup...
> > 
> > 
> > 
> > Second issue: From time to time autotune produces a segfault:
> > 
> > root@demo:~# autotune 
> > == auto-tuning started, period=1000000 ns (may take a while)
> > irq gravity... 1984 ns
> > kernel gravity... 10912ns
> > user gravity... Segmentation fault
> > 
> > I haven't seen the segfault with a dovetail enabled kernel yet.
> > So it might be ipipe related...
> > 
> > I was able to reproduce once with gdb attached. We seem to crash 
> > in rtmd.c line 170 (do_ioctl, XENOMAI_SYSCALL3()). GDB was 
> > unable to present a backtrace. ("previous frame identical to this 
> > frame (corrupt stack?")
> > 
> 
> Does corectl provide some hints? Is the kernel reporting a userspace or
> a kernel space fault?

dmesg doesn't list a segfault at all... Wrong routed signal? I'm going
to play with corectl, but there was nothing interesting so far.

> 
> Jan
> 

Re: autotune inside qemu: early shot and segfault

[Jan Kiszka]

On 27.08.21 12:22, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> On Fri, 2021-08-27 at 12:03 +0200, Jan Kiszka wrote:
>> On 27.08.21 11:57, Florian Bezdeka wrote:
>>> Hi all,
>>>
>>> first issue:
>>>
>>> maybe someone can explain what's going on here. I'm running autotune
>>> inside qemu (ARM) on an x86_64 host and get the error below. The
>>> kernel in use is 4.19 (ipipe) build with current "next" branch.
>>>
>>> root@demo:~# autotune2
>>> == auto-tuning started, period=1000000 ns (may take a while)
>>> irq gravity... 0 ns
>>> kernel gravity... autotune: tuning failed (kernel): Resource temporarily unavailable
>>>
>>> dmesg tells me
>>>
>>> [   92.800781] [Xenomai] autotune(irqhand) started
>>> [  102.499494] [Xenomai] autotune(kthread) started
>>> [  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
>>> [  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]
>>>
>>>
>>> Any idea why / how this early shot can happen? I'm unable to
>>> reproduce it on a real hardware like the beagle bone black.
>>> I wonder why it seems to work in the CI setup...
>>>
>>>
>>>
>>> Second issue: From time to time autotune produces a segfault:
>>>
>>> root@demo:~# autotune
>>> == auto-tuning started, period=1000000 ns (may take a while)
>>> irq gravity... 1984 ns
>>> kernel gravity... 10912ns
>>> user gravity... Segmentation fault
>>>
>>> I haven't seen the segfault with a dovetail enabled kernel yet.
>>> So it might be ipipe related...
>>>
>>> I was able to reproduce once with gdb attached. We seem to crash
>>> in rtmd.c line 170 (do_ioctl, XENOMAI_SYSCALL3()). GDB was
>>> unable to present a backtrace. ("previous frame identical to this
>>> frame (corrupt stack?")
>>>
>>
>> Does corectl provide some hints? Is the kernel reporting a userspace or
>> a kernel space fault?
> 
> dmesg doesn't list a segfault at all... Wrong routed signal? I'm going
> to play with corectl, but there was nothing interesting so far.
> 

I meant coredumpctl btw., just to be clear.

Jan

-- 
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux

Re: autotune inside qemu: early shot and segfault

[Bezdeka, Florian]

On Fri, 2021-08-27 at 12:23 +0200, Jan Kiszka wrote:
> On 27.08.21 12:22, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> > On Fri, 2021-08-27 at 12:03 +0200, Jan Kiszka wrote:
> > > On 27.08.21 11:57, Florian Bezdeka wrote:
> > > > Hi all,
> > > > 
> > > > first issue:
> > > > 
> > > > maybe someone can explain what's going on here. I'm running autotune
> > > > inside qemu (ARM) on an x86_64 host and get the error below. The
> > > > kernel in use is 4.19 (ipipe) build with current "next" branch.
> > > > 
> > > > root@demo:~# autotune2
> > > > == auto-tuning started, period=1000000 ns (may take a while)
> > > > irq gravity... 0 ns
> > > > kernel gravity... autotune: tuning failed (kernel): Resource temporarily unavailable
> > > > 
> > > > dmesg tells me
> > > > 
> > > > [   92.800781] [Xenomai] autotune(irqhand) started
> > > > [  102.499494] [Xenomai] autotune(kthread) started
> > > > [  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
> > > > [  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]
> > > > 
> > > > 
> > > > Any idea why / how this early shot can happen? I'm unable to
> > > > reproduce it on a real hardware like the beagle bone black.
> > > > I wonder why it seems to work in the CI setup...
> > > > 
> > > > 
> > > > 
> > > > Second issue: From time to time autotune produces a segfault:
> > > > 
> > > > root@demo:~# autotune
> > > > == auto-tuning started, period=1000000 ns (may take a while)
> > > > irq gravity... 1984 ns
> > > > kernel gravity... 10912ns
> > > > user gravity... Segmentation fault
> > > > 
> > > > I haven't seen the segfault with a dovetail enabled kernel yet.
> > > > So it might be ipipe related...
> > > > 
> > > > I was able to reproduce once with gdb attached. We seem to crash
> > > > in rtmd.c line 170 (do_ioctl, XENOMAI_SYSCALL3()). GDB was
> > > > unable to present a backtrace. ("previous frame identical to this
> > > > frame (corrupt stack?")
> > > > 
> > > 
> > > Does corectl provide some hints? Is the kernel reporting a userspace or
> > > a kernel space fault?
> > 
> > dmesg doesn't list a segfault at all... Wrong routed signal? I'm going
> > to play with corectl, but there was nothing interesting so far.
> > 
> 
> I meant coredumpctl btw., just to be clear.

Wow, once coredumpctl was installed I got:

Stack trace of thread 312:
                #0  0x00000000b6f50daa _Unwind_VRS_Pop (libgcc_s.so.1)

Compiler issue? I'm currently using
gcc version 10.2.1 20210110 (Debian 10.2.1-6)

> 
> Jan
> 

Re: autotune inside qemu: early shot and segfault

[Jan Kiszka]

On 27.08.21 13:39, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> On Fri, 2021-08-27 at 12:23 +0200, Jan Kiszka wrote:
>> On 27.08.21 12:22, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
>>> On Fri, 2021-08-27 at 12:03 +0200, Jan Kiszka wrote:
>>>> On 27.08.21 11:57, Florian Bezdeka wrote:
>>>>> Hi all,
>>>>>
>>>>> first issue:
>>>>>
>>>>> maybe someone can explain what's going on here. I'm running autotune
>>>>> inside qemu (ARM) on an x86_64 host and get the error below. The
>>>>> kernel in use is 4.19 (ipipe) build with current "next" branch.
>>>>>
>>>>> root@demo:~# autotune2
>>>>> == auto-tuning started, period=1000000 ns (may take a while)
>>>>> irq gravity... 0 ns
>>>>> kernel gravity... autotune: tuning failed (kernel): Resource temporarily unavailable
>>>>>
>>>>> dmesg tells me
>>>>>
>>>>> [   92.800781] [Xenomai] autotune(irqhand) started
>>>>> [  102.499494] [Xenomai] autotune(kthread) started
>>>>> [  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
>>>>> [  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]
>>>>>
>>>>>
>>>>> Any idea why / how this early shot can happen? I'm unable to
>>>>> reproduce it on a real hardware like the beagle bone black.
>>>>> I wonder why it seems to work in the CI setup...
>>>>>
>>>>>
>>>>>
>>>>> Second issue: From time to time autotune produces a segfault:
>>>>>
>>>>> root@demo:~# autotune
>>>>> == auto-tuning started, period=1000000 ns (may take a while)
>>>>> irq gravity... 1984 ns
>>>>> kernel gravity... 10912ns
>>>>> user gravity... Segmentation fault
>>>>>
>>>>> I haven't seen the segfault with a dovetail enabled kernel yet.
>>>>> So it might be ipipe related...
>>>>>
>>>>> I was able to reproduce once with gdb attached. We seem to crash
>>>>> in rtmd.c line 170 (do_ioctl, XENOMAI_SYSCALL3()). GDB was
>>>>> unable to present a backtrace. ("previous frame identical to this
>>>>> frame (corrupt stack?")
>>>>>
>>>>
>>>> Does corectl provide some hints? Is the kernel reporting a userspace or
>>>> a kernel space fault?
>>>
>>> dmesg doesn't list a segfault at all... Wrong routed signal? I'm going
>>> to play with corectl, but there was nothing interesting so far.
>>>
>>
>> I meant coredumpctl btw., just to be clear.
> 
> Wow, once coredumpctl was installed I got:
> 
> Stack trace of thread 312:
>                 #0  0x00000000b6f50daa _Unwind_VRS_Pop (libgcc_s.so.1)
> 
> Compiler issue? I'm currently using
> gcc version 10.2.1 20210110 (Debian 10.2.1-6)
> 

Wait: You have a Debian 10 where (gcc is gcc-8), but for this test you
built autotune (only that?) with gcc-10?

Jan

-- 
Siemens AG, T RDA IOT
Corporate Competence Center Embedded Linux

Re: autotune inside qemu: early shot and segfault

[Bezdeka, Florian]

On Fri, 2021-08-27 at 14:15 +0200, Jan Kiszka wrote:
> On 27.08.21 13:39, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> > On Fri, 2021-08-27 at 12:23 +0200, Jan Kiszka wrote:
> > > On 27.08.21 12:22, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> > > > On Fri, 2021-08-27 at 12:03 +0200, Jan Kiszka wrote:
> > > > > On 27.08.21 11:57, Florian Bezdeka wrote:
> > > > > > Hi all,
> > > > > > 
> > > > > > first issue:
> > > > > > 
> > > > > > maybe someone can explain what's going on here. I'm running autotune
> > > > > > inside qemu (ARM) on an x86_64 host and get the error below. The
> > > > > > kernel in use is 4.19 (ipipe) build with current "next" branch.
> > > > > > 
> > > > > > root@demo:~# autotune2
> > > > > > == auto-tuning started, period=1000000 ns (may take a while)
> > > > > > irq gravity... 0 ns
> > > > > > kernel gravity... autotune: tuning failed (kernel): Resource temporarily unavailable
> > > > > > 
> > > > > > dmesg tells me
> > > > > > 
> > > > > > [   92.800781] [Xenomai] autotune(irqhand) started
> > > > > > [  102.499494] [Xenomai] autotune(kthread) started
> > > > > > [  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
> > > > > > [  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]
> > > > > > 
> > > > > > 
> > > > > > Any idea why / how this early shot can happen? I'm unable to
> > > > > > reproduce it on a real hardware like the beagle bone black.
> > > > > > I wonder why it seems to work in the CI setup...
> > > > > > 
> > > > > > 
> > > > > > 
> > > > > > Second issue: From time to time autotune produces a segfault:
> > > > > > 
> > > > > > root@demo:~# autotune
> > > > > > == auto-tuning started, period=1000000 ns (may take a while)
> > > > > > irq gravity... 1984 ns
> > > > > > kernel gravity... 10912ns
> > > > > > user gravity... Segmentation fault
> > > > > > 
> > > > > > I haven't seen the segfault with a dovetail enabled kernel yet.
> > > > > > So it might be ipipe related...
> > > > > > 
> > > > > > I was able to reproduce once with gdb attached. We seem to crash
> > > > > > in rtmd.c line 170 (do_ioctl, XENOMAI_SYSCALL3()). GDB was
> > > > > > unable to present a backtrace. ("previous frame identical to this
> > > > > > frame (corrupt stack?")
> > > > > > 
> > > > > 
> > > > > Does corectl provide some hints? Is the kernel reporting a userspace or
> > > > > a kernel space fault?
> > > > 
> > > > dmesg doesn't list a segfault at all... Wrong routed signal? I'm going
> > > > to play with corectl, but there was nothing interesting so far.
> > > > 
> > > 
> > > I meant coredumpctl btw., just to be clear.
> > 
> > Wow, once coredumpctl was installed I got:
> > 
> > Stack trace of thread 312:
> >                 #0  0x00000000b6f50daa _Unwind_VRS_Pop (libgcc_s.so.1)
> > 
> > Compiler issue? I'm currently using
> > gcc version 10.2.1 20210110 (Debian 10.2.1-6)
> > 
> 
> Wait: You have a Debian 10 where (gcc is gcc-8), but for this test you
> built autotune (only that?) with gcc-10?

It happens with a 1:1 xenomai-images build as well.

> 
> Jan
> 

Re: autotune inside qemu: early shot and segfault

[Lennart Sorensen]

On Fri, Aug 27, 2021 at 02:15:29PM +0200, Jan Kiszka via Xenomai wrote:
> On 27.08.21 13:39, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> > Wow, once coredumpctl was installed I got:
> > 
> > Stack trace of thread 312:
> >                 #0  0x00000000b6f50daa _Unwind_VRS_Pop (libgcc_s.so.1)
> > 
> > Compiler issue? I'm currently using
> > gcc version 10.2.1 20210110 (Debian 10.2.1-6)
> > 
> 
> Wait: You have a Debian 10 where (gcc is gcc-8), but for this test you
> built autotune (only that?) with gcc-10?

Debian 11 uses gcc 10.2.1.  The version says "Debian 10.2.1-6) meaning
gcc version is debian package version 10.2.1-6.  It would certainly be
Debian 11.

-- 
Len Sorensen

Re: autotune inside qemu: early shot and segfault

[Bezdeka, Florian]

On Fri, 2021-08-27 at 10:31 -0400, Lennart Sorensen wrote:
> On Fri, Aug 27, 2021 at 02:15:29PM +0200, Jan Kiszka via Xenomai wrote:
> > On 27.08.21 13:39, Bezdeka, Florian (T RDA IOT SES-DE) wrote:
> > > Wow, once coredumpctl was installed I got:
> > > 
> > > Stack trace of thread 312:
> > >                 #0  0x00000000b6f50daa _Unwind_VRS_Pop (libgcc_s.so.1)
> > > 
> > > Compiler issue? I'm currently using
> > > gcc version 10.2.1 20210110 (Debian 10.2.1-6)
> > > 
> > 
> > Wait: You have a Debian 10 where (gcc is gcc-8), but for this test you
> > built autotune (only that?) with gcc-10?
> 
> Debian 11 uses gcc 10.2.1.  The version says "Debian 10.2.1-6) meaning
> gcc version is debian package version 10.2.1-6.  It would certainly be
> Debian 11.
> 

There is no mix between Debian 10 and 11. It's 11. Always. I updated
xenomai-images locally to be based on Debian 11 already. That's were
gcc 10 comes into the game.

I was able to narrow this problem down to a forwarded directory from
the host to the qemu guest. For performance reasons I cross-compiled
all Xenomai components on the host and forwared it into the guest. That
worked fine up to now, but seems to have this side effect. (The
segfault happens whenever I get over the "kernel gravity stage". See
below.)

One problem remaining:
99% of autotune runs are failing in the "kernel gravity" stage with
"Resource temporarily unavailable". That can be seen in CI runs as
well. It does not matter if ipipe or dovetail is running in the kernel.

Limiting the number of CPUs of the qemu guest to "1" fixes this
problem.

In multi-CPU setups dmesg complains about an early shot:

[   92.800781] [Xenomai] autotune(irqhand) started
[  102.499494] [Xenomai] autotune(kthread) started
[  108.623898] [Xenomai] autotune(kthread) failed with early shot (827251 ns)
[  108.646795] [Xenomai] autotune finished [0i/5000k/5000u]

Any ideas?