Re: [PATCH v2] ocfs2: call journal flush to mark journal as empty after journal recovery when mount

From: Joseph Qi
Date: Mon Dec 16 2019 - 05:02:50 EST




On 19/12/12 14:00, Kai Li wrote:
> If journal is dirty when mount, it will be replayed but jbd2 sb
> log tail cannot be updated to mark a new start because
> journal->j_flag has already been set with JBD2_ABORT first
> in journal_init_common. When a new transaction is committed, it
> will be recored in block 1 first(journal->j_tail is set to 1 in
> journal_reset).If emergency restart happens again before journal
> super block is updated unfortunately, the new recorded trans will
> not be replayed in the next mount.
>
> The following steps describe this procedure in detail.
> 1. mount and touch some files
> 2. these transactions are committed to journal area but not checkpointed
> 3. emergency restart
> 4. mount again and its journals are replayed
> 5. journal super block's first s_start is 1, but its s_seq is not updated
> 6. touch a new file and its trans is committed but not checkpointed
> 7. emergency restart again
> 8. mount and journal is dirty, but trans committed in 6 will not be
> replayed.
>
> This exception happens easily when this lun is used by only one node. If it
> is used by multi-nodes, other node will replay its journal and its
> journal super block will be updated after recovery like what this patch
> does.
>
> ocfs2_recover_node->ocfs2_replay_journal.
>
> The following jbd2 journal can be generated by touching a new file after
> journal is replayed, and seq 15 is the first valid commit, but first seq
> is 13 in journal super block.
> logdump:
> Block 0: Journal Superblock
> Seq: 0 Type: 4 (JBD2_SUPERBLOCK_V2)
> Blocksize: 4096 Total Blocks: 32768 First Block: 1
> First Commit ID: 13 Start Log Blknum: 1
> Error: 0
> Feature Compat: 0
> Feature Incompat: 2 block64
> Feature RO compat: 0
> Journal UUID: 4ED3822C54294467A4F8E87D2BA4BC36
> FS Share Cnt: 1 Dynamic Superblk Blknum: 0
> Per Txn Block Limit Journal: 0 Data: 0
>
> Block 1: Journal Commit Block
> Seq: 14 Type: 2 (JBD2_COMMIT_BLOCK)
>
> Block 2: Journal Descriptor
> Seq: 15 Type: 1 (JBD2_DESCRIPTOR_BLOCK)
> No. Blocknum Flags
> 0. 587 none
> UUID: 00000000000000000000000000000000
> 1. 8257792 JBD2_FLAG_SAME_UUID
> 2. 619 JBD2_FLAG_SAME_UUID
> 3. 24772864 JBD2_FLAG_SAME_UUID
> 4. 8257802 JBD2_FLAG_SAME_UUID
> 5. 513 JBD2_FLAG_SAME_UUID JBD2_FLAG_LAST_TAG
> ...
> Block 7: Inode
> Inode: 8257802 Mode: 0640 Generation: 57157641 (0x3682809)
> FS Generation: 2839773110 (0xa9437fb6)
> CRC32: 00000000 ECC: 0000
> Type: Regular Attr: 0x0 Flags: Valid
> Dynamic Features: (0x1) InlineData
> User: 0 (root) Group: 0 (root) Size: 7
> Links: 1 Clusters: 0
> ctime: 0x5de5d870 0x11104c61 -- Tue Dec 3 11:37:20.286280801 2019
> atime: 0x5de5d870 0x113181a1 -- Tue Dec 3 11:37:20.288457121 2019
> mtime: 0x5de5d870 0x11104c61 -- Tue Dec 3 11:37:20.286280801 2019
> dtime: 0x0 -- Thu Jan 1 08:00:00 1970
> ...
> Block 9: Journal Commit Block
> Seq: 15 Type: 2 (JBD2_COMMIT_BLOCK)
>
> The following is jouranl recovery log when recovering the upper jbd2
> journal when mount again.
> syslog:
> [ 2265.648622] ocfs2: File system on device (252,1) was not unmounted cleanly, recovering it.
> [ 2265.649695] fs/jbd2/recovery.c:(do_one_pass, 449): Starting recovery pass 0
> [ 2265.650407] fs/jbd2/recovery.c:(do_one_pass, 449): Starting recovery pass 1
> [ 2265.650409] fs/jbd2/recovery.c:(do_one_pass, 449): Starting recovery pass 2
> [ 2265.650410] fs/jbd2/recovery.c:(jbd2_journal_recover, 278): JBD2: recovery, exit status 0, recovered transactions 13 to 13
>
> Due to first commit seq 13 recorded in journal super is not consistent
> with the value recorded in block 1(seq is 14), journal recovery will be
> terminated before seq 15 even though it is an unbroken commit, inode
> 8257802 is a new file and it will be lost.
>
> Signed-off-by: Kai Li <li.kai4@xxxxxxx>
> ---
> fs/ocfs2/journal.c | 9 +++++++++
> 1 file changed, 9 insertions(+)
>
> diff --git a/fs/ocfs2/journal.c b/fs/ocfs2/journal.c
> index 1afe57f425a0..5c7a489f47b0 100644
> --- a/fs/ocfs2/journal.c
> +++ b/fs/ocfs2/journal.c
> @@ -1066,6 +1066,15 @@ int ocfs2_journal_load(struct ocfs2_journal *journal, int local, int replayed)
>
> ocfs2_clear_journal_error(osb->sb, journal->j_journal, osb->slot_num);
>
> + if (replayed) {
> + mlog(ML_NOTICE, "journal recovery complete");

I don't think this log is appropriate, or we can change it to something like:
"Journal is dirty, wipe it first"?

Thanks,
Joseph

> + jbd2_journal_lock_updates(journal->j_journal);
> + status = jbd2_journal_flush(journal->j_journal);
> + jbd2_journal_unlock_updates(journal->j_journal);
> + if (status < 0)
> + mlog_errno(status);
> + }
> +
> status = ocfs2_journal_toggle_dirty(osb, 1, replayed);
> if (status < 0) {
> mlog_errno(status);
>