BUG: core dump in selftest of proc fs

BUG: core dump in selftest of proc fs

[Mirsad Goran Todorovac]

[-- Attachment #1: Type: text/plain, Size: 1444 bytes --]

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

[-- Attachment #2: config-6.2.0-rc2-mglru-kmemlk-nokasan+.xz --]
[-- Type: application/x-xz, Size: 44904 bytes --]

[-- Attachment #3: dmesg.log.xz --]
[-- Type: application/x-xz, Size: 26936 bytes --]

[-- Attachment #4: lshw.txt.xz --]
[-- Type: application/x-xz, Size: 5184 bytes --]

[-- Attachment #5: lsmod.txt.xz --]
[-- Type: application/x-xz, Size: 3412 bytes --]

Re: BUG: core dump in selftest of proc fs

[Alexey Dobriyan]

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" ?

Re: BUG: core dump in selftest of proc fs

[Mirsad Goran Todorovac]

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

Re: BUG: core dump in selftest of proc fs

[Alexey Dobriyan]

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.

Re: BUG: core dump in selftest of proc fs

[Mirsad Goran Todorovac]

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

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

[Alexey Dobriyan]

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 <adobriyan@gmail.com>
Reported-by: Mirsad Goran Todorovac <mirsad.todorovac@alu.unizg.hr>
---

 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;

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

[Mirsad Goran Todorovac]

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 <adobriyan@gmail.com>
> Reported-by: Mirsad Goran Todorovac <mirsad.todorovac@alu.unizg.hr>
> ---
> 
>   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

BUG: assert spuriously fails in selftest/proc/proc-uptime-001.c

[Mirsad Goran Todorovac]

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

Re: BUG: assert spuriously fails in selftest/proc/proc-uptime-001.c

[Mirsad Goran Todorovac]

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