aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorTheodore Ts'o <tytso@mit.edu>2013-01-02 22:43:36 -0500
committerTheodore Ts'o <tytso@mit.edu>2013-01-03 09:03:53 -0500
commit1eb31c4885156b595e6ceb4516cb1e1fb2d251fd (patch)
tree421880392d65e7225e715576dba3463bece7c931
parent2279fd78fe875e612ff998fe658a2c18ee13c66b (diff)
downloade2fsprogs-1eb31c4885156b595e6ceb4516cb1e1fb2d251fd.tar.gz
e2fsprogs-1eb31c4885156b595e6ceb4516cb1e1fb2d251fd.tar.xz
e2fsprogs-1eb31c4885156b595e6ceb4516cb1e1fb2d251fd.zip
resize2fs: add resource tracking as a debug option
Add a new debug flag which prints how much time is consumed by the various parts of resize2fs's processing. Signed-off-by: "Theodore Ts'o" <tytso@mit.edu>
-rw-r--r--resize/Makefile.in27
-rw-r--r--resize/resize2fs.8.in2
-rw-r--r--resize/resize2fs.c50
-rw-r--r--resize/resize2fs.h22
-rw-r--r--resize/resource_track.c128
5 files changed, 213 insertions, 16 deletions
diff --git a/resize/Makefile.in b/resize/Makefile.in
index b2739ac1..a06b642b 100644
--- a/resize/Makefile.in
+++ b/resize/Makefile.in
@@ -16,7 +16,8 @@ PROGS= resize2fs
TEST_PROGS= test_extent
MANPAGES= resize2fs.8
-RESIZE_OBJS= extent.o resize2fs.o main.o online.o sim_progress.o
+RESIZE_OBJS= extent.o resize2fs.o main.o online.o resource_track.o \
+ sim_progress.o
TEST_EXTENT_OBJS= extent.o test_extent.o
@@ -24,6 +25,7 @@ SRCS= $(srcdir)/extent.c \
$(srcdir)/resize2fs.c \
$(srcdir)/main.c \
$(srcdir)/online.c \
+ $(srcdir)/resource_track.c \
$(srcdir)/sim_progress.c
LIBS= $(LIBE2P) $(LIBEXT2FS) $(LIBCOM_ERR) $(LIBINTL)
@@ -144,35 +146,48 @@ source_tar_file: $(top_srcdir)/.exclude-file
# Makefile dependencies follow. This must be the last section in
# the Makefile.in file
#
-extent.o: $(srcdir)/extent.c $(srcdir)/resize2fs.h \
+extent.o: $(srcdir)/extent.c $(top_builddir)/lib/config.h \
+ $(top_builddir)/lib/dirpaths.h $(srcdir)/resize2fs.h \
$(top_srcdir)/lib/ext2fs/ext2_fs.h $(top_builddir)/lib/ext2fs/ext2_types.h \
$(top_srcdir)/lib/ext2fs/ext2fs.h $(top_srcdir)/lib/ext2fs/ext3_extents.h \
$(top_srcdir)/lib/et/com_err.h $(top_srcdir)/lib/ext2fs/ext2_io.h \
$(top_builddir)/lib/ext2fs/ext2_err.h \
$(top_srcdir)/lib/ext2fs/ext2_ext_attr.h $(top_srcdir)/lib/ext2fs/bitops.h \
$(top_srcdir)/lib/e2p/e2p.h
-resize2fs.o: $(srcdir)/resize2fs.c $(srcdir)/resize2fs.h \
+resize2fs.o: $(srcdir)/resize2fs.c $(top_builddir)/lib/config.h \
+ $(top_builddir)/lib/dirpaths.h $(srcdir)/resize2fs.h \
$(top_srcdir)/lib/ext2fs/ext2_fs.h $(top_builddir)/lib/ext2fs/ext2_types.h \
$(top_srcdir)/lib/ext2fs/ext2fs.h $(top_srcdir)/lib/ext2fs/ext3_extents.h \
$(top_srcdir)/lib/et/com_err.h $(top_srcdir)/lib/ext2fs/ext2_io.h \
$(top_builddir)/lib/ext2fs/ext2_err.h \
$(top_srcdir)/lib/ext2fs/ext2_ext_attr.h $(top_srcdir)/lib/ext2fs/bitops.h \
$(top_srcdir)/lib/e2p/e2p.h
-main.o: $(srcdir)/main.c $(top_srcdir)/lib/e2p/e2p.h \
+main.o: $(srcdir)/main.c $(top_builddir)/lib/config.h \
+ $(top_builddir)/lib/dirpaths.h $(top_srcdir)/lib/e2p/e2p.h \
$(top_srcdir)/lib/ext2fs/ext2_fs.h $(top_builddir)/lib/ext2fs/ext2_types.h \
$(srcdir)/resize2fs.h $(top_srcdir)/lib/ext2fs/ext2fs.h \
$(top_srcdir)/lib/ext2fs/ext3_extents.h $(top_srcdir)/lib/et/com_err.h \
$(top_srcdir)/lib/ext2fs/ext2_io.h $(top_builddir)/lib/ext2fs/ext2_err.h \
$(top_srcdir)/lib/ext2fs/ext2_ext_attr.h $(top_srcdir)/lib/ext2fs/bitops.h \
$(top_srcdir)/version.h
-online.o: $(srcdir)/online.c $(srcdir)/resize2fs.h \
+online.o: $(srcdir)/online.c $(top_builddir)/lib/config.h \
+ $(top_builddir)/lib/dirpaths.h $(srcdir)/resize2fs.h \
$(top_srcdir)/lib/ext2fs/ext2_fs.h $(top_builddir)/lib/ext2fs/ext2_types.h \
$(top_srcdir)/lib/ext2fs/ext2fs.h $(top_srcdir)/lib/ext2fs/ext3_extents.h \
$(top_srcdir)/lib/et/com_err.h $(top_srcdir)/lib/ext2fs/ext2_io.h \
$(top_builddir)/lib/ext2fs/ext2_err.h \
$(top_srcdir)/lib/ext2fs/ext2_ext_attr.h $(top_srcdir)/lib/ext2fs/bitops.h \
$(top_srcdir)/lib/e2p/e2p.h
-sim_progress.o: $(srcdir)/sim_progress.c $(srcdir)/resize2fs.h \
+resource_track.o: $(srcdir)/resource_track.c $(top_builddir)/lib/config.h \
+ $(top_builddir)/lib/dirpaths.h $(srcdir)/resize2fs.h \
+ $(top_srcdir)/lib/ext2fs/ext2_fs.h $(top_builddir)/lib/ext2fs/ext2_types.h \
+ $(top_srcdir)/lib/ext2fs/ext2fs.h $(top_srcdir)/lib/ext2fs/ext3_extents.h \
+ $(top_srcdir)/lib/et/com_err.h $(top_srcdir)/lib/ext2fs/ext2_io.h \
+ $(top_builddir)/lib/ext2fs/ext2_err.h \
+ $(top_srcdir)/lib/ext2fs/ext2_ext_attr.h $(top_srcdir)/lib/ext2fs/bitops.h \
+ $(top_srcdir)/lib/e2p/e2p.h
+sim_progress.o: $(srcdir)/sim_progress.c $(top_builddir)/lib/config.h \
+ $(top_builddir)/lib/dirpaths.h $(srcdir)/resize2fs.h \
$(top_srcdir)/lib/ext2fs/ext2_fs.h $(top_builddir)/lib/ext2fs/ext2_types.h \
$(top_srcdir)/lib/ext2fs/ext2fs.h $(top_srcdir)/lib/ext2fs/ext3_extents.h \
$(top_srcdir)/lib/et/com_err.h $(top_srcdir)/lib/ext2fs/ext2_io.h \
diff --git a/resize/resize2fs.8.in b/resize/resize2fs.8.in
index 9ff6e0a0..735fc917 100644
--- a/resize/resize2fs.8.in
+++ b/resize/resize2fs.8.in
@@ -99,6 +99,8 @@ from the following list:
4 \-\ Debug inode relocations
.br
8 \-\ Debug moving the inode table
+.br
+ 16 \-\ Print timing information
.TP
.B \-f
Forces resize2fs to proceed with the filesystem resize operation, overriding
diff --git a/resize/resize2fs.c b/resize/resize2fs.c
index d9501f92..f6a52e52 100644
--- a/resize/resize2fs.c
+++ b/resize/resize2fs.c
@@ -74,14 +74,7 @@ errcode_t resize_fs(ext2_filsys fs, blk64_t *new_size, int flags,
{
ext2_resize_t rfs;
errcode_t retval;
-
- retval = ext2fs_read_bitmaps(fs);
- if (retval)
- return retval;
-
- fs->super->s_state |= EXT2_ERROR_FS;
- ext2fs_mark_super_dirty(fs);
- ext2fs_flush(fs);
+ struct resource_track rtrack, overall_track;
/*
* Create the data structure
@@ -89,32 +82,53 @@ errcode_t resize_fs(ext2_filsys fs, blk64_t *new_size, int flags,
retval = ext2fs_get_mem(sizeof(struct ext2_resize_struct), &rfs);
if (retval)
return retval;
- memset(rfs, 0, sizeof(struct ext2_resize_struct));
- fix_uninit_block_bitmaps(fs);
+ memset(rfs, 0, sizeof(struct ext2_resize_struct));
fs->priv_data = rfs;
rfs->old_fs = fs;
rfs->flags = flags;
rfs->itable_buf = 0;
rfs->progress = progress;
+
+ init_resource_track(&overall_track, "overall resize2fs", fs->io);
+ init_resource_track(&rtrack, "read_bitmaps", fs->io);
+ retval = ext2fs_read_bitmaps(fs);
+ if (retval)
+ goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+
+ fs->super->s_state |= EXT2_ERROR_FS;
+ ext2fs_mark_super_dirty(fs);
+ ext2fs_flush(fs);
+
+ init_resource_track(&rtrack, "fix_uninit_block_bitmaps 1", fs->io);
+ fix_uninit_block_bitmaps(fs);
+ print_resource_track(rfs, &rtrack, fs->io);
retval = ext2fs_dup_handle(fs, &rfs->new_fs);
if (retval)
goto errout;
+ init_resource_track(&rtrack, "adjust_superblock", fs->io);
retval = adjust_superblock(rfs, *new_size);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+
+ init_resource_track(&rtrack, "fix_uninit_block_bitmaps 2", fs->io);
fix_uninit_block_bitmaps(rfs->new_fs);
+ print_resource_track(rfs, &rtrack, fs->io);
/* Clear the block bitmap uninit flag for the last block group */
ext2fs_bg_flags_clear(rfs->new_fs, rfs->new_fs->group_desc_count - 1,
EXT2_BG_BLOCK_UNINIT);
*new_size = ext2fs_blocks_count(rfs->new_fs->super);
+ init_resource_track(&rtrack, "blocks_to_move", fs->io);
retval = blocks_to_move(rfs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
#ifdef RESIZE2FS_DEBUG
if (rfs->flags & RESIZE_DEBUG_BMOVE)
@@ -124,36 +138,52 @@ errcode_t resize_fs(ext2_filsys fs, blk64_t *new_size, int flags,
rfs->needed_blocks);
#endif
+ init_resource_track(&rtrack, "block_mover", fs->io);
retval = block_mover(rfs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+ init_resource_track(&rtrack, "inode_scan_and_fix", fs->io);
retval = inode_scan_and_fix(rfs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+ init_resource_track(&rtrack, "inode_ref_fix", fs->io);
retval = inode_ref_fix(rfs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+ init_resource_track(&rtrack, "move_itables", fs->io);
retval = move_itables(rfs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+ init_resource_track(&rtrack, "calculate_summary_stats", fs->io);
retval = ext2fs_calculate_summary_stats(rfs->new_fs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+ init_resource_track(&rtrack, "fix_resize_inode", fs->io);
retval = fix_resize_inode(rfs->new_fs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
+ init_resource_track(&rtrack, "fix_sb_journal_backup", fs->io);
retval = fix_sb_journal_backup(rfs->new_fs);
if (retval)
goto errout;
+ print_resource_track(rfs, &rtrack, fs->io);
rfs->new_fs->super->s_state &= ~EXT2_ERROR_FS;
rfs->new_fs->flags &= ~EXT2_FLAG_MASTER_SB_ONLY;
+
+ print_resource_track(rfs, &overall_track, fs->io);
retval = ext2fs_close(rfs->new_fs);
if (retval)
goto errout;
diff --git a/resize/resize2fs.h b/resize/resize2fs.h
index 21847593..d425491d 100644
--- a/resize/resize2fs.h
+++ b/resize/resize2fs.h
@@ -76,11 +76,26 @@ typedef struct ext2_sim_progress *ext2_sim_progmeter;
#define RESIZE_DEBUG_BMOVE 0x0002
#define RESIZE_DEBUG_INODEMAP 0x0004
#define RESIZE_DEBUG_ITABLEMOVE 0x0008
+#define RESIZE_DEBUG_RTRACK 0x0010
#define RESIZE_PERCENT_COMPLETE 0x0100
#define RESIZE_VERBOSE 0x0200
/*
+ * This structure is used for keeping track of how much resources have
+ * been used for a particular resize2fs pass.
+ */
+struct resource_track {
+ const char *desc;
+ struct timeval time_start;
+ struct timeval user_start;
+ struct timeval system_start;
+ void *brk_start;
+ unsigned long long bytes_read;
+ unsigned long long bytes_written;
+};
+
+/*
* The core state structure for the ext2 resizer
*/
typedef struct ext2_resize_struct *ext2_resize_t;
@@ -148,6 +163,13 @@ extern errcode_t ext2fs_iterate_extent(ext2_extent extent, __u64 *old_loc,
extern errcode_t online_resize_fs(ext2_filsys fs, const char *mtpt,
blk64_t *new_size, int flags);
+/* resource_track.c */
+extern void init_resource_track(struct resource_track *track, const char *desc,
+ io_channel channel);
+extern void print_resource_track(ext2_resize_t rfs,
+ struct resource_track *track,
+ io_channel channel);
+
/* sim_progress.c */
extern errcode_t ext2fs_progress_init(ext2_sim_progmeter *ret_prog,
const char *label,
diff --git a/resize/resource_track.c b/resize/resource_track.c
new file mode 100644
index 00000000..f0efe114
--- /dev/null
+++ b/resize/resource_track.c
@@ -0,0 +1,128 @@
+/*
+ * resource_track.c --- resource tracking
+ *
+ * Copyright (C) 2013 by Theodore Ts'o
+ *
+ * %Begin-Header%
+ * This file may be redistributed under the terms of the GNU Public
+ * License.
+ * %End-Header%
+ */
+
+
+#include "config.h"
+#include "resize2fs.h"
+#include <time.h>
+#ifdef HAVE_MALLOC_H
+#include <malloc.h>
+#endif
+#include <sys/resource.h>
+
+void init_resource_track(struct resource_track *track, const char *desc,
+ io_channel channel)
+{
+#ifdef HAVE_GETRUSAGE
+ struct rusage r;
+#endif
+ io_stats io_start = 0;
+
+ track->desc = desc;
+ track->brk_start = sbrk(0);
+ gettimeofday(&track->time_start, 0);
+#ifdef HAVE_GETRUSAGE
+#ifdef sun
+ memset(&r, 0, sizeof(struct rusage));
+#endif
+ getrusage(RUSAGE_SELF, &r);
+ track->user_start = r.ru_utime;
+ track->system_start = r.ru_stime;
+#else
+ track->user_start.tv_sec = track->user_start.tv_usec = 0;
+ track->system_start.tv_sec = track->system_start.tv_usec = 0;
+#endif
+ track->bytes_read = 0;
+ track->bytes_written = 0;
+ if (channel && channel->manager && channel->manager->get_stats)
+ channel->manager->get_stats(channel, &io_start);
+ if (io_start) {
+ track->bytes_read = io_start->bytes_read;
+ track->bytes_written = io_start->bytes_written;
+ }
+}
+
+static float timeval_subtract(struct timeval *tv1,
+ struct timeval *tv2)
+{
+ return ((tv1->tv_sec - tv2->tv_sec) +
+ ((float) (tv1->tv_usec - tv2->tv_usec)) / 1000000);
+}
+
+void print_resource_track(ext2_resize_t rfs, struct resource_track *track,
+ io_channel channel)
+{
+#ifdef HAVE_GETRUSAGE
+ struct rusage r;
+#endif
+#ifdef HAVE_MALLINFO
+ struct mallinfo malloc_info;
+#endif
+ struct timeval time_end;
+
+ if ((rfs->flags & RESIZE_DEBUG_RTRACK) == 0)
+ return;
+
+ gettimeofday(&time_end, 0);
+
+ if (track->desc)
+ printf("%s: ", track->desc);
+
+#ifdef HAVE_MALLINFO
+#define kbytes(x) (((unsigned long)(x) + 1023) / 1024)
+
+ malloc_info = mallinfo();
+ printf("Memory used: %luk/%luk (%luk/%luk), ",
+ kbytes(malloc_info.arena), kbytes(malloc_info.hblkhd),
+ kbytes(malloc_info.uordblks), kbytes(malloc_info.fordblks));
+#else
+ printf("Memory used: %lu, ",
+ (unsigned long) (((char *) sbrk(0)) -
+ ((char *) track->brk_start)));
+#endif
+#ifdef HAVE_GETRUSAGE
+ getrusage(RUSAGE_SELF, &r);
+
+ printf("time: %5.2f/%5.2f/%5.2f\n",
+ timeval_subtract(&time_end, &track->time_start),
+ timeval_subtract(&r.ru_utime, &track->user_start),
+ timeval_subtract(&r.ru_stime, &track->system_start));
+#else
+ printf("elapsed time: %6.3f\n",
+ timeval_subtract(&time_end, &track->time_start));
+#endif
+#define mbytes(x) (((x) + 1048575) / 1048576)
+ if (channel && channel->manager && channel->manager->get_stats) {
+ io_stats delta = 0;
+ unsigned long long bytes_read = 0;
+ unsigned long long bytes_written = 0;
+
+ channel->manager->get_stats(channel, &delta);
+ if (delta) {
+ bytes_read = delta->bytes_read - track->bytes_read;
+ bytes_written = delta->bytes_written -
+ track->bytes_written;
+ if (bytes_read == 0 && bytes_written == 0)
+ goto skip_io;
+ if (track->desc)
+ printf("%s: ", track->desc);
+ printf("I/O read: %lluMB, write: %lluMB, "
+ "rate: %.2fMB/s\n",
+ mbytes(bytes_read),
+ mbytes(bytes_written),
+ (double)mbytes(bytes_read + bytes_written) /
+ timeval_subtract(&time_end, &track->time_start));
+ }
+ }
+skip_io:
+ fflush(stdout);
+}
+