stable-rc 4.14.60-rc1/654fc6e3ea92: regressions detected in project stable v.4.14.y on OE
Summary ------------------------------------------------------------------------
kernel: 4.14.60-rc1 git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git git branch: linux-4.14.y git commit: 654fc6e3ea92407f572a7c25ec24cf5cdffc3012 git describe: v4.14.59-247-g654fc6e3ea92 Test details: https://qa-reports.linaro.org/lkft/linux-stable-rc-4.14-oe/build/v4.14.59-24...
Regressions (compared to build v4.14.59-217-g15764ef1e5ef) ------------------------------------------------------------------------
qemu_arm: ltp-fs-tests: * runltp_fs * rwtest02
* test src: git://github.com/linux-test-project/ltp.git
Boards, architectures and test suites: -------------------------------------
dragonboard-410c - arm64 * boot - pass: 21 * kselftest - skip: 38, pass: 42 * libhugetlbfs - fail: 2, skip: 1, pass: 88 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 17, pass: 64 * ltp-cve-tests - skip: 8, pass: 27 * ltp-fcntl-locktests-tests - pass: 2 * ltp-filecaps-tests - pass: 2 * ltp-fs-tests - skip: 6, pass: 60 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - skip: 1, pass: 21 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-pty-tests - pass: 4 * ltp-sched-tests - pass: 14 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 135, pass: 1014 * ltp-timers-tests - pass: 13
hi6220-hikey - arm64 * boot - pass: 21 * kselftest - skip: 30, pass: 41 * libhugetlbfs - fail: 1, skip: 1, pass: 89 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 17, pass: 64 * ltp-cve-tests - skip: 8, pass: 27 * ltp-fcntl-locktests-tests - pass: 2 * ltp-filecaps-tests - pass: 2 * ltp-fs-tests - skip: 6, pass: 60 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - skip: 1, pass: 21 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-pty-tests - pass: 4 * ltp-sched-tests - skip: 4, pass: 10 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 136, pass: 1013 * ltp-timers-tests - pass: 13
juno-r2 - arm64 * boot - pass: 21 * kselftest - fail: 1, skip: 28, pass: 44 * libhugetlbfs - fail: 1, skip: 1, pass: 89 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 17, pass: 64 * ltp-cve-tests - skip: 9, pass: 26 * ltp-fcntl-locktests-tests - pass: 2 * ltp-fs-tests - skip: 6, pass: 60 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - pass: 22 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-open-posix-tests - fail: 5, skip: 41, pass: 1689 * ltp-pty-tests - pass: 4 * ltp-sched-tests - skip: 4, pass: 10 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 135, pass: 1014 * ltp-timers-tests - pass: 13
qemu_arm * boot - pass: 21 * kselftest - skip: 40, pass: 43 * libhugetlbfs - fail: 1, skip: 1, pass: 86 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 18, pass: 63 * ltp-cve-tests - skip: 12, pass: 23 * ltp-fcntl-locktests-tests - pass: 2 * ltp-filecaps-tests - pass: 2 * ltp-fs-tests - fail: 2, skip: 5, pass: 59 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - skip: 1, pass: 21 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-pty-tests - pass: 4 * ltp-sched-tests - skip: 6, pass: 8 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 99, pass: 1050 * ltp-timers-tests - pass: 13
qemu_arm64 * boot - pass: 21 * kselftest - skip: 38, pass: 47 * libhugetlbfs - fail: 1, skip: 1, pass: 89 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 17, pass: 64 * ltp-cve-tests - skip: 10, pass: 25 * ltp-fcntl-locktests-tests - pass: 2 * ltp-filecaps-tests - pass: 2 * ltp-fs-tests - skip: 6, pass: 60 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - pass: 22 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-pty-tests - pass: 4 * ltp-sched-tests - skip: 6, pass: 8 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 159, pass: 990 * ltp-timers-tests - pass: 13
qemu_x86_64 * boot - pass: 21 * kselftest - skip: 34, pass: 62 * libhugetlbfs - fail: 1, skip: 1, pass: 89 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 17, pass: 64 * ltp-cve-tests - skip: 5, pass: 30 * ltp-fcntl-locktests-tests - pass: 2 * ltp-filecaps-tests - pass: 2 * ltp-fs-tests - skip: 6, pass: 60 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - pass: 22 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-pty-tests - pass: 4 * ltp-sched-tests - pass: 14 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 155, pass: 994 * ltp-timers-tests - pass: 13
x15 - arm * boot - pass: 22 * kselftest - skip: 35, pass: 45 * libhugetlbfs - fail: 1, skip: 1, pass: 86 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 18, pass: 63 * ltp-cve-tests - skip: 10, pass: 25 * ltp-fcntl-locktests-tests - pass: 2 * ltp-filecaps-tests - pass: 2 * ltp-fs-tests - skip: 5, pass: 61 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - skip: 2, pass: 20 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-open-posix-tests - fail: 5, skip: 40, pass: 1690 * ltp-pty-tests - pass: 4 * ltp-sched-tests - pass: 14 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 78, pass: 1071 * ltp-timers-tests - pass: 13
x86_64 * boot - pass: 24 * kselftest - skip: 28, pass: 59 * kselftest-vsyscall-mode-native - fail: 1, skip: 29, pass: 56 * kselftest-vsyscall-mode-none - skip: 29, pass: 59 * libhugetlbfs - fail: 1, skip: 1, pass: 89 * ltp-cap_bounds-tests - pass: 2 * ltp-containers-tests - skip: 17, pass: 64 * ltp-cve-tests - skip: 5, pass: 30 * ltp-fcntl-locktests-tests - pass: 2 * ltp-filecaps-tests - pass: 2 * ltp-fs-tests - skip: 5, pass: 61 * ltp-fs_bind-tests - pass: 2 * ltp-fs_perms_simple-tests - pass: 19 * ltp-fsx-tests - pass: 2 * ltp-hugetlb-tests - pass: 22 * ltp-io-tests - pass: 3 * ltp-ipc-tests - pass: 9 * ltp-math-tests - pass: 11 * ltp-nptl-tests - pass: 2 * ltp-open-posix-tests - fail: 5, skip: 44, pass: 1686 * ltp-pty-tests - pass: 4 * ltp-sched-tests - skip: 4, pass: 10 * ltp-securebits-tests - pass: 4 * ltp-syscalls-tests - skip: 118, pass: 1031 * ltp-timers-tests - pass: 13
Comments on regressions:
On Wed, Aug 01, 2018 at 12:08:10PM +0000, Linaro QA wrote:
Summary
kernel: 4.14.60-rc1 git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git git branch: linux-4.14.y git commit: 654fc6e3ea92407f572a7c25ec24cf5cdffc3012 git describe: v4.14.59-247-g654fc6e3ea92 Test details: https://qa-reports.linaro.org/lkft/linux-stable-rc-4.14-oe/build/v4.14.59-24...
Regressions (compared to build v4.14.59-217-g15764ef1e5ef)
qemu_arm: ltp-fs-tests: * runltp_fs * rwtest02
It is failing on arm32 bits only as it looks like.
[ 945.979675] ------------[ cut here ]------------ [ 945.984994] WARNING: CPU: 1 PID: 572 at /srv/oe/build/tmp-rpb-glibc/work-shared/am57xx-evm/kernel-source/lib/iov_iter.c:695 copy_page_to_iter+0x308/0x4e8 [ 946.002849] Modules linked in: fuse [ 946.003665] CPU: 1 PID: 572 Comm: doio Not tainted 4.14.60-rc1 #1 [ 946.003894] Hardware name: Generic DT based system [ 946.005949] [<c0413e20>] (unwind_backtrace) from [<c040dc04>] (show_stack+0x20/0x24) [ 946.006729] [<c040dc04>] (show_stack) from [<c10842c4>] (dump_stack+0xb4/0xe0) [ 946.007471] [<c10842c4>] (dump_stack) from [<c044bdd0>] (__warn+0xf8/0x110) [ 946.008233] [<c044bdd0>] (__warn) from [<c044beb8>] (warn_slowpath_null+0x30/0x38) [ 946.008959] [<c044beb8>] (warn_slowpath_null) from [<c083ab6c>] (copy_page_to_iter+0x308/0x4e8) [ 946.010215] [<c083ab6c>] (copy_page_to_iter) from [<c05b0a20>] (shmem_file_read_iter+0x1fc/0x438) [ 946.011334] [<c05b0a20>] (shmem_file_read_iter) from [<c0610704>] (__vfs_read+0xe0/0x12c) [ 946.012402] [<c0610704>] (__vfs_read) from [<c06107e8>] (vfs_read+0x98/0x11c) [ 946.013485] [<c06107e8>] (vfs_read) from [<c0610cc8>] (SyS_read+0x4c/0xa0) [ 946.014261] [<c0610cc8>] (SyS_read) from [<c0408e40>] (ret_fast_syscall+0x0/0x28) [ 946.017109] ---[ end trace 36e04ae918de332f ]---
generated by the rwtest02:
--------------------- read() request returned wrong # of bytes - expected 78251, got 2677 Request number 8143 syscall: read(6, 01540240, 78251) fd 6 is file /tmp/ltp-p7UHOQLpOS/rw-buffered-559 - open flags are 0 read done at file offset 3245451 doio(rwtest02) ( 572) 10:20:42 ---------------------
This is a warning telling us that a shared memory backed file was read and it could not be read entirely. This would be triggered by an attempt of reading a file in /tmp/ for example. shmem_file_operations has a pointer for .read_iter() which points to "shmem_file_read_iter", the base for this stack trace.
There is a warning for slowpath, what usually tells us that kernel had to do a slower path for allocating memory. Since this test is testing async reads, it might be the case that the data wasn't ready after sometime because kernel was slowly trying to claim pages or something similar.
@Naresh,
Would you mind re-running this test ? So we can check if this stack trace happens again ?
Thank you
* test src: git://github.com/linux-test-project/ltp.git
On 1 August 2018 at 19:19, Rafael David Tinoco rafael.tinoco@linaro.org wrote:
Comments on regressions:
On Wed, Aug 01, 2018 at 12:08:10PM +0000, Linaro QA wrote:
Summary
kernel: 4.14.60-rc1 git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git git branch: linux-4.14.y git commit: 654fc6e3ea92407f572a7c25ec24cf5cdffc3012 git describe: v4.14.59-247-g654fc6e3ea92 Test details: https://qa-reports.linaro.org/lkft/linux-stable-rc-4.14-oe/build/v4.14.59-24...
Regressions (compared to build v4.14.59-217-g15764ef1e5ef)
qemu_arm: ltp-fs-tests: * runltp_fs * rwtest02
It is failing on arm32 bits only as it looks like.
[ 945.979675] ------------[ cut here ]------------ [ 945.984994] WARNING: CPU: 1 PID: 572 at /srv/oe/build/tmp-rpb-glibc/work-shared/am57xx-evm/kernel-source/lib/iov_iter.c:695 copy_page_to_iter+0x308/0x4e8 [ 946.002849] Modules linked in: fuse [ 946.003665] CPU: 1 PID: 572 Comm: doio Not tainted 4.14.60-rc1 #1 [ 946.003894] Hardware name: Generic DT based system [ 946.005949] [<c0413e20>] (unwind_backtrace) from [<c040dc04>] (show_stack+0x20/0x24) [ 946.006729] [<c040dc04>] (show_stack) from [<c10842c4>] (dump_stack+0xb4/0xe0) [ 946.007471] [<c10842c4>] (dump_stack) from [<c044bdd0>] (__warn+0xf8/0x110) [ 946.008233] [<c044bdd0>] (__warn) from [<c044beb8>] (warn_slowpath_null+0x30/0x38) [ 946.008959] [<c044beb8>] (warn_slowpath_null) from [<c083ab6c>] (copy_page_to_iter+0x308/0x4e8) [ 946.010215] [<c083ab6c>] (copy_page_to_iter) from [<c05b0a20>] (shmem_file_read_iter+0x1fc/0x438) [ 946.011334] [<c05b0a20>] (shmem_file_read_iter) from [<c0610704>] (__vfs_read+0xe0/0x12c) [ 946.012402] [<c0610704>] (__vfs_read) from [<c06107e8>] (vfs_read+0x98/0x11c) [ 946.013485] [<c06107e8>] (vfs_read) from [<c0610cc8>] (SyS_read+0x4c/0xa0) [ 946.014261] [<c0610cc8>] (SyS_read) from [<c0408e40>] (ret_fast_syscall+0x0/0x28) [ 946.017109] ---[ end trace 36e04ae918de332f ]---
generated by the rwtest02:
read() request returned wrong # of bytes - expected 78251, got 2677 Request number 8143 syscall: read(6, 01540240, 78251) fd 6 is file /tmp/ltp-p7UHOQLpOS/rw-buffered-559 - open flags are 0 read done at file offset 3245451 doio(rwtest02) ( 572) 10:20:42
This is a warning telling us that a shared memory backed file was read and it could not be read entirely. This would be triggered by an attempt of reading a file in /tmp/ for example. shmem_file_operations has a pointer for .read_iter() which points to "shmem_file_read_iter", the base for this stack trace.
There is a warning for slowpath, what usually tells us that kernel had to do a slower path for allocating memory. Since this test is testing async reads, it might be the case that the data wasn't ready after sometime because kernel was slowly trying to claim pages or something similar.
@Naresh,
Would you mind re-running this test ? So we can check if this stack trace happens again ?
I will re-test with 10 iterations and let you know.
- Naresh
Thank you
* test src: git://github.com/linux-test-project/ltp.git
Hi Rafael,
On 1 August 2018 at 19:28, Naresh Kamboju naresh.kamboju@linaro.org wrote:
On 1 August 2018 at 19:19, Rafael David Tinoco rafael.tinoco@linaro.org wrote:
Comments on regressions:
On Wed, Aug 01, 2018 at 12:08:10PM +0000, Linaro QA wrote:
Summary
kernel: 4.14.60-rc1 git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git git branch: linux-4.14.y git commit: 654fc6e3ea92407f572a7c25ec24cf5cdffc3012 git describe: v4.14.59-247-g654fc6e3ea92 Test details: https://qa-reports.linaro.org/lkft/linux-stable-rc-4.14-oe/build/v4.14.59-24...
Regressions (compared to build v4.14.59-217-g15764ef1e5ef)
qemu_arm: ltp-fs-tests: * runltp_fs * rwtest02
It is failing on arm32 bits only as it looks like.
[ 945.979675] ------------[ cut here ]------------ [ 945.984994] WARNING: CPU: 1 PID: 572 at /srv/oe/build/tmp-rpb-glibc/work-shared/am57xx-evm/kernel-source/lib/iov_iter.c:695 copy_page_to_iter+0x308/0x4e8 [ 946.002849] Modules linked in: fuse [ 946.003665] CPU: 1 PID: 572 Comm: doio Not tainted 4.14.60-rc1 #1 [ 946.003894] Hardware name: Generic DT based system [ 946.005949] [<c0413e20>] (unwind_backtrace) from [<c040dc04>] (show_stack+0x20/0x24) [ 946.006729] [<c040dc04>] (show_stack) from [<c10842c4>] (dump_stack+0xb4/0xe0) [ 946.007471] [<c10842c4>] (dump_stack) from [<c044bdd0>] (__warn+0xf8/0x110) [ 946.008233] [<c044bdd0>] (__warn) from [<c044beb8>] (warn_slowpath_null+0x30/0x38) [ 946.008959] [<c044beb8>] (warn_slowpath_null) from [<c083ab6c>] (copy_page_to_iter+0x308/0x4e8) [ 946.010215] [<c083ab6c>] (copy_page_to_iter) from [<c05b0a20>] (shmem_file_read_iter+0x1fc/0x438) [ 946.011334] [<c05b0a20>] (shmem_file_read_iter) from [<c0610704>] (__vfs_read+0xe0/0x12c) [ 946.012402] [<c0610704>] (__vfs_read) from [<c06107e8>] (vfs_read+0x98/0x11c) [ 946.013485] [<c06107e8>] (vfs_read) from [<c0610cc8>] (SyS_read+0x4c/0xa0) [ 946.014261] [<c0610cc8>] (SyS_read) from [<c0408e40>] (ret_fast_syscall+0x0/0x28) [ 946.017109] ---[ end trace 36e04ae918de332f ]---
generated by the rwtest02:
read() request returned wrong # of bytes - expected 78251, got 2677 Request number 8143 syscall: read(6, 01540240, 78251) fd 6 is file /tmp/ltp-p7UHOQLpOS/rw-buffered-559 - open flags are 0 read done at file offset 3245451 doio(rwtest02) ( 572) 10:20:42
This is a warning telling us that a shared memory backed file was read and it could not be read entirely. This would be triggered by an attempt of reading a file in /tmp/ for example. shmem_file_operations has a pointer for .read_iter() which points to "shmem_file_read_iter", the base for this stack trace.
There is a warning for slowpath, what usually tells us that kernel had to do a slower path for allocating memory. Since this test is testing async reads, it might be the case that the data wasn't ready after sometime because kernel was slowly trying to claim pages or something similar.
@Naresh,
Would you mind re-running this test ? So we can check if this stack trace happens again ?
I will re-test with 10 iterations and let you know.
56 times the test run and all times it PASS. no kernel crash or segmentation fault. https://lkft.validation.linaro.org/scheduler/job/349773#L642
- Naresh
This is a warning telling us that a shared memory backed file was read and it could not be read entirely. This would be triggered by an attempt of reading a file in /tmp/ for example. shmem_file_operations has a pointer for .read_iter() which points to "shmem_file_read_iter", the base for this stack trace.
There is a warning for slowpath, what usually tells us that kernel had to do a slower path for allocating memory. Since this test is testing async reads, it might be the case that the data wasn't ready after sometime because kernel was slowly trying to claim pages or something similar.
@Naresh,
Would you mind re-running this test ? So we can check if this stack trace happens again ?
I will re-test with 10 iterations and let you know.
56 times the test run and all times it PASS. no kernel crash or segmentation fault. https://lkft.validation.linaro.org/scheduler/job/349773#L642
Yep, that is why I asked for a re-run. This was a false positive due to high memory pressure, most likely, caused by previous tests in the same run. Best guess is that kernel was trying to acquire mem pages for the buffer copy (userland <-> kernel), for the vfs_read() of a tmpfs filesystem, and it took more time than test was designed to handle.
I expect this type of issues to be reduced when we move away from QEMU arm32/64 guests on x86_64 and run KVM guests on real arm for the tests.
-
Linaro QA -
Naresh Kamboju -
Rafael David Tinoco