LTP: madvise08.c:203: TFAIL: No sequence in dump after MADV_DODUMP.

[Naresh Kamboju <naresh.kamboju@linaro.org>]

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

LTP syscalls madvise08 test case failed on all devices from
Linux next 20210118 to till day.
strace log attached to this email and link provided below.

BAD: next-20210118
GOOD: next-20210115

This failure is easily reproducible on Linux next tag 20210118 above.

tst_test.c:1250: TINFO: Timeout per run is 0h 15m 00s
madvise08.c:73: TINFO: Temporary core pattern is
'/scratch/ltp-2nftQzNI1K/HclFMH/dump-%p'
madvise08.c:112: TINFO: Dump file should be dump-10109
madvise08.c:196: TPASS: madvise(..., MADV_DONTDUMP)
madvise08.c:112: TINFO: Dump file should be dump-10110
madvise08.c:203: TFAIL: No sequence in dump after MADV_DODUMP.

strace log,
https://lkft.validation.linaro.org/scheduler/job/2184866#L1257

Full test log link,
https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20210118/testrun/3771572/suite/ltp-syscalls-tests/test/madvise08/log

Test case link,
https://github.com/linux-test-project/ltp/blob/master/testcases/kernel/syscalls/madvise/madvise08.c#L203

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

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

[-- Attachment #2: madvise08-strace.log --]
[-- Type: text/x-log, Size: 13165 bytes --]

+ cd /opt/ltp/testcases/bin/
+ strace -f ./madvise08
execve(\"./madvise08\", [\"./madvise08\"], 0x7ffd189342b8 /* 22 vars */) = 0
brk(NULL)                               = 0x2542000
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=20188, ...}) = 0
mmap(NULL, 20188, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fc414fd7000
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\33\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) = 0x7fc414fd5000
mmap(NULL, 3877600, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc414a05000
mprotect(0x7fc414baf000, 2093056, PROT_NONE) = 0
mmap(0x7fc414dae000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a9000) = 0x7fc414dae000
mmap(0x7fc414db4000, 15072, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fc414db4000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7fc414fd65c0) = 0
mprotect(0x7fc414dae000, 16384, PROT_READ) = 0
mprotect(0x61e000, 4096, PROT_READ)     = 0
mprotect(0x7fc414fdc000, 4096, PROT_READ) = 0
munmap(0x7fc414fd7000, 20188)           = 0
getpid()                                = 484
geteuid()                               = 0
uname({sysname=\"Linux\", nodename=\"intel-corei7-64\", ...}) = 0
access(\"/dev/shm\", F_OK)                = 0
getpid()                                = 484
openat(AT_FDCWD, \"/dev/shm/ltp_madvise08_484\", O_RDWR|O_CREAT|O_EXCL, 0600) = 3
chmod(\"/dev/shm/ltp_madvise08_484\", 0666) = 0
ftruncate(3, 4096)                      = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0) = 0x7fc414fdb000
unlink(\"/dev/shm/ltp_madvise08_484\")    = 0
close(3)                                = 0
getpid()                                = 484
mkdir(\"/tmp/YtwWXr\", 0700)              = 0
brk(NULL)                               = 0x2542000
brk(0x2563000)                          = 0x2563000
getgid()                                = 0
chown(\"/tmp/YtwWXr\", -1, 0)             = 0
chmod(\"/tmp/YtwWXr\", 0777)              = 0
getcwd(\"/opt/ltp/testcases/bin\", 4096)  = 23
chdir(\"/tmp/YtwWXr\")                    = 0
access(\"/proc/sys/kernel/core_pattern\", F_OK) = 0
openat(AT_FDCWD, \"/proc/sys/kernel/core_pattern\", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
read(3, \"|/bin/false\n\", 1024)          = 12
close(3)                                = 0
rt_sigaction(SIGALRM, {sa_handler=0x406360, sa_mask=[ALRM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=0x406200, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, {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:1250: \33[1;34mTINFO: \33\"..., 65tst_test.c:1250: [1;34mTINFO: [0mTimeout per run is 0h 05m 00s
) = 65
getpid()                                = 484
alarm(300)                              = 0
rt_sigaction(SIGINT, {sa_handler=0x406310, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fc414fd6890) = 485
strace: Process 485 attached
[pid   484] wait4(485,  <unfinished ...>
[pid   485] rt_sigaction(SIGALRM, {sa_handler=SIG_DFL, sa_mask=[ALRM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, {sa_handler=0x406360, sa_mask=[ALRM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, 8) = 0
[pid   485] rt_sigaction(SIGUSR1, {sa_handler=SIG_DFL, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, {sa_handler=0x406200, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, 8) = 0
[pid   485] rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, {sa_handler=0x406310, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, 8) = 0
[pid   485] setpgid(0, 0)               = 0
[pid   485] clock_gettime(CLOCK_REALTIME, NULL) = -1 EFAULT (Bad address)
[pid   485] clock_gettime(CLOCK_MONOTONIC, {tv_sec=43, tv_nsec=350935439}) = 0
[pid   485] getppid()                   = 484
[pid   485] kill(484, SIGUSR1 <unfinished ...>
[pid   484] <... wait4 resumed> 0x7ffe616cc818, 0, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
[pid   485] <... kill resumed> )        = 0
[pid   484] --- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_USER, si_pid=485, si_uid=0} ---
[pid   484] alarm(300)                  = 300
[pid   484] rt_sigreturn({mask=[]} <unfinished ...>
[pid   485] getpid( <unfinished ...>
[pid   484] <[   44.736394] audit: type=1701 audit(1611570186.639:3): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=486 comm=\"madvise08\" exe=\"/opt/ltp/testcases/bin/madvise08\" sig=6 res=1
... rt_sigreturn[   44.754167] audit: type=1701 audit(1611570186.657:4): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=487 comm=\"madvise08\" exe=\"/opt/ltp/testcases/bin/madvise08\" sig=6 res=1
 resumed> ) = 61
[pid   485] <... getpid resumed> )      = 485
[pid   484] wait4(485,  <unfinished ...>
[pid   485] prlimit64(0, RLIMIT_CORE, {rlim_cur=RLIM64_INFINITY, rlim_max=RLIM64_INFINITY}, NULL) = 0
[pid   485] prctl(PR_GET_DUMPABLE)      = 1 (SUID_DUMP_USER)
[pid   485] openat(AT_FDCWD, \"/proc/self/coredump_filter\", O_RDONLY) = 3
[pid   485] fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
[pid   485] read(3, \"00000033\n\", 1024) = 9
[pid   485] close(3)                    = 0
[pid   485] getcwd(\"/tmp/YtwWXr\", 1024) = 12
[pid   485] write(2, \"madvise08.c:78: \33[1;34mTINFO: \33[\"..., 82madvise08.c:78: [1;34mTINFO: [0mTemporary core pattern is '/tmp/YtwWXr/dump-%p'
) = 82
[pid   485] openat(AT_FDCWD, \"/proc/sys/kernel/core_pattern\", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
[pid   485] fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
[pid   485] write(3, \"/tmp/YtwWXr/dump-%p\", 19) = 19
[pid   485] close(3)                    = 0
[pid   485] mmap(NULL, 1282, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc414fda000
[pid   485] getpid()                    = 485
[pid   485] clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fc414fd6890) = 486
strace: Process 486 attached
[pid   485] wait4(486,  <unfinished ...>
[pid   486] madvise(0x7fc414fda000, 1282, MADV_DONTDUMP) = 0
[pid   486] rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0
[pid   486] rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
[pid   486] getpid()                    = 486
[pid   486] gettid()                    = 486
[pid   486] tgkill(486, 486, SIGABRT)   = 0
[pid   486] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid   486] --- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=486, si_uid=0} ---
[pid   486] +++ killed by SIGABRT (core dumped) +++
[pid   485] <... wait4 resumed> [{WIFSIGNALED(s) && WTERMSIG(s) == SIGABRT && WCOREDUMP(s)}], 0, NULL) = 486
[pid   485] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_DUMPED, si_pid=486, si_uid=0, si_status=SIGABRT, si_utime=0, si_stime=0} ---
[pid   485] write(2, \"madvise08.c:117: \33[1;34mTINFO: \33\"..., 64madvise08.c:117: [1;34mTINFO: [0mDump file should be dump-486
) = 64
[pid   485] access(\"dump-486\", F_OK)    = 0
[pid   485] openat(AT_FDCWD, \"dump-486\", O_RDONLY) = 3
[pid   485] read(3, \"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\4\0>\0\1\0\0\0\0\0\0\0\0\0\0\0\"..., 1024) = 1024
[pid   485] read(3, \"\0\300\3\0\0\0\0\0\0\340\375\24\304\177\0\0\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\"..., 1024) = 292
[pid   485] read(3, \"\", 1024)           = 0
[pid   485] close(3)                    = 0
[pid   485] write(2, \"madvise08.c:201: \33[1;32mTPASS: \33\"..., 63madvise08.c:201: [1;32mTPASS: [0mmadvise(..., MADV_DONTDUMP)
) = 63
[pid   485] getpid()                    = 485
[pid   485] wait4(-1, 0x7ffe616cc7dc, 0, NULL) = -1 ECHILD (No child processes)
[pid   485] clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fc414fd6890) = 487
strace: Process 487 attached
[pid   485] wait4(487,  <unfinished ...>
[pid   487] madvise(0x7fc414fda000, 1282, MADV_DODUMP) = 0
[pid   487] rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0
[pid   487] rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
[pid   487] getpid()                    = 487
[pid   487] gettid()                    = 487
[pid   487] tgkill(487, 487, SIGABRT)   = 0
[pid   487] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid   487] --- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=487, si_uid=0} ---
[pid   487] +++ killed by SIGABRT (core dumped) +++
[pid   485] <... wait4 resumed> [{WIFSIGNALED(s) && WTERMSIG(s) == SIGABRT && WCOREDUMP(s)}], 0, NULL) = 487
[pid   485] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_DUMPED, si_pid=487, si_uid=0, si_status=SIGABRT, si_utime=0, si_stime=0} ---
[pid   485] write(2, \"madvise08.c:117: \33[1;34mTINFO: \33\"..., 64madvise08.c:117: [1;34mTINFO: [0mDump file should be dump-487
) = 64
[pid   485] access(\"dump-487\", F_OK)    = 0
[pid   485] openat(AT_FDCWD, \"dump-487\", O_RDONLY) = 3
[pid   485] read(3, \"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\4\0>\0\1\0\0\0\0\0\0\0\0\0\0\0\"..., 1024) = 1024
[pid   485] read(3, \"\0\320\3\0\0\0\0\0\0\340\375\24\304\177\0\0\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\"..., 1024) = 292
[pid   485] read(3, \"\", 1024)           = 0
[pid   485] close(3)                    = 0
[pid   485] write(2, \"madvise08.c:208: \33[1;31mTFAIL: \33\"..., 74madvise08.c:208: [1;31mTFAIL: [0mNo sequence in dump after MADV_DODUMP.
) = 74
[pid   485] getpid()                    = 485
[pid   485] wait4(-1, 0x7ffe616cc7dc, 0, NULL) = -1 ECHILD (No child processes)
[pid   485] clock_gettime(CLOCK_MONOTONIC, {tv_sec=44, tv_nsec=100424064}) = 0
[pid   485] getppid()                   = 484
[pid   485] kill(484, SIGUSR1)          = 0
[pid   485] munmap(0x7fc414fda000, 1282 <unfinished ...>
[pid   484] <... wait4 resumed> 0x7ffe616cc818, 0, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
[pid   485] <... munmap resumed> )      = 0
[pid   484] --- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_USER, si_pid=485, si_uid=0} ---
[pid   485] exit_group(0 <unfinished ...>
[pid   484] alarm(300 <unfinished ...>
[pid   485] <... exit_group resumed>)   = ?
[pid   484] <... alarm resumed> )       = 299
[pid   484] rt_sigreturn({mask=[]} <unfinished ...>
[pid   485] +++ exited with 0 +++
<... rt_sigreturn resumed> )            = 61
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=485, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(485, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 485
alarm(0)                                = 300
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, {sa_handler=0x406310, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fc414a395b0}, 8) = 0
fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(4, 64), ...}) = 0
ioctl(1, TCGETS, {B115200 opost isig icanon echo ...}) = 0
write(1, \"\n\", 1
)                       = 1
write(1, \"Summary:\n\", 9Summary:
)               = 9
write(1, \"passed   1\n\", 11passed   1
)            = 11
write(1, \"failed   1\n\", 11failed   1
)            = 11
write(1, \"skipped  0\n\", 11skipped  0
)            = 11
write(1, \"warnings 0\n\", 11warnings 0
)            = 11
openat(AT_FDCWD, \"/tmp/YtwWXr\", O_RDONLY|O_DIRECTORY|O_NOFOLLOW) = 3
close(3)                                = 0
openat(AT_FDCWD, \"/tmp/YtwWXr\", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFDIR|0777, st_size=80, ...}) = 0
getdents(3, /* 4 entries */, 32768)     = 112
openat(AT_FDCWD, \"/tmp/YtwWXr/dump-487\", O_RDONLY|O_DIRECTORY|O_NOFOLLOW) = -1 ENOTDIR (Not a directory)
unlink(\"/tmp/YtwWXr/dump-487\")          = 0
openat(AT_FDCWD, \"/tmp/YtwWXr/dump-486\", O_RDONLY|O_DIRECTORY|O_NOFOLLOW) = -1 ENOTDIR (Not a directory)
unlink(\"/tmp/YtwWXr/dump-486\")          = 0
getdents(3, /* 0 entries */, 32768)     = 0
close(3)                                = 0
lstat(\"/tmp/YtwWXr\", {st_mode=S_IFDIR|0777, st_size=40, ...}) = 0
unlink(\"/tmp/YtwWXr\")                   = -1 EISDIR (Is a directory)
rmdir(\"/tmp/YtwWXr\")                    = 0
openat(AT_FDCWD, \"/proc/sys/kernel/core_pattern\", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
write(3, \"|/bin/false\n\", 12)           = 12
close(3)                                = 0
access(\"/dev/shm/ltp_madvise08_484\", F_OK) = -1 ENOENT (No such file or directory)
msync(0x7fc414fdb000, 4096, MS_SYNC)    = 0
munmap(0x7fc414fdb000, 4096)            = 0
exit_group(1)                           = ?
+++ exited with 1 +++