| Message ID | 1484141938-4195-1-git-send-email-houtao1@huawei.com (mailing list archive) |
|---|---|
| State | Accepted |
| Headers | show |
On Wed, Jan 11, 2017 at 09:38:58PM +0800, Hou Tao wrote: > It is possible that the data fork or the attribute fork > of an inode will be splitted to the next log record, so > we need to check the count of available operations > in the log record and calculate the count of skipped > operations properly. > So what is the problem with the existing code? You need to describe the problematic log state and the existing code flow in more detail (i.e., which op record covering the inode format is split across a log record? what is the observed logprint behavior?) in the commit log description, particularly since this is likely not a state easily tested/reproduced. > Signed-off-by: Hou Tao <houtao1@huawei.com> > --- > logprint/log_misc.c | 21 ++++++++++++--------- > 1 file changed, 12 insertions(+), 9 deletions(-) > > diff --git a/logprint/log_misc.c b/logprint/log_misc.c > index a0f1766..20f0f89 100644 > --- a/logprint/log_misc.c > +++ b/logprint/log_misc.c > @@ -524,6 +524,7 @@ xlog_print_trans_inode( > xfs_inode_log_format_t *f; > int mode; > int size; > + int printed_ops; > > /* > * print inode type header region > @@ -572,13 +573,6 @@ xlog_print_trans_inode( > xlog_print_trans_inode_core(&dino); > *ptr += xfs_log_dinode_size(dino.di_version); > So it appears the inode item can have 2-4 op records: the format, core inode and optionally the data and attr forks. Up to this point, we've printed the format and core, which is two ops. If we hit the end of the log record, we need to return the number of remaining ops in the format so the subsequent record iteration can skip them and find the first new transaction... > - if (*i == num_ops-1 && f->ilf_size == 3) { > - return 1; > - } > - ... which afaict, the above check does. E.g., If we've printed two ops out of three and hit the record op count, return 1 op to skip. So what are we trying to fix here? Is the problem that i isn't bumped before we return, or that we're missing some information that should be printed by the hunk that follows this check? Or am I missing something else..? > - /* does anything come next */ > - op_head = (xlog_op_header_t *)*ptr; > - So then op_head is set, may not necessarily be valid, but it isn't actually used in this hunk so we can safely proceed without this assignment (I'm starting to wonder if this code is intentionally obtuse or just by accident :P). > switch (f->ilf_fields & (XFS_ILOG_DEV | XFS_ILOG_UUID)) { > case XFS_ILOG_DEV: > printf(_("DEV inode: no extra region\n")); > @@ -595,7 +589,13 @@ xlog_print_trans_inode( > ASSERT(f->ilf_size <= 4); > ASSERT((f->ilf_size == 3) || (f->ilf_fields & XFS_ILOG_AFORK)); > > + /* does anything come next */ > + printed_ops = 2; > + op_head = (xlog_op_header_t *)*ptr; > + Now we set op_head and add the checks below to see if we can increment to another op header. If not, return the skip count. So I think the logic here is Ok, but the existing code is confusing and so it's not totally clear what you are trying to fix. Also, what I would suggest is to do something like 'skip_count = f->ilf_size' once near the top of the function, decrement it at each point as appropriate as we step through the op headers, then update all of the return points to just 'return skip_count;'. Thoughts? > if (f->ilf_fields & XFS_ILOG_DFORK) { > + if (*i == num_ops-1) > + return f->ilf_size-printed_ops; I'm not really sure what we want to do here with regard to indentation inconsistency with existing code. The existing code uses 4 spaces vs. this patch using tabs. Perhaps that's a question for Eric.. Either way, the indentation of the 'if ()' itself is broken here... > (*i)++; > xlog_print_op_header(op_head, *i, ptr); > > @@ -618,11 +618,14 @@ xlog_print_trans_inode( > > *ptr += be32_to_cpu(op_head->oh_len); > if (op_head->oh_flags & XLOG_CONTINUE_TRANS) > - return 1; > + return f->ilf_size-printed_ops; > op_head = (xlog_op_header_t *)*ptr; > + printed_ops++; > } > > if (f->ilf_fields & XFS_ILOG_AFORK) { > + if (*i == num_ops-1) > + return f->ilf_size-printed_ops; ... and the same thing here. Brian > (*i)++; > xlog_print_op_header(op_head, *i, ptr); > > @@ -644,7 +647,7 @@ xlog_print_trans_inode( > } > *ptr += be32_to_cpu(op_head->oh_len); > if (op_head->oh_flags & XLOG_CONTINUE_TRANS) > - return 1; > + return f->ilf_size-printed_ops; > } > > return 0; > -- > 2.5.0 > > -- > To unsubscribe from this list: send the line "unsubscribe linux-xfs" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html -- To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On 1/12/17 7:34 AM, Brian Foster wrote: > On Wed, Jan 11, 2017 at 09:38:58PM +0800, Hou Tao wrote: >> It is possible that the data fork or the attribute fork >> of an inode will be splitted to the next log record, so >> we need to check the count of available operations >> in the log record and calculate the count of skipped >> operations properly. >> > > So what is the problem with the existing code? You need to describe the > problematic log state and the existing code flow in more detail (i.e., > which op record covering the inode format is split across a log record? > what is the observed logprint behavior?) in the commit log description, > particularly since this is likely not a state easily tested/reproduced. I agree - I hadn't reviewed this yet because xfs_logprint is very confusing and complicated anyway, and I wasn't quite clear on the problem or the resolution here. >> Signed-off-by: Hou Tao <houtao1@huawei.com> >> --- >> logprint/log_misc.c | 21 ++++++++++++--------- >> 1 file changed, 12 insertions(+), 9 deletions(-) >> >> diff --git a/logprint/log_misc.c b/logprint/log_misc.c >> index a0f1766..20f0f89 100644 >> --- a/logprint/log_misc.c >> +++ b/logprint/log_misc.c >> @@ -524,6 +524,7 @@ xlog_print_trans_inode( >> xfs_inode_log_format_t *f; >> int mode; >> int size; >> + int printed_ops; >> >> /* >> * print inode type header region >> @@ -572,13 +573,6 @@ xlog_print_trans_inode( >> xlog_print_trans_inode_core(&dino); >> *ptr += xfs_log_dinode_size(dino.di_version); >> > > So it appears the inode item can have 2-4 op records: the format, core > inode and optionally the data and attr forks. Up to this point, we've > printed the format and core, which is two ops. If we hit the end of the > log record, we need to return the number of remaining ops in the format > so the subsequent record iteration can skip them and find the first new > transaction... > >> - if (*i == num_ops-1 && f->ilf_size == 3) { >> - return 1; >> - } >> - > > ... which afaict, the above check does. E.g., If we've printed two ops > out of three and hit the record op count, return 1 op to skip. > > So what are we trying to fix here? Is the problem that i isn't bumped > before we return, or that we're missing some information that should be > printed by the hunk that follows this check? Or am I missing something > else..? A testcase would help us understand. :) >> - /* does anything come next */ >> - op_head = (xlog_op_header_t *)*ptr; >> - > > So then op_head is set, may not necessarily be valid, but it isn't > actually used in this hunk so we can safely proceed without this > assignment (I'm starting to wonder if this code is intentionally obtuse > or just by accident :P). xfs_logprint is a mess :( >> switch (f->ilf_fields & (XFS_ILOG_DEV | XFS_ILOG_UUID)) { >> case XFS_ILOG_DEV: >> printf(_("DEV inode: no extra region\n")); >> @@ -595,7 +589,13 @@ xlog_print_trans_inode( >> ASSERT(f->ilf_size <= 4); >> ASSERT((f->ilf_size == 3) || (f->ilf_fields & XFS_ILOG_AFORK)); >> >> + /* does anything come next */ >> + printed_ops = 2; >> + op_head = (xlog_op_header_t *)*ptr; >> + > > Now we set op_head and add the checks below to see if we can increment > to another op header. If not, return the skip count. > > So I think the logic here is Ok, but the existing code is confusing and > so it's not totally clear what you are trying to fix. Also, what I would > suggest is to do something like 'skip_count = f->ilf_size' once near the > top of the function, decrement it at each point as appropriate as we > step through the op headers, then update all of the return points to > just 'return skip_count;'. Thoughts? > >> if (f->ilf_fields & XFS_ILOG_DFORK) { >> + if (*i == num_ops-1) >> + return f->ilf_size-printed_ops; > > I'm not really sure what we want to do here with regard to indentation > inconsistency with existing code. The existing code uses 4 spaces vs. > this patch using tabs. Perhaps that's a question for Eric.. Yeah, I'd say try to follow the surrounding code style, but regardless, code under conditionals should be indented in /some/ way. Thanks, -Eric > Either way, the indentation of the 'if ()' itself is broken here... > >> (*i)++; >> xlog_print_op_header(op_head, *i, ptr); >> >> @@ -618,11 +618,14 @@ xlog_print_trans_inode( >> >> *ptr += be32_to_cpu(op_head->oh_len); >> if (op_head->oh_flags & XLOG_CONTINUE_TRANS) >> - return 1; >> + return f->ilf_size-printed_ops; >> op_head = (xlog_op_header_t *)*ptr; >> + printed_ops++; >> } >> >> if (f->ilf_fields & XFS_ILOG_AFORK) { >> + if (*i == num_ops-1) >> + return f->ilf_size-printed_ops; > > ... and the same thing here. > > Brian > >> (*i)++; >> xlog_print_op_header(op_head, *i, ptr); >> >> @@ -644,7 +647,7 @@ xlog_print_trans_inode( >> } >> *ptr += be32_to_cpu(op_head->oh_len); >> if (op_head->oh_flags & XLOG_CONTINUE_TRANS) >> - return 1; >> + return f->ilf_size-printed_ops; >> } >> >> return 0; >> -- >> 2.5.0 >> >> -- >> To unsubscribe from this list: send the line "unsubscribe linux-xfs" in >> the body of a message to majordomo@vger.kernel.org >> More majordomo info at http://vger.kernel.org/majordomo-info.html > -- > To unsubscribe from this list: send the line "unsubscribe linux-xfs" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html > -- To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On 2017/1/12 22:38, Eric Sandeen wrote: >> So what is the problem with the existing code? You need to describe the >> problematic log state and the existing code flow in more detail (i.e., >> which op record covering the inode format is split across a log record? >> what is the observed logprint behavior?) in the commit log description, >> particularly since this is likely not a state easily tested/reproduced. > > I agree - I hadn't reviewed this yet because xfs_logprint is > very confusing and complicated anyway, and I wasn't quite > clear on the problem or the resolution here. Sorry for the confusion. Thanks for Brian's review. >> So it appears the inode item can have 2-4 op records: the format, core >> inode and optionally the data and attr forks. Up to this point, we've >> printed the format and core, which is two ops. If we hit the end of the >> log record, we need to return the number of remaining ops in the format >> so the subsequent record iteration can skip them and find the first new >> transaction... >> ... which afaict, the above check does. E.g., If we've printed two ops >> out of three and hit the record op count, return 1 op to skip. >> >> So what are we trying to fix here? Is the problem that i isn't bumped >> before we return, or that we're missing some information that should be >> printed by the hunk that follows this check? Or am I missing something >> else..? > A testcase would help us understand. :) If the data/attr fork log operation of an inode log item are splitted to the next log record, xfs_logprint doesn't check the remaining log operations in current log record and still tries to print these log operations which don't exist in the log record. The content of these log operations will be incorrect, or worse xfs_logprint will trigger an segment-fault and exit. xfs_logprint also doesn't calculate the count of the splitted log operations correctly. It just returns 1 when the current log operation is splitted to the next log record. xfs_logprint needs to consider the log operations behind. As we can see from the following example, there are only 243 operations in the first log record, but xfs_logprint shows the 244th operation and the length of the operation is invalid. The first operation of the second log record comes from the split, but xfs_logprint doesn't show something likes "Left over region from split log item" to clarify it. ============================================================================ cycle: 120 version: 2 lsn: 120,11014 tail_lsn: 120,427 length of Log Record: 32256 prev offset: 10984 num ops: 243 ...... h_size: 32768 ---------------------------------------------------------------------------- Oper (0): tid: 2db4353b len: 0 clientid: TRANS flags: START ...... ---------------------------------------------------------------------------- Oper (240): tid: 2db4353b len: 56 clientid: TRANS flags: none INODE: #regs: 4 ino: 0x200a4bf flags: 0x45 dsize: 64 blkno: 10506832 len: 16 boff: 7936 Oper (241): tid: 2db4353b len: 96 clientid: TRANS flags: none INODE CORE ...... Oper (242): tid: 2db4353b len: 64 clientid: TRANS flags: none EXTENTS inode data Oper (243): tid: 150000 len: 83886080 clientid: ERROR flags: none LOCAL attr data ============================================================================ cycle: 120 version: 2 lsn: 120,11078 tail_lsn: 120,427 length of Log Record: 3584 prev offset: 11014 num ops: 44 ...... ---------------------------------------------------------------------------- Oper (0): tid: 2db4353b len: 52 clientid: TRANS flags: none ---------------------------------------------------------------------------- >> Now we set op_head and add the checks below to see if we can increment >> to another op header. If not, return the skip count. >> >> So I think the logic here is Ok, but the existing code is confusing and >> so it's not totally clear what you are trying to fix. Also, what I would >> suggest is to do something like 'skip_count = f->ilf_size' once near the >> top of the function, decrement it at each point as appropriate as we >> step through the op headers, then update all of the return points to >> just 'return skip_count;'. Thoughts? "skip_count" is better than the "printed_ops" one. >> >>> if (f->ilf_fields & XFS_ILOG_DFORK) { >>> + if (*i == num_ops-1) >>> + return f->ilf_size-printed_ops; >> >> I'm not really sure what we want to do here with regard to indentation >> inconsistency with existing code. The existing code uses 4 spaces vs. >> this patch using tabs. Perhaps that's a question for Eric.. > > Yeah, I'd say try to follow the surrounding code style, but regardless, > code under conditionals should be indented in /some/ way. The existing code mixes the usage of 4 spaces and tab, and there is no indentation for the statement under conditionals. If the above explanation is OK, I will send a V2 patch. Regards. Tao -- To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On 1/12/17 9:28 PM, Hou Tao wrote: > The existing code mixes the usage of 4 spaces and tab, and there is no > indentation for the statement under conditionals. At least on my terminal, # grep -A1 -w if logprint/log_misc.c shows every if statement with some form of indentation below it. Whether it's 4 spaces or a tab, doesn't matter too much to me, because it's mixed in the file. Thanks, -Eric -- To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On 2017/1/13 11:32, Eric Sandeen wrote: > On 1/12/17 9:28 PM, Hou Tao wrote: >> The existing code mixes the usage of 4 spaces and tab, and there is no >> indentation for the statement under conditionals. > > At least on my terminal, > > # grep -A1 -w if logprint/log_misc.c > > shows every if statement with some form of indentation below it. > Whether it's 4 spaces or a tab, doesn't matter too much to me, > because it's mixed in the file. grep treats the tab as 8 spaces, so here comes the indentation for most return statements under conditionals in function xlog_print_trans_inode. Any way it is my mistake, and i will fix it. Regards, Tao -- To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Fri, Jan 13, 2017 at 11:28:34AM +0800, Hou Tao wrote: > > On 2017/1/12 22:38, Eric Sandeen wrote: > >> So what is the problem with the existing code? You need to describe the > >> problematic log state and the existing code flow in more detail (i.e., > >> which op record covering the inode format is split across a log record? > >> what is the observed logprint behavior?) in the commit log description, > >> particularly since this is likely not a state easily tested/reproduced. > > > > I agree - I hadn't reviewed this yet because xfs_logprint is > > very confusing and complicated anyway, and I wasn't quite > > clear on the problem or the resolution here. > Sorry for the confusion. Thanks for Brian's review. > > >> So it appears the inode item can have 2-4 op records: the format, core > >> inode and optionally the data and attr forks. Up to this point, we've > >> printed the format and core, which is two ops. If we hit the end of the > >> log record, we need to return the number of remaining ops in the format > >> so the subsequent record iteration can skip them and find the first new > >> transaction... > >> ... which afaict, the above check does. E.g., If we've printed two ops > >> out of three and hit the record op count, return 1 op to skip. > >> > >> So what are we trying to fix here? Is the problem that i isn't bumped > >> before we return, or that we're missing some information that should be > >> printed by the hunk that follows this check? Or am I missing something > >> else..? > > A testcase would help us understand. :) > If the data/attr fork log operation of an inode log item are splitted to the > next log record, xfs_logprint doesn't check the remaining log operations in > current log record and still tries to print these log operations which don't > exist in the log record. The content of these log operations will be incorrect, > or worse xfs_logprint will trigger an segment-fault and exit. > > xfs_logprint also doesn't calculate the count of the splitted log operations > correctly. It just returns 1 when the current log operation is splitted to > the next log record. xfs_logprint needs to consider the log operations behind. > Ok, though I'm still unclear on where this applies to the code... > As we can see from the following example, there are only 243 operations in > the first log record, but xfs_logprint shows the 244th operation and the length > of the operation is invalid. > > The first operation of the second log record comes from the split, but > xfs_logprint doesn't show something likes "Left over region from split log item" > to clarify it. > Thank you for the example. This helps clarify the problem. > ============================================================================ > cycle: 120 version: 2 lsn: 120,11014 tail_lsn: 120,427 > length of Log Record: 32256 prev offset: 10984 num ops: 243 > ...... > h_size: 32768 > ---------------------------------------------------------------------------- > Oper (0): tid: 2db4353b len: 0 clientid: TRANS flags: START > ...... > ---------------------------------------------------------------------------- > Oper (240): tid: 2db4353b len: 56 clientid: TRANS flags: none So we have the 243 op count record and get to this 4 op count inode transaction. The 4th op header happens to be split off into the next log record... > INODE: #regs: 4 ino: 0x200a4bf flags: 0x45 dsize: 64 > blkno: 10506832 len: 16 boff: 7936 > Oper (241): tid: 2db4353b len: 96 clientid: TRANS flags: none > INODE CORE > ...... > Oper (242): tid: 2db4353b len: 64 clientid: TRANS flags: none > EXTENTS inode data The first 3 op headers (240-242) appear to print fine, but there is no num_ops validation against '*i' between the 3rd and 4th ops. We just blindly increment i to 243, print and carry on as if nothing was skipped. Could you update the commit log description to be very specific with regard to the problem here? For example, point out that if an inode item happens to have 4 op headers and the 4th exists after a log record boundary, we don't handle the op count correctly and print invalid data. Also for reference (and since this is difficult to test/verify), could you also reply with the new output for this situation with the patched logprint? Thanks. Brian > Oper (243): tid: 150000 len: 83886080 clientid: ERROR flags: none > LOCAL attr data > ============================================================================ > cycle: 120 version: 2 lsn: 120,11078 tail_lsn: 120,427 > length of Log Record: 3584 prev offset: 11014 num ops: 44 > ...... > ---------------------------------------------------------------------------- > Oper (0): tid: 2db4353b len: 52 clientid: TRANS flags: none > ---------------------------------------------------------------------------- > > >> Now we set op_head and add the checks below to see if we can increment > >> to another op header. If not, return the skip count. > >> > >> So I think the logic here is Ok, but the existing code is confusing and > >> so it's not totally clear what you are trying to fix. Also, what I would > >> suggest is to do something like 'skip_count = f->ilf_size' once near the > >> top of the function, decrement it at each point as appropriate as we > >> step through the op headers, then update all of the return points to > >> just 'return skip_count;'. Thoughts? > "skip_count" is better than the "printed_ops" one. > > >> > >>> if (f->ilf_fields & XFS_ILOG_DFORK) { > >>> + if (*i == num_ops-1) > >>> + return f->ilf_size-printed_ops; > >> > >> I'm not really sure what we want to do here with regard to indentation > >> inconsistency with existing code. The existing code uses 4 spaces vs. > >> this patch using tabs. Perhaps that's a question for Eric.. > > > > Yeah, I'd say try to follow the surrounding code style, but regardless, > > code under conditionals should be indented in /some/ way. > The existing code mixes the usage of 4 spaces and tab, and there is no > indentation for the statement under conditionals. > > If the above explanation is OK, I will send a V2 patch. > > Regards. > > Tao > > -- > To unsubscribe from this list: send the line "unsubscribe linux-xfs" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html -- To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
diff --git a/logprint/log_misc.c b/logprint/log_misc.c index a0f1766..20f0f89 100644 --- a/logprint/log_misc.c +++ b/logprint/log_misc.c @@ -524,6 +524,7 @@ xlog_print_trans_inode( xfs_inode_log_format_t *f; int mode; int size; + int printed_ops; /* * print inode type header region @@ -572,13 +573,6 @@ xlog_print_trans_inode( xlog_print_trans_inode_core(&dino); *ptr += xfs_log_dinode_size(dino.di_version); - if (*i == num_ops-1 && f->ilf_size == 3) { - return 1; - } - - /* does anything come next */ - op_head = (xlog_op_header_t *)*ptr; - switch (f->ilf_fields & (XFS_ILOG_DEV | XFS_ILOG_UUID)) { case XFS_ILOG_DEV: printf(_("DEV inode: no extra region\n")); @@ -595,7 +589,13 @@ xlog_print_trans_inode( ASSERT(f->ilf_size <= 4); ASSERT((f->ilf_size == 3) || (f->ilf_fields & XFS_ILOG_AFORK)); + /* does anything come next */ + printed_ops = 2; + op_head = (xlog_op_header_t *)*ptr; + if (f->ilf_fields & XFS_ILOG_DFORK) { + if (*i == num_ops-1) + return f->ilf_size-printed_ops; (*i)++; xlog_print_op_header(op_head, *i, ptr); @@ -618,11 +618,14 @@ xlog_print_trans_inode( *ptr += be32_to_cpu(op_head->oh_len); if (op_head->oh_flags & XLOG_CONTINUE_TRANS) - return 1; + return f->ilf_size-printed_ops; op_head = (xlog_op_header_t *)*ptr; + printed_ops++; } if (f->ilf_fields & XFS_ILOG_AFORK) { + if (*i == num_ops-1) + return f->ilf_size-printed_ops; (*i)++; xlog_print_op_header(op_head, *i, ptr); @@ -644,7 +647,7 @@ xlog_print_trans_inode( } *ptr += be32_to_cpu(op_head->oh_len); if (op_head->oh_flags & XLOG_CONTINUE_TRANS) - return 1; + return f->ilf_size-printed_ops; } return 0;
It is possible that the data fork or the attribute fork of an inode will be splitted to the next log record, so we need to check the count of available operations in the log record and calculate the count of skipped operations properly. Signed-off-by: Hou Tao <houtao1@huawei.com> --- logprint/log_misc.c | 21 ++++++++++++--------- 1 file changed, 12 insertions(+), 9 deletions(-)