Re: [PATCH v4] debugfs/logdump.c: Add parameter t to dump sequence commit timestamps

["Darrick J. Wong" <djwong@kernel.org>]

On Fri, Jul 04, 2025 at 10:11:09AM +0800, zhanchengbin wrote:
> On 2025/7/3 23:39, Darrick J. Wong wrote:
> > On Thu, Jul 03, 2025 at 08:07:53PM +0800, zhanchengbin wrote:
> > > When filesystem errors occur, inspect journal sequences with parameter t to
> > > dump commit timestamps.
> > > 
> > > Signed-off-by: zhanchengbin <zhanchengbin1@huawei.com>
> > > ---
> > > v4: (1) Fix incorrect variable type; (2) Add logging for error branches.
> > > - Link to v3:
> > > https://patchwork.ozlabs.org/project/linux-ext4/patch/32252e29-aba9-df6f-3b97-d3774df375ad@huawei.com/
> > > v3: Change from displaying UTC time to local time.
> > > - Link to v2:
> > > https://patchwork.ozlabs.org/project/linux-ext4/patch/5a4b703c-6940-d9da-5686-337e3220d3a4@huawei.com/
> > > v2: Correct abnormal formats in the patch.
> > > - Link to v1:
> > > https://patchwork.ozlabs.org/project/linux-ext4/patch/50aeb0c1-9f14-ed04-c3b7-7a50f61c3341@huawei.com/
> > > ---
> > >   debugfs/logdump.c | 61 ++++++++++++++++++++++++++++++++++++++++-------
> > >   1 file changed, 52 insertions(+), 9 deletions(-)
> > > 
> > > diff --git a/debugfs/logdump.c b/debugfs/logdump.c
> > > index 324ed42..a1256c4 100644
> > > --- a/debugfs/logdump.c
> > > +++ b/debugfs/logdump.c
> > > @@ -47,7 +47,7 @@ enum journal_location {JOURNAL_IS_INTERNAL,
> > > JOURNAL_IS_EXTERNAL};
> > > 
> > >   #define ANY_BLOCK ((blk64_t) -1)
> > > 
> > > -static int		dump_all, dump_super, dump_old, dump_contents,
> > > dump_descriptors;
> > > +static int		dump_all, dump_super, dump_old, dump_contents,
> > > dump_descriptors, dump_time;
> > >   static int64_t		dump_counts;
> > >   static blk64_t		block_to_dump, bitmap_to_dump, inode_block_to_dump;
> > >   static unsigned int	group_to_dump, inode_offset_to_dump;
> > > @@ -67,6 +67,8 @@ static void dump_descriptor_block(FILE *, struct
> > > journal_source *,
> > >   				  char *, journal_superblock_t *,
> > >   				  unsigned int *, unsigned int, __u32, tid_t);
> > > 
> > > +static void dump_commit_time(FILE *out_file, char *buf);
> > > +
> > >   static void dump_revoke_block(FILE *, char *, journal_superblock_t *,
> > >   				  unsigned int, unsigned int, tid_t);
> > > 
> > > @@ -118,10 +120,11 @@ void do_logdump(int argc, ss_argv_t argv, int sci_idx
> > > EXT2FS_ATTR((unused)),
> > >   	inode_block_to_dump = ANY_BLOCK;
> > >   	inode_to_dump = -1;
> > >   	dump_counts = -1;
> > > +	dump_time = 0;
> > >   	wrapped_flag = false;
> > > 
> > >   	reset_getopt();
> > > -	while ((c = getopt (argc, argv, "ab:ci:f:OsSn:")) != EOF) {
> > > +	while ((c = getopt (argc, argv, "ab:ci:f:OsSn:t")) != EOF) {
> > >   		switch (c) {
> > >   		case 'a':
> > >   			dump_all++;
> > > @@ -162,6 +165,9 @@ void do_logdump(int argc, ss_argv_t argv, int sci_idx
> > > EXT2FS_ATTR((unused)),
> > >   				return;
> > >   			}
> > >   			break;
> > > +		case 't':
> > > +			dump_time++;
> > > +			break;
> > >   		default:
> > >   			goto print_usage;
> > >   		}
> > > @@ -521,21 +527,33 @@ static void dump_journal(char *cmdname, FILE
> > > *out_file,
> > >   				break;
> > >   		}
> > > 
> > > -		if (dump_descriptors) {
> > > -			fprintf (out_file, "Found expected sequence %u, "
> > > -				 "type %u (%s) at block %u\n",
> > > -				 sequence, blocktype,
> > > -				 type_to_name(blocktype), blocknr);
> > > -		}
> > > -
> > >   		switch (blocktype) {
> > >   		case JBD2_DESCRIPTOR_BLOCK:
> > > +			if (dump_descriptors) {
> > > +				fprintf (out_file, "Found expected sequence %u, "
> > > +					 "type %u (%s) at block %u\n",
> > > +					 sequence, blocktype,
> > > +					 type_to_name(blocktype), blocknr);
> > > +			}
> > > +
> > >   			dump_descriptor_block(out_file, source, buf, jsb,
> > >   					      &blocknr, blocksize, maxlen,
> > >   					      transaction);
> > >   			continue;
> > > 
> > >   		case JBD2_COMMIT_BLOCK:
> > > +			if (dump_descriptors) {
> > > +				fprintf (out_file, "Found expected sequence %u, "
> > > +					 "type %u (%s) at block %u",
> > > +					 sequence, blocktype,
> > > +					 type_to_name(blocktype), blocknr);
> > > +			}
> > > +
> > > +			if (dump_time)
> > > +				dump_commit_time(out_file, buf);
> > > +			else
> > > +				fprintf(out_file, "\n");
> > > +
> > >   			cur_counts++;
> > >   			transaction++;
> > >   			blocknr++;
> > > @@ -543,6 +561,13 @@ static void dump_journal(char *cmdname, FILE *out_file,
> > >   			continue;
> > > 
> > >   		case JBD2_REVOKE_BLOCK:
> > > +			if (dump_descriptors) {
> > > +				fprintf (out_file, "Found expected sequence %u, "
> > > +					 "type %u (%s) at block %u\n",
> > > +					 sequence, blocktype,
> > > +					 type_to_name(blocktype), blocknr);
> > > +			}
> > > +
> > >   			dump_revoke_block(out_file, buf, jsb,
> > >   					  blocknr, blocksize,
> > >   					  transaction);
> > > @@ -742,6 +767,24 @@ static void dump_descriptor_block(FILE *out_file,
> > >   	*blockp = blocknr;
> > >   }
> > > 
> > > +static void dump_commit_time(FILE *out_file, char *buf)
> > > +{
> > > +	struct commit_header	*header;
> > > +	uint64_t	commit_sec;
> > > +	time_t		timestamp;
> > > +	char		time_buffer[26];
> > > +	char		*result;
> > > +
> > > +	header = (struct commit_header *)buf;
> > > +	commit_sec = be64_to_cpu(header->h_commit_sec);
> > > +
> > > +	timestamp = commit_sec;
> > > +	result = ctime_r(&timestamp, time_buffer);
> > > +	if (result)
> > > +		fprintf(out_file, ", commit at: %s", time_buffer);
> > 
> > Nit: missing newline in this fprintf... or you could delete the newline
> > below and change the callsite to:
> > 
> > 	if (dump_time)
> > 		dump_commit_time(out_file, buf);
> > 	fprintf(out_file, "\n");
> > 
> 
> In my test environment, the string generated by ctime_r comes with a
> newline character at the end.

Oh, I guess that /is/ in the manpage:

	Broken-down time is stored in the structure tm, described in
	tm(3type).

	The call ctime(t) is equivalent to asctime(localtime(t)).  It
	converts the calendar time t into a null-terminated string of
	the form

           "Wed Jun 30 21:49:08 1993\n"

and then POSIX has this to say about asctime():

	The asctime() function shall convert the broken-down time in the
	structure pointed to by timeptr into a string in the form:

	Sun Sep 16 01:03:52 1973\n\0

which is also in ISO C23:

	The asctime function converts the broken-down time in the
	structure pointed to by timeptr into a string in the form:

	Sun Sep 16 01:03:52 1973\n\0

	using the equivalent of the following algorithm.

Sigh.

Reviewed-by: "Darrick J. Wong" <djwong@kernel.org>

--D

> Thanks,
>  - bin.
> 
> > > +	else
> > > +		fprintf(out_file, ", commit_sec is %llu\n", commit_sec);
> > 
> > Hm?
> > 
> > (Everything else in the patch looks ok to me)
> > 
> > --D
> > 
> > > +}
> > > 
> > >   static void dump_revoke_block(FILE *out_file, char *buf,
> > >   			      journal_superblock_t *jsb EXT2FS_ATTR((unused)),
> > > -- 
> > > 2.33.0
> > > 
> > > 
> > 
> > .
> >