From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by smtp.lore.kernel.org (Postfix) with ESMTP id DF01AC4167B for ; Mon, 11 Dec 2023 17:49:58 +0000 (UTC) Received: by kanga.kvack.org (Postfix) id 51F6E6B018D; Mon, 11 Dec 2023 12:49:58 -0500 (EST) Received: by kanga.kvack.org (Postfix, from userid 40) id 4CF316B018E; Mon, 11 Dec 2023 12:49:58 -0500 (EST) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 370616B018F; Mon, 11 Dec 2023 12:49:58 -0500 (EST) X-Delivered-To: linux-mm@kvack.org Received: from relay.hostedemail.com (smtprelay0012.hostedemail.com [216.40.44.12]) by kanga.kvack.org (Postfix) with ESMTP id 21A4C6B018D for ; Mon, 11 Dec 2023 12:49:58 -0500 (EST) Received: from smtpin20.hostedemail.com (a10.router.float.18 [10.200.18.1]) by unirelay02.hostedemail.com (Postfix) with ESMTP id DF06A120299 for ; Mon, 11 Dec 2023 17:49:57 +0000 (UTC) X-FDA: 81555275634.20.21292C4 Received: from smtp-out2.suse.de (smtp-out2.suse.de [195.135.223.131]) by imf29.hostedemail.com (Postfix) with ESMTP id 37A18120028 for ; Mon, 11 Dec 2023 17:49:54 +0000 (UTC) Authentication-Results: imf29.hostedemail.com; dkim=pass header.d=suse.cz header.s=susede2_rsa header.b=Mf5cRpVZ; dkim=pass header.d=suse.cz header.s=susede2_ed25519 header.b=vlQqGyRm; dkim=pass header.d=suse.cz header.s=susede2_rsa header.b=Mf5cRpVZ; dkim=pass header.d=suse.cz header.s=susede2_ed25519 header.b=vlQqGyRm; dmarc=none; spf=pass (imf29.hostedemail.com: domain of jack@suse.cz designates 195.135.223.131 as permitted sender) smtp.mailfrom=jack@suse.cz ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=hostedemail.com; s=arc-20220608; t=1702316995; h=from:from:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:cc:mime-version:mime-version: content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references:dkim-signature; bh=RkLrrI1gmexDEyXqv7RkIgYzgnlJqhMidUtAhq81i5Y=; b=z9h/KPR71UdKSZY23PiONFUM2qqgOWcZ2Lj0reYf3kfdDO371qachCfsey+4aCgwAerHr+ hdVY1x23mPB7OOStK+J5IQwMvfSeMabVvf6CDJjGqfcaJCx/BpW4lV5rTdsdQeG3T12cBh LGMhlvaLaID3YK6X/tx9/UagThtkMsY= ARC-Authentication-Results: i=1; imf29.hostedemail.com; dkim=pass header.d=suse.cz header.s=susede2_rsa header.b=Mf5cRpVZ; dkim=pass header.d=suse.cz header.s=susede2_ed25519 header.b=vlQqGyRm; dkim=pass header.d=suse.cz header.s=susede2_rsa header.b=Mf5cRpVZ; dkim=pass header.d=suse.cz header.s=susede2_ed25519 header.b=vlQqGyRm; dmarc=none; spf=pass (imf29.hostedemail.com: domain of jack@suse.cz designates 195.135.223.131 as permitted sender) smtp.mailfrom=jack@suse.cz ARC-Seal: i=1; s=arc-20220608; d=hostedemail.com; t=1702316995; a=rsa-sha256; cv=none; b=wBDyx4blotjU1WMuQ3KKE++7ZFSUXuvHCYihUSEU9WRwZXv99odyXAoE+rzcnZcWlGo9me /rZn/ZZVjTrz8mT8WhNgEuOn3CkigwqnEgR1/fxS1pNap92iyYgUYOQv+LKfkS+h7SOkOP Csui/f9J6t8vD4+kRHVCfXZdetquKzw= Received: from imap2.dmz-prg2.suse.org (imap2.dmz-prg2.suse.org [10.150.64.98]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by smtp-out2.suse.de (Postfix) with ESMTPS id 3BBA11FBA7; Mon, 11 Dec 2023 17:49:53 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.cz; s=susede2_rsa; t=1702316993; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=RkLrrI1gmexDEyXqv7RkIgYzgnlJqhMidUtAhq81i5Y=; b=Mf5cRpVZ5GM9ghuslV9oPpAafIYRuwI93WQVJf4B+qgNuAAF9Gzv6/kfc0QuDlTcTEuCRa c2mUzap33UGntnsg1iTuoM9srE/jJQ4sTOhS/OoOMBdlRulDMx3YTg7u/+klnrYExuMFzz 1+qxUPTP/6GEAc1yB721gmcPZyGGao4= DKIM-Signature: v=1; a=ed25519-sha256; c=relaxed/relaxed; d=suse.cz; s=susede2_ed25519; t=1702316993; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=RkLrrI1gmexDEyXqv7RkIgYzgnlJqhMidUtAhq81i5Y=; b=vlQqGyRmzMB4lY+KXhdWBUUhIgZZkJ41LWZtGOL3JvD4qcgQHLfeKzxUlfA2fPt9TIfs/D ML2z9OGUgqEMsaBA== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.cz; s=susede2_rsa; t=1702316993; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=RkLrrI1gmexDEyXqv7RkIgYzgnlJqhMidUtAhq81i5Y=; b=Mf5cRpVZ5GM9ghuslV9oPpAafIYRuwI93WQVJf4B+qgNuAAF9Gzv6/kfc0QuDlTcTEuCRa c2mUzap33UGntnsg1iTuoM9srE/jJQ4sTOhS/OoOMBdlRulDMx3YTg7u/+klnrYExuMFzz 1+qxUPTP/6GEAc1yB721gmcPZyGGao4= DKIM-Signature: v=1; a=ed25519-sha256; c=relaxed/relaxed; d=suse.cz; s=susede2_ed25519; t=1702316993; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=RkLrrI1gmexDEyXqv7RkIgYzgnlJqhMidUtAhq81i5Y=; b=vlQqGyRmzMB4lY+KXhdWBUUhIgZZkJ41LWZtGOL3JvD4qcgQHLfeKzxUlfA2fPt9TIfs/D ML2z9OGUgqEMsaBA== Received: from imap2.dmz-prg2.suse.org (localhost [127.0.0.1]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (No client certificate requested) by imap2.dmz-prg2.suse.org (Postfix) with ESMTPS id 2B10D13A6B; Mon, 11 Dec 2023 17:49:53 +0000 (UTC) Received: from dovecot-director2.suse.de ([10.150.64.162]) by imap2.dmz-prg2.suse.org with ESMTPSA id Q9d8CsFLd2VEIwAAn2gu4w (envelope-from ); Mon, 11 Dec 2023 17:49:53 +0000 Received: by quack3.suse.cz (Postfix, from userid 1000) id C0B16A07E3; Mon, 11 Dec 2023 18:49:52 +0100 (CET) Date: Mon, 11 Dec 2023 18:49:52 +0100 From: Jan Kara To: Baokun Li Cc: Jan Kara , linux-mm@kvack.org, linux-ext4@vger.kernel.org, tytso@mit.edu, adilger.kernel@dilger.ca, willy@infradead.org, akpm@linux-foundation.org, ritesh.list@gmail.com, linux-kernel@vger.kernel.org, yi.zhang@huawei.com, yangerkun@huawei.com, yukuai3@huawei.com Subject: Re: [PATCH -RFC 0/2] mm/ext4: avoid data corruption when extending DIO write race with buffered read Message-ID: <20231211174952.mdwyh7fmu7rjzfn3@quack3> References: <20231202091432.8349-1-libaokun1@huawei.com> <20231204121120.mpxntey47rluhcfi@quack3> <20231204144106.fk4yxc422gppifsz@quack3> <70b274c2-c19a-103b-4cf4-b106c698ddcc@huawei.com> <20231206193757.k5cppxqew6zjmbx3@quack3> <63b1e234-e005-a62b-82c5-fa7acf26d53a@huawei.com> MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: <63b1e234-e005-a62b-82c5-fa7acf26d53a@huawei.com> X-Rspamd-Server: rspam09 X-Rspamd-Queue-Id: 37A18120028 X-Stat-Signature: eeya83za5m4bysph8f7srks49fefrsut X-Rspam-User: X-HE-Tag: 1702316994-446446 X-HE-Meta: U2FsdGVkX1+ntOKlyLc87OVg0T9UFLOeBoi7J8Vebmo5g7MQJHET+ctBQXFszQJvOBriQlYa5fKQDaiVCLowNY4TW6bEOovlcmW8D+IK9xfFdU+yJ1MSzDheROtozrLMK8JPaRznvRoQg/O6gZ4t4LS92sDEtQxPIWuD7XQKUBtNKZuD3f05u8AA/O7bieQpUh2rHnG9iuxosPosFADVrWpJEn4aACYhjMtHtEzktP9iiVFAhLUDbwRAVrGo7sgu+1tttXprFtVA9Zh+WOfl4N/j/E2i6iU6QcWkXnPQeVh5Hp6bBl4FVga8Qcm3iJkVbMjRF5WEkmcMxrv40WDfvYbmP51oTB6DWlTdd955avIR8fcciYX8SgDif2EDer+TqC+3nRdQaruWlOV1rdg85wApfoARESXxNKjQGmphqYsjSeqaPFqBAIfG0xScODUJPlFSFSW2r0WEPKL43WW629nU5jtmwN+QzQXB54acZDY1Vz2Ax5C+ch6H2yBKDaCAtdduWex3wWov874uABdz74WsxV/b2UaaGgUvYVZxTVE0TIlU3mVIcsr37aCm4SueAOqrEMUf4JS3T3j11QFGjqJBkCXK0ak04i3yC3GsSMevgEGDyweTY+k1Z3rw4sDYNR1SoMZ1rCz73obT+KtSdRxs6Y75Ofe78D5MCFbZ/z1cxRjIZmGNMvTAHrdOi1UmL6SD3CfecfQDYXn17v4T10T89vL9x3lt6uvrmXthLtvQ4QbeK1SOdvcmORKS7W+sq59u1bW+JQ2K/RfA7r+emIETYHK4cd1JWZimFrnMcC6fpwChOXaoc4pNQRWnDaTia8PMWscwnqD/FKLSyWN0WgtH+FKoj3HIpSdhbs9YPDTxyFDtiAJo0JbbMK08LRYwtOVGm9yKfHIprjWIGgZFzR9g2JlYLhCvB1A9senlYo671OaRoDobW0KPBs2yHoVxwcxFYU7k3YRKYPNgiu0 luti9Hak DnXa/S0ZSl3QMpZeOp/ksGs4MzdDa9bZmXwxcj4z1SwodDuM1MyD3vAnWzFrOCU5NmTGTHbeCRlpz6aAMtVfRAuw23Ax5sPoexznRNV0n6MSvnepfy3Hh7Sp39rjUB80acBw6yKrIQnNt7aKVScII8PzgAoWLHP3IN+x+mHI9246vY4ys+BFVwbwxl9pSIqNQYVwgyMQfzFNT6yTJWXtlOD9vISrdkbUnyq1dnaMcwNRVSe2NcZk/h3mnpXGAI7mTnPhmKea9i1HXltuP/KmHv4bvVb9bbgQPa125x79mRonFVNxMB04k3JnDkuViFICY3+95RyjLTDcnFRM= X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4 Sender: owner-linux-mm@kvack.org Precedence: bulk X-Loop: owner-majordomo@kvack.org List-ID: List-Subscribe: List-Unsubscribe: On Thu 07-12-23 22:15:55, Baokun Li wrote: > 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 > > > #include > > > #include > > > > > > 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? Indeed, I have checked and filemap_read() (but this dates back even to old do_generic_file_read() code) indeed does copy data only after checking uptodate flag and then sampling i_size so we may be copying state in the middle of the racing write and indeed there is nothing which would prevent prefetching page data before fetching inode size. I agree this is kind of nasty so I think adding a read barrier between i_size_read() and copy_page_to_iter() makes sense. Does it fix your issue with MYSQL? Honza -- Jan Kara SUSE Labs, CR