Message-ID: <63b1e234-e005-a62b-82c5-fa7acf26d53a@huawei.com>
Date:   Thu, 7 Dec 2023 22:15:55 +0800
From:   Baokun Li <libaokun1@...wei.com>
To:     Jan Kara <jack@...e.cz>
CC:     <linux-mm@...ck.org>, <linux-ext4@...r.kernel.org>,
        <tytso@....edu>, <adilger.kernel@...ger.ca>, <willy@...radead.org>,
        <akpm@...ux-foundation.org>, <ritesh.list@...il.com>,
        <linux-kernel@...r.kernel.org>, <yi.zhang@...wei.com>,
        <yangerkun@...wei.com>, <yukuai3@...wei.com>,
        Baokun Li <libaokun1@...wei.com>
Subject: Re: [PATCH -RFC 0/2] mm/ext4: avoid data corruption when extending
 DIO write race with buffered read

On 2023/12/7 3:37, Jan Kara wrote:
> On Tue 05-12-23 20:50:30, Baokun Li wrote:
>> On 2023/12/4 22:41, Jan Kara wrote:
>>> On Mon 04-12-23 21:50:18, Baokun Li wrote:
>>>> On 2023/12/4 20:11, Jan Kara wrote:
>>>> The problem is with a one-master-twoslave MYSQL database with three
>>>> physical machines, and using sysbench pressure testing on each of the
>>>> three machines, the problem occurs about once every two to three hours.
>>>>
>>>> The problem is with the relay log file, and when the problem occurs, the
>>>> middle dozens of bytes of the file are read as all zeros, while the data on
>>>> disk is not. This is a journal-like file where a write process gets the data
>>>> from
>>>> the master node and writes it locally, and another replay process reads the
>>>> file and performs the replay operation accordingly (some SQL statements).
>>>> The problem is that when replaying, it finds that the data read is
>>>> corrupted,
>>>> not valid SQL data, while the data on disk is normal.
>>>>
>>>> It's not confirmed that buffered reads vs direct IO writes is actually
>>>> causing this issue, but this is the only scenario that we can reproduce
>>>> with our local simplified scripts. Also, after merging in patch 1, the
>>>> MYSQL pressure test scenario has now been tested for 5 days and has not
>>>> been reproduced.
>>>>
>>>> I'll double-check the problem scenario, although buffered reads with
>>>> buffered writes doesn't seem to have this problem.
>>> Yeah, from what you write it seems that the replay code is using buffered
>>> reads on the journal file. I guess you could confirm that with a bit of
>>> kernel tracing but the symptoms look pretty convincing. Did you try talking
>>> to MYSQL guys about why they are doing this?
>> The operations performed on the relay log file are buffered reads and
>> writes, which I confirmed with the following bpftrace script:
>> ```
>> #include <linux/fs.h>
>> #include <linux/path.h>
>> #include <linux/dcache.h>
>>
>> kprobe:generic_file_buffered_read /!strncmp(str(((struct kiocb
>> *)arg0)->ki_filp->f_path.dentry->d_name.name), "relay", 5)/ {
>>      printf("read path: %s\n", str(((struct kiocb
>> *)arg0)->ki_filp->f_path.dentry->d_name.name));
>> }
>>
>> kprobe:ext4_buffered_write_iter /!strncmp(str(((struct kiocb
>> *)arg0)->ki_filp->f_path.dentry->d_name.name), "relay", 5)/ {
>>      printf("write path: %s\n", str(((struct kiocb
>> *)arg0)->ki_filp->f_path.dentry->d_name.name));
>> }
>> ```
>> I suspect there are DIO writes causing the problem, but I haven't caught
>> any DIO writes to such files via bpftrace.
> Interesting. Not sure how your partially zeroed-out buffers could happen
> with fully buffered IO.
>
After looking at the code again and again, the following concurrency
seems to bypass the memory barrier:

ext4_buffered_write_iter
  generic_perform_write
   copy_page_from_iter_atomic
   ext4_da_write_end
    ext4_da_do_write_end
     block_write_end
      __block_commit_write
       folio_mark_uptodate
        smp_wmb()
        set_bit(PG_uptodate, folio_flags(folio, 0))
     i_size_write(inode, pos + copied)
     // write isize 2048
     unlock_page(page)

ext4_file_read_iter
  generic_file_read_iter
   filemap_read
    filemap_get_pages
     filemap_get_read_batch
     folio_test_uptodate(folio)
      ret = test_bit(PG_uptodate, folio_flags(folio, 0));
      if (ret)
       smp_rmb();
       // The read barrier here ensures
       // that data 0-2048 in the page is synchronized.
                            ext4_buffered_write_iter
                             generic_perform_write
                              copy_page_from_iter_atomic
                              ext4_da_write_end
                               ext4_da_do_write_end
                                block_write_end
                                 __block_commit_write
                                  folio_mark_uptodate
                                   smp_wmb()
                                   set_bit(PG_uptodate, 
folio_flags(folio, 0))
                                i_size_write(inode, pos + copied)
                                // write isize 4096
                                unlock_page(page)
    // read isize 4096
    isize = i_size_read(inode)
    // But there is no read barrier here,
    // so the data in the 2048-4096 range
    // may not be synchronized yet !!!
    copy_page_to_iter()
    // copyout 4096

In the concurrency above, we read the updated i_size, but there is
no read barrier to ensure that the data in the page is the same as
the i_size at this point. Therefore, we may copy the unsynchronized
page out. Is it normal for us to read zero-filled data in this case?



Thanks!
-- 
With Best Regards,
Baokun Li
.

Powered by blists - more mailing lists