FAIL: LTP: clone08.c:135: FAIL: ctid != getpid() (0 != 1008)

From: Naresh Kamboju
Date: Wed Oct 21 2020 - 12:12:41 EST

Next message: Greg Kroah-Hartman: "Re: [PATCH 1/1] usb: serial: option: add Quectel EC200T module support"
Previous message: Greg KH: "Buggy commit tracked to: "Re: [PATCH 2/9] iov_iter: move rw_copy_check_uvector() into lib/iov_iter.c""
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

LTP syscalls clone08 and clone301 FAILED on x86_64 KASAN enabled build
But tests are getting PASS on Non KASAN build.
This regression started happening from Linux next-20201015 nowards
Please refer to the strace output at the bottom of this email.

There are few more regression on linux next i will share those failure
in a separate email,
ltp-syscalls-tests:
* clone08
* clone301
* fcntl34
* fcntl34_64
* fcntl36
* fcntl36_64
* keyctl02
* rt_tgsigqueueinfo01

metadata:
git branch: master
git repo: https://gitlab.com/Linaro/lkft/mirrors/next/linux-next
git describe: next-20201015
kernel-config:
https://builds.tuxbuild.com/SCI7Xyjb7V2NbfQ2lbKBZw/kernel.config

steps to reproduce:
# boot x86_64 with KASAN enabled kernel and run tests
# cd /opt/ltp/testcases/bin
# ./clone08
# ./clone301

clone08:
---------
clone08.c:71: INFO: running CLONE_PARENT
clone08.c:115: PASS: clone and forked child has the same parent
clone08.c:71: INFO: running CLONE_CHILD_SETTID
clone08.c:135: FAIL: ctid != getpid() (0 != 1008)
clone08.c:71: INFO: running CLONE_PARENT_SETTID
clone08.c:145: FAIL: ptid != getpid() (0 != 1009)
clone08.c:71: INFO: running CLONE_THREAD
clone08.c:222: PASS: clone has the same thread id
clone08.c:212: PASS: futex exit on ctid change, ctid: 0

clone301:
----------
clone301.c:159: PASS: Parent got correct signal SIGCHLD
clone301.c:159: PASS: Parent got correct signal SIGUSR2
clone301.c:159: PASS: Parent got correct signal SIGCHLD
clone301.c:159: PASS: Parent got correct signal SIGCHLD
clone301.c:138: FAIL: pidfd_send_signal() failed: EBADF (9)
clone301.c:79: FAIL: Child haven't got signal

Reported-by: Naresh Kamboju <naresh.kamboju@xxxxxxxxxx>

full test log link,
https://lkft.validation.linaro.org/scheduler/job/1844087

strace output:
+ strace -f ./clone08
execve(\"./clone08\", [\"./clone08\"], 0x7ffe70dccb78 /* 22 vars */) = 0
brk(NULL) = 0x2531000
access(\"/etc/ld.so.preload\", R_OK) = -1 ENOENT (No such file or
directory)
openat(AT_FDCWD, \"/etc/ld.so.cache\", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=19408, ...}) = 0
mmap(NULL, 19408, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f7e61446000
close(3) = 0
openat(AT_FDCWD, \"/lib/libc.so.6\", O_RDONLY|O_CLOEXEC) = 3
read(3, \"\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\2\0\0\0\0\0\"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1771456, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x7f7e61444000
mmap(NULL, 3877600, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3,
0) = 0x7f7e60e74000
mprotect(0x7f7e6101e000, 2093056, PROT_NONE) = 0
mmap(0x7f7e6121d000, 24576, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a9000) = 0x7f7e6121d000
mmap(0x7f7e61223000, 15072, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f7e61223000
close(3) = 0
arch_prctl(ARCH_SET_FS, 0x7f7e61445580) = 0
mprotect(0x7f7e6121d000, 16384, PROT_READ) = 0
mprotect(0x61c000, 4096, PROT_READ) = 0
mprotect(0x7f7e6144b000, 4096, PROT_READ) = 0
munmap(0x7f7e61446000, 19408) = 0
getpid() = 525
access(\"/dev/shm\", F_OK) = 0
getpid() = 525
openat(AT_FDCWD, \"/dev/shm/ltp_clone08_525\", O_RDWR|O_CREAT|O_EXCL, 0600) = 3
chmod(\"/dev/shm/ltp_clone08_525\", 0666) = 0
ftruncate(3, 4096) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0) = 0x7f7e6144a000
unlink(\"/dev/shm/ltp_clone08_525\") = 0
close(3) = 0
rt_sigaction(SIGALRM, {sa_handler=0x403e40, sa_mask=[ALRM],
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f7e60ea85b0},
{sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=0x403ce0, sa_mask=[USR1],
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f7e60ea85b0},
{sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
ioctl(2, TCGETS, {B115200 opost isig icanon echo ...}) = 0
write(2, \"tst_test.c:1246: INFO: [\"..., 64tst_test.c:1246: INFO:
Timeout per run is 0h 05m 00s
) = 64
getpid() = 525
alarm(300) = 0
rt_sigaction(SIGINT, {sa_handler=0x403df0, sa_mask=[INT],
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f7e60ea85b0},
{sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
clone(strace: Process 526 attached
child_stack=NULL,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7f7e61445850) = 526
[pid 525] wait4(526, <unfinished ...>
[pid 526] rt_sigaction(SIGALRM, {sa_handler=SIG_DFL, sa_mask=[ALRM],
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f7e60ea85b0},
{sa_handler=0x403e40, sa_mask=[ALRM], sa_flags=SA_RESTORER|SA_RESTART,
sa_restorer=0x7f7e60ea85b0}, 8) = 0
[pid 526] rt_sigaction(SIGUSR1, {sa_handler=SIG_DFL, sa_mask=[USR1],
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f7e60ea85b0},
{sa_handler=0x403ce0, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART,
sa_restorer=0x7f7e60ea85b0}, 8) = 0
[pid 526] rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[INT],
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f7e60ea85b0},
{sa_handler=0x403df0, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART,
sa_restorer=0x7f7e60ea85b0}, 8) = 0
[pid 526] setpgid(0, 0) = 0
[pid 526] clock_gettime(CLOCK_MONOTONIC, {tv_sec=248, tv_nsec=252551861}) = 0
[pid 526] getppid() = 525
[pid 526] kill(525, SIGUSR1) = 0
[pid 525] <... wait4 resumed> 0x7ffc8bca80d8, 0, NULL) = ?
ERESTARTSYS (To be restarted if SA_RESTART is set)
[pid 525] --- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_USER,
si_pid=526, si_uid=0} ---
[pid 525] alarm(300 <unfinished ...>
[pid 526] brk(NULL <unfinished ...>
[pid 525] <... alarm resumed> ) = 300
[pid 526] <... brk resumed> ) = 0x2531000
[pid 525] rt_sigreturn({mask=[]} <unfinished ...>
[pid 526] brk(0x2552000 <unfinished ...>
[pid 525] <... rt_sigreturn resumed> ) = 61
[pid 526] <... brk resumed> ) = 0x2552000
[pid 525] wait4(526, <unfinished ...>
[pid 526] getpid() = 526
[pid 526] mmap(NULL, 1052672, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7e61343000
[pid 526] getpid() = 526
[pid 526] write(2, \"clone08.c:71: INFO: r\"..., 52clone08.c:71:
INFO: running CLONE_PARENT
) = 52
[pid 526] clone(child_stack=NULL,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7f7e61445850) = 527
strace: Process 527 attached
[pid 526] wait4(-1, <unfinished ...>
[pid 527] getppid() = 526
[pid 527] clone(strace: Process 528 attached
<unfinished ...>
[pid 528] getppid( <unfinished ...>
[pid 527] <... clone resumed> child_stack=0x7f7e61443000,
flags=CLONE_PARENT|SIGCHLD) = 528
[pid 528] <... getppid resumed> ) = 526
[pid 527] exit_group(0) = ?
[pid 528] write(2, \"clone08.c:115: PASS: "..., 75clone08.c:115:
PASS: clone and forked child has the same parent
) = 75
[pid 528] exit(0) = ?
[pid 527] +++ exited with 0 +++
[pid 526] <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) ==
0}], 0, NULL) = 527
[pid 526] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED,
si_pid=527, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
[pid 526] wait4(-1, <unfinished ...>
[pid 528] +++ exited with 0 +++
[pid 526] <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) ==
0}], 0, NULL) = 528
[pid 526] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED,
si_pid=528, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
[pid 526] wait4(-1, 0x7ffc8bca809c, 0, NULL) = -1 ECHILD (No child processes)
[pid 526] getpid() = 526
[pid 526] wait4(-1, 0x7ffc8bca809c, 0, NULL) = -1 ECHILD (No child processes)
[pid 526] write(2, \"clone08.c:71: INFO: r\"..., 58clone08.c:71:
INFO: running CLONE_CHILD_SETTID
) = 58
[pid 526] clone(strace: Process 529 attached
child_stack=0x7f7e61443000, flags=CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x61d2e4) = 529
[pid 529] getpid( <unfinished ...>
[pid 526] wait4(-1, <unfinished ...>
[pid 529] <... getpid resumed> ) = 529
[pid 529] getpid() = 529
[pid 529] write(2, \"clone08.c:135: FAIL: "..., 60clone08.c:135:
FAIL: ctid != getpid() (0 != 529)
) = 60
[pid 529] exit(0) = ?
[pid 529] +++ exited with 0 +++
[pid 526] <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) ==
0}], 0, NULL) = 529
[pid 526] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED,
si_pid=529, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
[pid 526] wait4(-1, 0x7ffc8bca809c, 0, NULL) = -1 ECHILD (No child processes)
[pid 526] getpid() = 526
[pid 526] wait4(-1, 0x7ffc8bca809c, 0, NULL) = -1 ECHILD (No child processes)
[pid 526] write(2, \"clone08.c:71: INFO: r\"..., 59clone08.c:71:
INFO: running CLONE_PARENT_SETTID
) = 59
[pid 526] clone(strace: Process 530 attached
child_stack=0x7f7e61443000,
flags=CLONE_VM|CLONE_PARENT_SETTID|SIGCHLD, parent_tidptr=0x61d2e8) =
530
[pid 530] getpid( <unfinished ...>
[pid 526] wait4(-1, <unfinished ...>
[pid 530] <... getpid resumed> ) = 530
[pid 530] getpid() = 530
[pid 530] write(2, \"clone08.c:145: FAIL: "..., 60clone08.c:145:
FAIL: ptid != getpid() (0 != 530)
) = 60
[pid 530] exit(0) = ?
[pid 530] +++ exited with 0 +++
[pid 526] <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) ==
0}], 0, NULL) = 530
[pid 526] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED,
si_pid=530, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
[pid 526] wait4(-1, 0x7ffc8bca809c, 0, NULL) = -1 ECHILD (No child processes)
[pid 526] getpid() = 526

strace output log link,
https://lkft.validation.linaro.org/scheduler/job/1865313#L2121

Test case links:
https://github.com/linux-test-project/ltp/blob/master/testcases/kernel/syscalls/clone/clone08.c
https://github.com/linux-test-project/ltp/blob/master/testcases/kernel/syscalls/clone3/clone301.c

--
Linaro LKFT
https://lkft.linaro.org

Next message: Greg Kroah-Hartman: "Re: [PATCH 1/1] usb: serial: option: add Quectel EC200T module support"
Previous message: Greg KH: "Buggy commit tracked to: "Re: [PATCH 2/9] iov_iter: move rw_copy_check_uvector() into lib/iov_iter.c""
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]