On Mon, Oct 16, 2017 at 09:48:30AM +0000, Linaro QA wrote:
Summary
kernel: 4.4.92 git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git git branch: linux-4.4.y git commit: 69f53f5d37d53ba17ca744947226b4cdadb90c13 git describe: v4.4.92 Test details: https://qa-reports.linaro.org/lkft/linux-stable-rc-4.4-oe/build/v4.4.92
Regressions (compared to build v4.4.91-48-gc0489dd5896d)
x15 - arm: ltp-syscalls-tests: * fcntl36
* test src: git://github.com/linux-test-project/ltp.git
Hm, what does this mean? Did this regress due to a breakage of your system, as this link: https://qa-reports.linaro.org/lkft/linux-stable-rc-4.4-oe/build/v4.4.92/test... shows all "No log available for this test" :(
No test logs are expected with current status of qa-reports. We have complete log for ltp syscalls runs in a single file and work in progress for split logs for each test case.
Here is the log for the failure test case.
fcntl36.c:303: INFO: OFD read lock vs OFD write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD write lock vs POSIX write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD read lock vs POSIX write lock fcntl36.c:205: FAIL: Unexpected data offset 12304 value 9 fcntl36.c:205: FAIL: Unexpected data offset 13568 value 47 fcntl36.c:303: INFO: OFD write lock vs POSIX read lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD write lock vs OFD write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD r/w lock vs POSIX write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD r/w lock vs POSIX read lock fcntl36.c:381: PASS: Access between threads synchronized Summary: passed 6 failed 2 skipped 0 warnings 0
Linux version 4.4.92 (buildslave@x86-64-08) (gcc version 6.2.1 20161016 (Linaro GCC 6.2-2016.11) ) #1 SMP Thu Oct 12 10:59:44 UTC 2017
LAVA job id: https://lkft.validation.linaro.org/scheduler/job/46680#L2847
Bug reported for this failure please refer this link. LKFT: 4.4: X15: LTP syscall test case fcntl36.c:205: FAIL: Unexpected data offset 12304 value 9 https://bugs.linaro.org/show_bug.cgi?id=3339
This bug is not consistence, I have re tested fcntl36. 1. test PASS in independent run "./fcntl36" 2. test FAIL with "strace ./fcntl36"
Re-tested log, https://lkft.validation.linaro.org/scheduler/job/47795#L904
Pastebin log for above case if you do not like full boot log. https://pastebin.com/XWuSDaMe
- Naresh
confused.
greg k-h
On Mon, Oct 16, 2017 at 3:04 PM, Naresh Kamboju naresh.kamboju@linaro.org wrote:
On Mon, Oct 16, 2017 at 09:48:30AM +0000, Linaro QA wrote:
Here is the log for the failure test case.
fcntl36.c:303: INFO: OFD read lock vs OFD write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD write lock vs POSIX write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD read lock vs POSIX write lock fcntl36.c:205: FAIL: Unexpected data offset 12304 value 9 fcntl36.c:205: FAIL: Unexpected data offset 13568 value 47 fcntl36.c:303: INFO: OFD write lock vs POSIX read lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD write lock vs OFD write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD r/w lock vs POSIX write lock fcntl36.c:381: PASS: Access between threads synchronized fcntl36.c:303: INFO: OFD r/w lock vs POSIX read lock fcntl36.c:381: PASS: Access between threads synchronized Summary: passed 6 failed 2 skipped 0 warnings 0
Linux version 4.4.92 (buildslave@x86-64-08) (gcc version 6.2.1 20161016 (Linaro GCC 6.2-2016.11) ) #1 SMP Thu Oct 12 10:59:44 UTC 2017
LAVA job id: https://lkft.validation.linaro.org/scheduler/job/46680#L2847
Bug reported for this failure please refer this link. LKFT: 4.4: X15: LTP syscall test case fcntl36.c:205: FAIL: Unexpected data offset 12304 value 9 https://bugs.linaro.org/show_bug.cgi?id=3339
This bug is not consistence, I have re tested fcntl36.
- test PASS in independent run "./fcntl36"
- test FAIL with "strace ./fcntl36"
Ok. I have cross-checked this with the contents of Linux 4.4.92, nothing got merged in *this* release that is likely to be related to the particular problem found here.
The most likely possible causes then are:
1. a bug in LTP, testing something that is not guaranteed to be reliable, or maybe not on all file systems. 2. an old bug in the kernel, possibly fixed in newer versions 3. a regression introduced in an earlier v4.4.y snapshot but not caught by the unreliable test
I see that the test case in question is relatively new, fcntl36.c was only added in LTP on September 1 2017, so this might be a previously unknown problem with the test case, or it might be known bug that the test case was added to find. I've added Xiong Zhou and Cyril Hrubis to Cc, they were both involved in adding the test case to LTP and may have more information.
Arnd
Hi!
Linux version 4.4.92 (buildslave@x86-64-08) (gcc version 6.2.1 20161016 (Linaro GCC 6.2-2016.11) ) #1 SMP Thu Oct 12 10:59:44 UTC 2017
LAVA job id: https://lkft.validation.linaro.org/scheduler/job/46680#L2847
Bug reported for this failure please refer this link. LKFT: 4.4: X15: LTP syscall test case fcntl36.c:205: FAIL: Unexpected data offset 12304 value 9 https://bugs.linaro.org/show_bug.cgi?id=3339
This bug is not consistence, I have re tested fcntl36.
- test PASS in independent run "./fcntl36"
- test FAIL with "strace ./fcntl36"
Ok. I have cross-checked this with the contents of Linux 4.4.92, nothing got merged in *this* release that is likely to be related to the particular problem found here.
The most likely possible causes then are:
- a bug in LTP, testing something that is not guaranteed to be reliable, or maybe not on all file systems.
- an old bug in the kernel, possibly fixed in newer versions
- a regression introduced in an earlier v4.4.y snapshot but not caught by the unreliable test
I see that the test case in question is relatively new, fcntl36.c was only added in LTP on September 1 2017, so this might be a previously unknown problem with the test case, or it might be known bug that the test case was added to find. I've added Xiong Zhou and Cyril Hrubis to Cc, they were both involved in adding the test case to LTP and may have more information.
The assertion that fail runs several threads where:
First half of them are writers where each of these loops:
* lock region in a file with posix write lock * write to the region * unlock it
While the second half loops concurently (time and file offset vise):
* lock region with read ofd lock * read the region, expects it to be consistent block vise * unlock it
As far as I can tell this is supposed to be supported combination
Also I'm not aware of any kernel bugs in this area either, when we add a bug reproducer to LTP we include kernel commit hash in the top level comment in the testcase, which isn't the case here. Maybe Xiong Zhou can elaborate.
What filesystem is this testcase running against, i.e. what is in TMPDIR (defaults to /tmp) and what is mounted under that directory? We are running this test in SUSE against several kernel versions since it was introduced in the git repository and we never seen a failure, we are running it mostly against Btrfs though.
On Mon, Oct 16, 2017 at 4:37 PM, Cyril Hrubis chrubis@suse.cz wrote:
First half of them are writers where each of these loops:
- lock region in a file with posix write lock
- write to the region
- unlock it
While the second half loops concurently (time and file offset vise):
- lock region with read ofd lock
- read the region, expects it to be consistent block vise
- unlock it
As far as I can tell this is supposed to be supported combination
I've read the fs/locks.c implementation now and agree this should be supported: posix locks and ofd locks are in the same namespace but considered having different owners by definition, so they will conflict and the reader/writer should block on each other.
I don't see any interesting patches in that area between linux-4.4 and current mainline, or anything relevant that went into stable/linux-4.4.y
What filesystem is this testcase running against, i.e. what is in TMPDIR (defaults to /tmp) and what is mounted under that directory? We are running this test in SUSE against several kernel versions since it was introduced in the git repository and we never seen a failure, we are running it mostly against Btrfs though.
I hope Naresh can clarify but I suspect it might be NFS, which is a bit of a special case here. When checking whether two locks have the same owner, we call this function in the kernel:
static int posix_same_owner(struct file_lock *fl1, struct file_lock *fl2) { if (fl1->fl_lmops && fl1->fl_lmops->lm_compare_owner) return fl2->fl_lmops == fl1->fl_lmops && fl1->fl_lmops->lm_compare_owner(fl1, fl2); return fl1->fl_owner == fl2->fl_owner; }
The last line is used on all file systems, except on NFS, which uses
static int nlmsvc_same_owner(struct file_lock *fl1, struct file_lock *fl2) { return fl1->fl_owner == fl2->fl_owner && fl1->fl_pid == fl2->fl_pid; }
so it only applies if both the owner and pid fields match. Not sure how that could cause problems though. Possibly if the fl1->fl_lmops pointer is different here?
Arnd
On 16 October 2017 at 21:25, Arnd Bergmann arnd@arndb.de wrote:
On Mon, Oct 16, 2017 at 4:37 PM, Cyril Hrubis chrubis@suse.cz wrote:
First half of them are writers where each of these loops:
- lock region in a file with posix write lock
- write to the region
- unlock it
While the second half loops concurently (time and file offset vise):
- lock region with read ofd lock
- read the region, expects it to be consistent block vise
- unlock it
As far as I can tell this is supposed to be supported combination
I've read the fs/locks.c implementation now and agree this should be supported: posix locks and ofd locks are in the same namespace but considered having different owners by definition, so they will conflict and the reader/writer should block on each other.
I don't see any interesting patches in that area between linux-4.4 and current mainline, or anything relevant that went into stable/linux-4.4.y
What filesystem is this testcase running against, i.e. what is in TMPDIR (defaults to /tmp) and what is mounted under that directory? We are running this test in SUSE against several kernel versions since it was introduced in the git repository and we never seen a failure, we are running it mostly against Btrfs though.
I have tested with TMPDIR=/ltp-tmp (ext4) and TMPDIR=/tmp (tmpfs) no different. fcntl36 failed intermittently - failed 9 times out of 10 times in different instance. Please find the paste bin log. https://pastebin.com/rJNv3P3w
I hope Naresh can clarify but I suspect it might be NFS, which is a bit of a special case here. When checking whether two locks have the same owner, we call this function in the kernel:
X15 does not use NFS.
static int posix_same_owner(struct file_lock *fl1, struct file_lock *fl2) { if (fl1->fl_lmops && fl1->fl_lmops->lm_compare_owner) return fl2->fl_lmops == fl1->fl_lmops && fl1->fl_lmops->lm_compare_owner(fl1, fl2); return fl1->fl_owner == fl2->fl_owner; }
The last line is used on all file systems, except on NFS, which uses
static int nlmsvc_same_owner(struct file_lock *fl1, struct file_lock *fl2) { return fl1->fl_owner == fl2->fl_owner && fl1->fl_pid == fl2->fl_pid; }
so it only applies if both the owner and pid fields match. Not sure how that could cause problems though. Possibly if the fl1->fl_lmops pointer is different here?
Arnd
On Mon, Oct 16, 2017 at 4:37 PM, Cyril Hrubis chrubis@suse.cz wrote:
The assertion that fail runs several threads where:
First half of them are writers where each of these loops:
- lock region in a file with posix write lock
- write to the region
- unlock it
While the second half loops concurently (time and file offset vise):
- lock region with read ofd lock
- read the region, expects it to be consistent block vise
- unlock it
As far as I can tell this is supposed to be supported combination
I looked at this again and what I found is that there are multiple concurrent writers that each get a posix write lock and then write to overlapping portions of the file.
What I think happens here is that multiple posix write locks get combined into a single lock, since they originate from the same PGID. On of them The writers therefore do not lock against one another, and they may write concurrently to the same part of the file. This can theoretically leave the file in an inconsistent state, but normally should not, since the individual writes are for larger areas and we would normally see the result of one or the other writes as if they were properly locked.
However, another thing that can happen is that one of the two threads then unlocks the region that it had been writing to, while the other one is still writing. A reader thread can now get the OFD read lock for a region that is completely unlocked but is still being written to.
Arnd
Hi!
I looked at this again and what I found is that there are multiple concurrent writers that each get a posix write lock and then write to overlapping portions of the file.
The blocks should not overlap for one kind of a lock, they overlap for different kind of locks though. So that posix write locks overlap with ofd read locks, etc.
So in the failing case it should look like:
| ofd read | ofd read | ofd read | | posix wr | posix wr | posix wr |
Since the ofd read lock blocks are starting at offset 0 and are write_size in size and the posix write locks are starting at offset write_size/4 and are as well write_size in size.
I tried to make sure that we do not have overlaping posix locks since in that case it's very easy to get a failure.
On Tue, Oct 31, 2017 at 10:33 AM, Cyril Hrubis chrubis@suse.cz wrote:
Hi!
I looked at this again and what I found is that there are multiple concurrent writers that each get a posix write lock and then write to overlapping portions of the file.
The blocks should not overlap for one kind of a lock, they overlap for different kind of locks though. So that posix write locks overlap with ofd read locks, etc.
So in the failing case it should look like:
| ofd read | ofd read | ofd read | | posix wr | posix wr | posix wr |
Since the ofd read lock blocks are starting at offset 0 and are write_size in size and the posix write locks are starting at offset write_size/4 and are as well write_size in size.
I tried to make sure that we do not have overlaping posix locks since in that case it's very easy to get a failure.
Ok, I see. In this case, we still see the posix locks being merged between the writers.Could it be that (either by design, or by accident) the F_UNLCK operation on one of them now releases the combined lock area?
I haven't looked at the code again, just guessing.
Arnd
Hi!
Since the ofd read lock blocks are starting at offset 0 and are write_size in size and the posix write locks are starting at offset write_size/4 and are as well write_size in size.
I tried to make sure that we do not have overlaping posix locks since in that case it's very easy to get a failure.
Ok, I see. In this case, we still see the posix locks being merged between the writers.Could it be that (either by design, or by accident) the F_UNLCK operation on one of them now releases the combined lock area?
That shouldn't be happening either. The threads that place the POSIX locks does not overlap and they should unlock exactly the same block that has been locked. So even if neighbouring locks are merged when locked the unlock operation should split them back again.
On Mon, Nov 6, 2017 at 3:18 PM, Cyril Hrubis chrubis@suse.cz wrote:
Hi!
Since the ofd read lock blocks are starting at offset 0 and are write_size in size and the posix write locks are starting at offset write_size/4 and are as well write_size in size.
I tried to make sure that we do not have overlaping posix locks since in that case it's very easy to get a failure.
Ok, I see. In this case, we still see the posix locks being merged between the writers.Could it be that (either by design, or by accident) the F_UNLCK operation on one of them now releases the combined lock area?
That shouldn't be happening either. The threads that place the POSIX locks does not overlap and they should unlock exactly the same block that has been locked. So even if neighbouring locks are merged when locked the unlock operation should split them back again.
Makes sense. Any idea how to analyze the failure further?
One more thing I looked at are the results that Naresh posted, in particular the file offsets that get reported for the incorrect reads, and there are actually three tests that fail, all of them involving one OFD lock and one POSIX lock:
0x3010 OFD read lock vs POSIX write lock 0x3500 OFD read lock vs POSIX write lock (second fail) 0x5080 OFD read lock vs POSIX write lock 0x5020 OFD read lock vs POSIX write lock
0x08b0 OFD r/w lock vs POSIX write lock 0x3008 OFD r/w lock vs POSIX write lock 0x5080 OFD r/w lock vs POSIX write lock
0x5420 OFD r/w lock vs POSIX read lock 0x36d8 OFD r/w lock vs POSIX read lock 0x4700 OFD r/w lock vs POSIX read lock (second fail) 0x5430 OFD r/w lock vs POSIX read lock
These are always 8-byte aligned addresses, but not cacheline aligned. The ones that fail in fn_ofd_r() fail at at n*4096 + m*8, with m being a small number. The ones that fail in fn_posix_r apparently tend to do so at address n*4096 + 1024 + m*8. In both cases that is the start of the read buffer, but there are some exceptions.
Since the file system is tmpfs, the access is directly on the page cache, and the write must be hitting memory just as we are accessing the first cache line of the page cache page most of the time this happens, but not always.
The 8-byte alignment is particularly interesting here, since I'm pretty sure we come here from copy_to_user(), which uses the 'ldp' and 'stp' instructions on arm64 to copy 16 bytes at a time.
Arnd