2023-01-04 19:00:05

by Mirsad Todorovac

[permalink] [raw]
Subject: BUG: core dump in selftest of proc fs

Dear all,

Trying to complete `make kselftest` for the first time, so maybe I'm doing something wrong?

Or we are having a regression in 6.2-rc2 release candidate ...

However, the output of selftest run is:

make[2]: Entering directory '.../linux_torvalds/tools/testing/selftests/proc'
TAP version 13
1..21
# selftests: proc: fd-001-lookup
ok 1 selftests: proc: fd-001-lookup
# selftests: proc: fd-002-posix-eq
ok 2 selftests: proc: fd-002-posix-eq
# selftests: proc: fd-003-kthread
ok 3 selftests: proc: fd-003-kthread
# selftests: proc: proc-loadavg-001
ok 4 selftests: proc: proc-loadavg-001
# selftests: proc: proc-empty-vm
# proc-empty-vm: proc-empty-vm.c:184: test_proc_pid_maps: Assertion `rv == 0' failed.
# /usr/bin/timeout: the monitored command dumped core
# Aborted
not ok 5 selftests: proc: proc-empty-vm # exit=134
# selftests: proc: proc-pid-vm
# proc-pid-vm: proc-pid-vm.c:365: main: Assertion `rv == len' failed.
# /usr/bin/timeout: the monitored command dumped core
# Aborted

Please find attached lshw output, dmesg, config and lsmod.

I am available for further diagnostics.

The platform is Ubuntu 22.10 kinetic kudu on a Lenovo Ideapad 3 15ITL6 laptop.

Kind regards,
Mirsad

--
Mirsad Goran Todorovac
Sistem inženjer
Grafički fakultet | Akademija likovnih umjetnosti
Sveučilište u Zagrebu
--
System engineer
Faculty of Graphic Arts | Academy of Fine Arts
University of Zagreb, Republic of Croatia
The European Union


Attachments:
config-6.2.0-rc2-mglru-kmemlk-nokasan+.xz (43.85 kB)
dmesg.log.xz (26.30 kB)
lshw.txt.xz (5.06 kB)
lsmod.txt.xz (3.33 kB)
Download all attachments

2023-01-04 19:14:20

by Alexey Dobriyan

[permalink] [raw]
Subject: Re: BUG: core dump in selftest of proc fs

On Wed, Jan 04, 2023 at 07:27:40PM +0100, Mirsad Goran Todorovac wrote:
> Trying to complete `make kselftest` for the first time, so maybe I'm doing something wrong?
>
> Or we are having a regression in 6.2-rc2 release candidate ...
>
> However, the output of selftest run is:

> # proc-empty-vm: proc-empty-vm.c:184: test_proc_pid_maps: Assertion `rv == 0' failed.
> # /usr/bin/timeout: the monitored command dumped core
> # Aborted
> not ok 5 selftests: proc: proc-empty-vm # exit=134
> # selftests: proc: proc-pid-vm
> # proc-pid-vm: proc-pid-vm.c:365: main: Assertion `rv == len' failed.
> # /usr/bin/timeout: the monitored command dumped core
> # Aborted
>
> Please find attached lshw output, dmesg, config and lsmod.
>
> I am available for further diagnostics.
>
> The platform is Ubuntu 22.10 kinetic kudu on a Lenovo Ideapad 3 15ITL6 laptop.

What the output of "cat /proc/self/maps" ?

2023-01-06 10:48:25

by Alexey Dobriyan

[permalink] [raw]
Subject: Re: BUG: core dump in selftest of proc fs

On Wed, Jan 04, 2023 at 07:27:40PM +0100, Mirsad Goran Todorovac wrote:
> Dear all,
>
> Trying to complete `make kselftest` for the first time, so maybe I'm doing something wrong?
>
> Or we are having a regression in 6.2-rc2 release candidate ...
>
> However, the output of selftest run is:
>
> make[2]: Entering directory '.../linux_torvalds/tools/testing/selftests/proc'
> TAP version 13
> 1..21
> # selftests: proc: fd-001-lookup
> ok 1 selftests: proc: fd-001-lookup
> # selftests: proc: fd-002-posix-eq
> ok 2 selftests: proc: fd-002-posix-eq
> # selftests: proc: fd-003-kthread
> ok 3 selftests: proc: fd-003-kthread
> # selftests: proc: proc-loadavg-001
> ok 4 selftests: proc: proc-loadavg-001
> # selftests: proc: proc-empty-vm
> # proc-empty-vm: proc-empty-vm.c:184: test_proc_pid_maps: Assertion `rv == 0' failed.
> # /usr/bin/timeout: the monitored command dumped core
> # Aborted
> not ok 5 selftests: proc: proc-empty-vm # exit=134
> # selftests: proc: proc-pid-vm
> # proc-pid-vm: proc-pid-vm.c:365: main: Assertion `rv == len' failed.
> # /usr/bin/timeout: the monitored command dumped core
> # Aborted
>
> Please find attached lshw output, dmesg, config and lsmod.
>
> I am available for further diagnostics.
>
> The platform is Ubuntu 22.10 kinetic kudu on a Lenovo Ideapad 3 15ITL6 laptop.

The "bug" is that "call rel32" instruction testing for executable
vsyscall page which should be relocated to "call 0xffffffffff600000"
is messed up. Ubuntu 22.10 ships with "vsyscall=xonly" so there should not be
any faults when executing from it. But segfault happens with normal
randomised userspace address.

I'll change it to "call *rax" which should be more robust (and works)
and free from relocations.

2023-01-06 13:57:34

by Mirsad Todorovac

[permalink] [raw]
Subject: Re: BUG: core dump in selftest of proc fs

On 06. 01. 2023. 11:39, Alexey Dobriyan wrote:
> On Wed, Jan 04, 2023 at 07:27:40PM +0100, Mirsad Goran Todorovac wrote:
>> Dear all,
>>
>> Trying to complete `make kselftest` for the first time, so maybe I'm doing something wrong?
>>
>> Or we are having a regression in 6.2-rc2 release candidate ...
>>
>> However, the output of selftest run is:
>>
>> make[2]: Entering directory '.../linux_torvalds/tools/testing/selftests/proc'
>> TAP version 13
>> 1..21
>> # selftests: proc: fd-001-lookup
>> ok 1 selftests: proc: fd-001-lookup
>> # selftests: proc: fd-002-posix-eq
>> ok 2 selftests: proc: fd-002-posix-eq
>> # selftests: proc: fd-003-kthread
>> ok 3 selftests: proc: fd-003-kthread
>> # selftests: proc: proc-loadavg-001
>> ok 4 selftests: proc: proc-loadavg-001
>> # selftests: proc: proc-empty-vm
>> # proc-empty-vm: proc-empty-vm.c:184: test_proc_pid_maps: Assertion `rv == 0' failed.
>> # /usr/bin/timeout: the monitored command dumped core
>> # Aborted
>> not ok 5 selftests: proc: proc-empty-vm # exit=134
>> # selftests: proc: proc-pid-vm
>> # proc-pid-vm: proc-pid-vm.c:365: main: Assertion `rv == len' failed.
>> # /usr/bin/timeout: the monitored command dumped core
>> # Aborted
>>
>> Please find attached lshw output, dmesg, config and lsmod.
>>
>> I am available for further diagnostics.
>>
>> The platform is Ubuntu 22.10 kinetic kudu on a Lenovo Ideapad 3 15ITL6 laptop.
>
> The "bug" is that "call rel32" instruction testing for executable
> vsyscall page which should be relocated to "call 0xffffffffff600000"
> is messed up. Ubuntu 22.10 ships with "vsyscall=xonly" so there should not be
> any faults when executing from it. But segfault happens with normal
> randomised userspace address.
>
> I'll change it to "call *rax" which should be more robust (and works)
> and free from relocations.

If you will need to test the patch in the same environment where the problem initially
occurred, I am ready at your disposal.

Thanks,
Mirsad

--
Mirsad Goran Todorovac
Sistem inženjer
Grafički fakultet | Akademija likovnih umjetnosti
Sveučilište u Zagrebu
--
System engineer
Faculty of Graphic Arts | Academy of Fine Arts
University of Zagreb, Republic of Croatia
The European Union

2023-01-06 14:17:42

by Mirsad Todorovac

[permalink] [raw]
Subject: Re: BUG: core dump in selftest of proc fs

On 04. 01. 2023. 19:36, Alexey Dobriyan wrote:
> On Wed, Jan 04, 2023 at 07:27:40PM +0100, Mirsad Goran Todorovac wrote:
>> Trying to complete `make kselftest` for the first time, so maybe I'm doing something wrong?
>>
>> Or we are having a regression in 6.2-rc2 release candidate ...
>>
>> However, the output of selftest run is:
>
>> # proc-empty-vm: proc-empty-vm.c:184: test_proc_pid_maps: Assertion `rv == 0' failed.
>> # /usr/bin/timeout: the monitored command dumped core
>> # Aborted
>> not ok 5 selftests: proc: proc-empty-vm # exit=134
>> # selftests: proc: proc-pid-vm
>> # proc-pid-vm: proc-pid-vm.c:365: main: Assertion `rv == len' failed.
>> # /usr/bin/timeout: the monitored command dumped core
>> # Aborted
>>
>> Please find attached lshw output, dmesg, config and lsmod.
>>
>> I am available for further diagnostics.
>>
>> The platform is Ubuntu 22.10 kinetic kudu on a Lenovo Ideapad 3 15ITL6 laptop.
>
> What the output of "cat /proc/self/maps" ?

root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds# cat /proc/self/maps
5606e3099000-5606e309b000 r--p 00000000 103:04 5505728 /usr/bin/cat
5606e309b000-5606e309f000 r-xp 00002000 103:04 5505728 /usr/bin/cat
5606e309f000-5606e30a1000 r--p 00006000 103:04 5505728 /usr/bin/cat
5606e30a1000-5606e30a2000 r--p 00007000 103:04 5505728 /usr/bin/cat
5606e30a2000-5606e30a3000 rw-p 00008000 103:04 5505728 /usr/bin/cat
5606e4804000-5606e4825000 rw-p 00000000 00:00 0 [heap]
7f9833400000-7f9833c42000 r--p 00000000 103:04 5505206 /usr/lib/locale/locale-archive
7f9833e00000-7f9833e22000 r--p 00000000 103:04 5506045 /usr/lib/x86_64-linux-gnu/libc.so.6
7f9833e22000-7f9833f9b000 r-xp 00022000 103:04 5506045 /usr/lib/x86_64-linux-gnu/libc.so.6
7f9833f9b000-7f9833ff2000 r--p 0019b000 103:04 5506045 /usr/lib/x86_64-linux-gnu/libc.so.6
7f9833ff2000-7f9833ff6000 r--p 001f1000 103:04 5506045 /usr/lib/x86_64-linux-gnu/libc.so.6
7f9833ff6000-7f9833ff8000 rw-p 001f5000 103:04 5506045 /usr/lib/x86_64-linux-gnu/libc.so.6
7f9833ff8000-7f9834005000 rw-p 00000000 00:00 0
7f983401e000-7f9834040000 rw-p 00000000 00:00 0
7f9834040000-7f9834097000 r--p 00000000 103:04 5636099 /usr/lib/locale/C.utf8/LC_CTYPE
7f9834097000-7f983409a000 rw-p 00000000 00:00 0
7f983409d000-7f983409e000 r--p 00000000 103:04 5636115 /usr/lib/locale/C.utf8/LC_NUMERIC
7f983409e000-7f983409f000 r--p 00000000 103:04 5636123 /usr/lib/locale/C.utf8/LC_TIME
7f983409f000-7f98340a0000 r--p 00000000 103:04 5636098 /usr/lib/locale/C.utf8/LC_COLLATE
7f98340a0000-7f98340a1000 r--p 00000000 103:04 5636111 /usr/lib/locale/C.utf8/LC_MONETARY
7f98340a1000-7f98340a2000 r--p 00000000 103:04 5636109 /usr/lib/locale/C.utf8/LC_MESSAGES/SYS_LC_MESSAGES
7f98340a2000-7f98340a3000 r--p 00000000 103:04 5636117 /usr/lib/locale/C.utf8/LC_PAPER
7f98340a3000-7f98340a4000 r--p 00000000 103:04 5636113 /usr/lib/locale/C.utf8/LC_NAME
7f98340a4000-7f98340a5000 r--p 00000000 103:04 5636097 /usr/lib/locale/C.utf8/LC_ADDRESS
7f98340a5000-7f98340a6000 r--p 00000000 103:04 5636121 /usr/lib/locale/C.utf8/LC_TELEPHONE
7f98340a6000-7f98340a7000 r--p 00000000 103:04 5636107 /usr/lib/locale/C.utf8/LC_MEASUREMENT
7f98340a7000-7f98340ae000 r--s 00000000 103:04 6164284 /usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache
7f98340ae000-7f98340af000 r--p 00000000 103:04 5636106 /usr/lib/locale/C.utf8/LC_IDENTIFICATION
7f98340af000-7f98340b1000 rw-p 00000000 00:00 0
7f98340b1000-7f98340b2000 r--p 00000000 103:04 5505669 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f98340b2000-7f98340db000 r-xp 00001000 103:04 5505669 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f98340db000-7f98340e5000 r--p 0002a000 103:04 5505669 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f98340e5000-7f98340e7000 r--p 00034000 103:04 5505669 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7f98340e7000-7f98340e9000 rw-p 00036000 103:04 5505669 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
7ffd0e771000-7ffd0e792000 rw-p 00000000 00:00 0 [stack]
7ffd0e7ec000-7ffd0e7f0000 r--p 00000000 00:00 0 [vvar]
7ffd0e7f0000-7ffd0e7f2000 r-xp 00000000 00:00 0 [vdso]
ffffffffff600000-ffffffffff601000 --xp 00000000 00:00 0 [vsyscall]
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds#

Sorry, overlooked your reply in the bunch of msgs. :(

Thanks,
Mirsad

--
Mirsad Goran Todorovac
Sistem inženjer
Grafički fakultet | Akademija likovnih umjetnosti
Sveučilište u Zagrebu
--
System engineer
Faculty of Graphic Arts | Academy of Fine Arts
University of Zagreb, Republic of Croatia
The European Union

2023-01-06 19:57:38

by Alexey Dobriyan

[permalink] [raw]
Subject: [PATCH] proc: fix PIE proc-empty-vm, proc-pid-vm tests

vsyscall detection code uses direct call to the beginning of
the vsyscall page:

asm ("call %P0" :: "i" (0xffffffffff600000))

It generates "call rel32" instruction but it is not relocated if binary
is PIE, so binary segfaults into random userspace address and vsyscall
page status is detected incorrectly.

Do more direct:

asm ("call *%rax")

which doesn't do need any relocaltions.

Mark g_vsyscall as volatile for a good measure, I didn't find instruction
setting it to 0. Now the code is obviously correct:

xor eax, eax
mov rdi, rbp
mov rsi, rbp
mov DWORD PTR [rip+0x2d15], eax # g_vsyscall = 0
mov rax, 0xffffffffff600000
call rax
mov DWORD PTR [rip+0x2d02], 1 # g_vsyscall = 1
mov eax, DWORD PTR ds:0xffffffffff600000
mov DWORD PTR [rip+0x2cf1], 2 # g_vsyscall = 2
mov edi, [rip+0x2ceb] # exit(g_vsyscall)
call exit

Note: fixed proc-empty-vm test oopses 5.19.0-28-generic kernel
but this is separate story.

Signed-off-by: Alexey Dobriyan <[email protected]>
Reported-by: Mirsad Goran Todorovac <[email protected]>
---

tools/testing/selftests/proc/proc-empty-vm.c | 12 +++++++-----
tools/testing/selftests/proc/proc-pid-vm.c | 9 +++++----
2 files changed, 12 insertions(+), 9 deletions(-)

--- a/tools/testing/selftests/proc/proc-empty-vm.c
+++ b/tools/testing/selftests/proc/proc-empty-vm.c
@@ -25,6 +25,7 @@
#undef NDEBUG
#include <assert.h>
#include <errno.h>
+#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
@@ -41,7 +42,7 @@
* 1: vsyscall VMA is --xp vsyscall=xonly
* 2: vsyscall VMA is r-xp vsyscall=emulate
*/
-static int g_vsyscall;
+static volatile int g_vsyscall;
static const char *g_proc_pid_maps_vsyscall;
static const char *g_proc_pid_smaps_vsyscall;

@@ -147,11 +148,12 @@ static void vsyscall(void)

g_vsyscall = 0;
/* gettimeofday(NULL, NULL); */
+ uint64_t rax = 0xffffffffff600000;
asm volatile (
- "call %P0"
- :
- : "i" (0xffffffffff600000), "D" (NULL), "S" (NULL)
- : "rax", "rcx", "r11"
+ "call *%[rax]"
+ : [rax] "+a" (rax)
+ : "D" (NULL), "S" (NULL)
+ : "rcx", "r11"
);

g_vsyscall = 1;
--- a/tools/testing/selftests/proc/proc-pid-vm.c
+++ b/tools/testing/selftests/proc/proc-pid-vm.c
@@ -257,11 +257,12 @@ static void vsyscall(void)

g_vsyscall = 0;
/* gettimeofday(NULL, NULL); */
+ uint64_t rax = 0xffffffffff600000;
asm volatile (
- "call %P0"
- :
- : "i" (0xffffffffff600000), "D" (NULL), "S" (NULL)
- : "rax", "rcx", "r11"
+ "call *%[rax]"
+ : [rax] "+a" (rax)
+ : "D" (NULL), "S" (NULL)
+ : "rcx", "r11"
);

g_vsyscall = 1;

2023-01-06 21:14:13

by Mirsad Todorovac

[permalink] [raw]
Subject: Re: [PATCH] proc: fix PIE proc-empty-vm, proc-pid-vm tests

Hi,

On 06. 01. 2023. 20:30, Alexey Dobriyan wrote:
> vsyscall detection code uses direct call to the beginning of
> the vsyscall page:
>
> asm ("call %P0" :: "i" (0xffffffffff600000))
>
> It generates "call rel32" instruction but it is not relocated if binary
> is PIE, so binary segfaults into random userspace address and vsyscall
> page status is detected incorrectly.
>
> Do more direct:
>
> asm ("call *%rax")
>
> which doesn't do need any relocaltions.
>
> Mark g_vsyscall as volatile for a good measure, I didn't find instruction
> setting it to 0. Now the code is obviously correct:
>
> xor eax, eax
> mov rdi, rbp
> mov rsi, rbp
> mov DWORD PTR [rip+0x2d15], eax # g_vsyscall = 0
> mov rax, 0xffffffffff600000
> call rax
> mov DWORD PTR [rip+0x2d02], 1 # g_vsyscall = 1
> mov eax, DWORD PTR ds:0xffffffffff600000
> mov DWORD PTR [rip+0x2cf1], 2 # g_vsyscall = 2
> mov edi, [rip+0x2ceb] # exit(g_vsyscall)
> call exit
>
> Note: fixed proc-empty-vm test oopses 5.19.0-28-generic kernel
> but this is separate story.
>
> Signed-off-by: Alexey Dobriyan <[email protected]>
> Reported-by: Mirsad Goran Todorovac <[email protected]>
> ---
>
> tools/testing/selftests/proc/proc-empty-vm.c | 12 +++++++-----
> tools/testing/selftests/proc/proc-pid-vm.c | 9 +++++----
> 2 files changed, 12 insertions(+), 9 deletions(-)
>
> --- a/tools/testing/selftests/proc/proc-empty-vm.c
> +++ b/tools/testing/selftests/proc/proc-empty-vm.c
> @@ -25,6 +25,7 @@
> #undef NDEBUG
> #include <assert.h>
> #include <errno.h>
> +#include <stdint.h>
> #include <stdio.h>
> #include <stdlib.h>
> #include <string.h>
> @@ -41,7 +42,7 @@
> * 1: vsyscall VMA is --xp vsyscall=xonly
> * 2: vsyscall VMA is r-xp vsyscall=emulate
> */
> -static int g_vsyscall;
> +static volatile int g_vsyscall;
> static const char *g_proc_pid_maps_vsyscall;
> static const char *g_proc_pid_smaps_vsyscall;
>
> @@ -147,11 +148,12 @@ static void vsyscall(void)
>
> g_vsyscall = 0;
> /* gettimeofday(NULL, NULL); */
> + uint64_t rax = 0xffffffffff600000;
> asm volatile (
> - "call %P0"
> - :
> - : "i" (0xffffffffff600000), "D" (NULL), "S" (NULL)
nt> - : "rax", "rcx", "r11"
> + "call *%[rax]"
> + : [rax] "+a" (rax)
> + : "D" (NULL), "S" (NULL)
> + : "rcx", "r11"
> );
>
> g_vsyscall = 1;
> --- a/tools/testing/selftests/proc/proc-pid-vm.c
> +++ b/tools/testing/selftests/proc/proc-pid-vm.c
> @@ -257,11 +257,12 @@ static void vsyscall(void)
>
> g_vsyscall = 0;
> /* gettimeofday(NULL, NULL); */
> + uint64_t rax = 0xffffffffff600000;
> asm volatile (
> - "call %P0"
> - :
> - : "i" (0xffffffffff600000), "D" (NULL), "S" (NULL)
> - : "rax", "rcx", "r11"
> + "call *%[rax]"
> + : [rax] "+a" (rax)
> + : "D" (NULL), "S" (NULL)
> + : "rcx", "r11"
> );
>
> g_vsyscall = 1;

I can confirm that the patch fixed the core dump in the exact environment that
used to reproduce the bug.

Apparently, it seems that gcc 12.2.0 -O2 optimiser on Ubuntu 22.10 kinetic kudu
did some new creative stuff to Alexey's code. For someone interested, I have saved the
assembly with and w/o -O2 ...

However, I have just found some spurious bug in proc-uptime-001.

But, this is another story ...

Thanks,
Mirsad

--
Mirsad Goran Todorovac
Sistem inženjer
Grafički fakultet | Akademija likovnih umjetnosti
Sveučilište u Zagrebu
--
System engineer
Faculty of Graphic Arts | Academy of Fine Arts
University of Zagreb, Republic of Croatia
The European Union

2023-01-06 22:06:06

by Mirsad Todorovac

[permalink] [raw]
Subject: BUG: assert spuriously fails in selftest/proc/proc-uptime-001.c

Hi all,

In the same environment as the previous bug report (Lenovo Ideapad 3 15ITL6 laptop
running Ubuntu 22.10 kinetic kudu and 6.2-rc2 vanilla Torvalds tree kernel), the
next test in the ...selftest/proc/* sequence spuriously fails in assert (i1 <= i0).

Please note that the compiler is the novelty GCC 12.2.0-3ubuntu1.

This was previously hidden by premature hang in the `make kselftest` run due to
proc-empty-vm an proc-pid-vm problems that are now fixed.

root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001

It happens about half of the times the program is called.

The source seems OK, I can't tell why the idle counter doesn't look monotonic to
the program.

Hope this helps.

BTW, good news: this time I have checked independently, and this is the last test from the .../selftest/proc
group that doesn't have clean exit code 0.

Thanks,
Mirsad

--
Mirsad Goran Todorovac
Sistem inženjer
Grafički fakultet | Akademija likovnih umjetnosti
Sveučilište u Zagrebu
--
System engineer
Faculty of Graphic Arts | Academy of Fine Arts
University of Zagreb, Republic of Croatia
The European Union

2023-01-06 22:23:34

by Mirsad Todorovac

[permalink] [raw]
Subject: Re: BUG: assert spuriously fails in selftest/proc/proc-uptime-001.c

On 06. 01. 2023. 22:18, Mirsad Goran Todorovac wrote:
> Hi all,
>
> In the same environment as the previous bug report (Lenovo Ideapad 3 15ITL6 laptop
> running Ubuntu 22.10 kinetic kudu and 6.2-rc2 vanilla Torvalds tree kernel), the
> next test in the ...selftest/proc/* sequence spuriously fails in assert (i1 <= i0).
>
> Please note that the compiler is the novelty GCC 12.2.0-3ubuntu1.
>
> This was previously hidden by premature hang in the `make kselftest` run due to
> proc-empty-vm an proc-pid-vm problems that are now fixed.
>
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
> proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
> Aborted (core dumped)
> root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
>
> It happens about half of the times the program is called.
>
> The source seems OK, I can't tell why the idle counter doesn't look monotonic to
> the program.
>
> Hope this helps.
>
> BTW, good news: this time I have checked independently, and this is the last test from the .../selftest/proc
> group that doesn't have clean exit code 0.

UPDATE:

The same behavior independently occurred with GCC 10.4.0, 9.5.0, 8.5.0 and 6.5.0.

Apparently this happens in 30% to 50% of attempts. Perhaps that's why it wasn't discovered yet:

root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# make CC=gcc-10
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread fd-001-lookup.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/fd-001-lookup
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread fd-002-posix-eq.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/fd-002-posix-eq
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread fd-003-kthread.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/fd-003-kthread
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-loadavg-001.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-loadavg-001
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-empty-vm.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-empty-vm
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-pid-vm.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-pid-vm
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-self-map-files-001.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-self-map-files-001
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-self-map-files-002.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-self-map-files-002
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-self-syscall.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-self-syscall
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-self-wchan.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-self-wchan
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-subset-pid.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-subset-pid
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-tid0.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-tid0
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-uptime-001.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-uptime-001
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-uptime-002.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-uptime-002
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread read.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/read
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread self.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/self
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread setns-dcache.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/setns-dcache
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread setns-sysvipc.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/setns-sysvipc
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread thread-self.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/thread-self
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-multiple-procfs.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-multiple-procfs
gcc-10 -Wall -O2 -Wno-unused-function -D_GNU_SOURCE -pthread proc-fsconfig-hidepid.c -o
/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc/proc-fsconfig-hidepid
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# for exe in `ls -l | grep -e -x |
awk '{ print $9 }'`; do echo -n ${exe}':'; ./$exe ; echo "exit=$?" ; done
fd-001-lookup:exit=0
fd-002-posix-eq:exit=0
fd-003-kthread:exit=0
proc-empty-vm:exit=0
proc-fsconfig-hidepid:exit=0
proc-loadavg-001:exit=0
proc-multiple-procfs:exit=0
proc-pid-vm:exit=0
proc-self-map-files-001:exit=0
proc-self-map-files-002:exit=0
proc-self-syscall:exit=0
proc-self-wchan:exit=0
proc-subset-pid:exit=0
proc-tid0:exit=0
proc-uptime-001:exit=0
proc-uptime-002:exit=0
read:exit=0
self:exit=0
setns-dcache:exit=0
setns-sysvipc:exit=0
thread-self:exit=0
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
proc-uptime-001: proc-uptime-001.c:39: main: Assertion `i1 >= i0' failed.
Aborted (core dumped)
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001
root@marvin-IdeaPad-3-15ITL6:/home/marvin/linux/kernel/linux_torvalds/tools/testing/selftests/proc# ./proc-uptime-001

The conclusion (to state the obvious) is that the GCC 12.2.0 optimisations are
not the culprit this time :-/

Thanks,
Mirsad

--
Mirsad Goran Todorovac
Sistem inženjer
Grafički fakultet | Akademija likovnih umjetnosti
Sveučilište u Zagrebu
--
System engineer
Faculty of Graphic Arts | Academy of Fine Arts
University of Zagreb, Republic of Croatia
The European Union