Some 64-bit tests

Some 64-bit tests

[Nick Dokos]

I built and ran e2fsprogs bits from the pu branch from last week
(not including the changes that you made yesterday.)

The basic cycle of mkfs/fill up the fs/fsck seemed to work without
fatal errors but there are several problematic points.

The mkfs looked like this:

,----
| $ sudo time mke2fs -q -t ext4 -O ^resize_inode -E stride=32,stripe-width=512 /dev/mapper/bigvg-bigvol
| 64.02user 722.30system 13:14.25elapsed 99%CPU (0avgtext+0avgdata 0maxresident)k
| 1240inputs+1026586096outputs (6major+317202minor)pagefaults 0swaps
`----

I then ran the Lustre test that Andreas posted:

,----
| $ sudo time ~/src/tools/lustre/liverfs -l -r -w /mnt
| Timestamp: 1243984976
| -- 0:bash -- time-stamp -- Jun/02/09 19:24:49 --
| -- 0:bash -- time-stamp -- Jun/03/09  9:42:50 --
| write File name: /mnt/dir00240/file020          
| write complete
| 
| liverfs: writing /mnt/liverfs.filecount failed :No space left on device
| -- 0:bash -- time-stamp -- Jun/03/09  9:44:41 --
| -- 0:bash -- time-stamp -- Jun/03/09 12:11:14 --
| 
| -- 0:bash -- time-stamp -- Jun/03/09 12:13:10 --
| -- 0:bash -- time-stamp -- Jun/04/09  2:39:01 --
| 374.48user 87720.31system 31:16:05elapsed 78%CPU (0avgtext+0avgdata 0maxresident)k
| 64604538992inputs+64670728952outputs (3major+460minor)pagefaults 0swaps
`----

roughly 14 hours to write and 17 hours to read everything back (the
ENOSPC error message is an artifact of the program and does not affect
the rest of the run). liverfs performs some consistency checking on the
contents of the files, so the fact that it did not find anything wrong
is encouraging.

It created 241 directories, each with 32 4GiB files in it (except the last
one, which had 20 files). That comes out to about 30TiB which is OK.

The fsck looks like this:

,----
| root@shifter:~/src/tests/2009/06-03# e2fsck -t -t -n -f /dev/mapper/bigvg-bigvol
| e2fsck 1.41.6 (30-May-2009)
| Pass 1: Checking inodes, blocks, and sizes
| Pass 1: Memory used: 31180k/18014398507629424k (31004k/177k), time: 384.17/294.25/ 2.24
| Pass 1: I/O read: 63MB, write: 0MB, rate: 0.16MB/s
| Pass 2: Checking directory structure
| Pass 2: Memory used: 31180k/18014398508200200k (30993k/188k), time:  1.00/ 0.40/ 0.49
| Pass 2: I/O read: 1MB, write: 0MB, rate: 1.00MB/s
| Pass 3: Checking directory connectivity
| Peak memory: Memory used: 31180k/18014398508450540k (30993k/188k), time: 389.75/298.39/ 3.52
| Pass 3: Memory used: 31180k/18014398508200200k (30993k/188k), time:  0.28/ 0.12/ 0.16
| Pass 3: I/O read: 1MB, write: 0MB, rate: 3.53MB/s
| Pass 4: Checking reference counts
| Pass 4: Memory used: 31180k/1520628k (30993k/188k), time: 70.32/70.17/ 0.13
| Pass 4: I/O read: 0MB, write: 0MB, rate: 0.00MB/s
| Pass 5: Checking group summary information
| Pass 5: Memory used: 31212k/1270288k (30993k/220k), time: 409.82/270.69/ 5.29
| Pass 5: I/O read: 979MB, write: 0MB, rate: 2.39MB/s
| /dev/mapper/bigvg-bigvol: 7954/2050768896 files (0.0% non-contiguous), 8203066502/8203075584 blocks
| Memory used: 31212k/1270288k (30993k/220k), time: 869.92/639.26/ 8.96
| I/O read: 1058MB, write: 0MB, rate: 1.22MB/s
| 
| real	14m31.299s
| user	10m39.257s
| sys	0m10.336s
`----

The "-t -t" part of the reporting may be truncating large quantities,
and the "peaK" and "pass 3" memory seem bogus:

  Peak memory: Memory used: 31180k/18014398508450540k (30993k/188k), time: 389.75/298.39/ 3.52
  Pass 3: Memory used: 31180k/18014398508200200k (30993k/188k), time:  0.28/ 0.12/ 0.16

The box has "only" 256GiB of memory and about 36GB of swap.

In addition, filefrag seems to have some problems. It reports
that every file has about 512 extents (most of them exactly 512, but a
few with less than that -- as little as 205 -- and a few more with more
than that -- as much as 1155. Since the program is single threaded, and
nothing else is happening on the file system, I (naively?) expected
maximal extents allocated (iiuc, that's 128MiB - so I'd expect 32
extents for most of the files).

filefrag -v has problems:

# filefrag -v file010
Filesystem type is: ef53
File size of file010 is 4294967296 (1048576 blocks, blocksize 4096)
 ext logical  physical  expected length flags
   0       0  40931328             2048 
   1    2048  40951808  40933375   2048 
   2    4096  40970240  40953855   2048 
   3    6144  40988672  40972287   2048 
   4    8192  41007104  40990719   2048 
   5   10240  41027584  41009151   2048 
 ...   .....  ........  ........   ....

 217 1034240  49362944  49348607   2048 
 218 1036288  49379328  49364991   2048 
 219 1038336  49397760  49381375   2048 
 220 1040384  49414144  49399807   2048 
 221 1042432  49430528  49416191   2048 
 222 1044480  49446912  49432575   2048 
 223 1046528  49463296  49448959   2048 eof
file010: 224 extents found

# filefrag file010
file010: 512 extents found

I haven't had a chance to take a look with debugfs yet.

Thanks,
Nick

Re: Some 64-bit tests

[Valerie Aurora]

On Mon, Jun 08, 2009 at 09:57:21AM -0400, Nick Dokos wrote:
> I built and ran e2fsprogs bits from the pu branch from last week
> (not including the changes that you made yesterday.)
> 
> The basic cycle of mkfs/fill up the fs/fsck seemed to work without
> fatal errors but there are several problematic points.

That's great news!  Thanks.

> The mkfs looked like this:
> 
> ,----
> | $ sudo time mke2fs -q -t ext4 -O ^resize_inode -E stride=32,stripe-width=512 /dev/mapper/bigvg-bigvol
> | 64.02user 722.30system 13:14.25elapsed 99%CPU (0avgtext+0avgdata 0maxresident)k
> | 1240inputs+1026586096outputs (6major+317202minor)pagefaults 0swaps
> `----
> 
> I then ran the Lustre test that Andreas posted:
> 
> ,----
> | $ sudo time ~/src/tools/lustre/liverfs -l -r -w /mnt
> | Timestamp: 1243984976
> | -- 0:bash -- time-stamp -- Jun/02/09 19:24:49 --
> | -- 0:bash -- time-stamp -- Jun/03/09  9:42:50 --
> | write File name: /mnt/dir00240/file020          
> | write complete
> | 
> | liverfs: writing /mnt/liverfs.filecount failed :No space left on device
> | -- 0:bash -- time-stamp -- Jun/03/09  9:44:41 --
> | -- 0:bash -- time-stamp -- Jun/03/09 12:11:14 --
> | 
> | -- 0:bash -- time-stamp -- Jun/03/09 12:13:10 --
> | -- 0:bash -- time-stamp -- Jun/04/09  2:39:01 --
> | 374.48user 87720.31system 31:16:05elapsed 78%CPU (0avgtext+0avgdata 0maxresident)k
> | 64604538992inputs+64670728952outputs (3major+460minor)pagefaults 0swaps
> `----
> 
> roughly 14 hours to write and 17 hours to read everything back (the
> ENOSPC error message is an artifact of the program and does not affect
> the rest of the run). liverfs performs some consistency checking on the
> contents of the files, so the fact that it did not find anything wrong
> is encouraging.
> 
> It created 241 directories, each with 32 4GiB files in it (except the last
> one, which had 20 files). That comes out to about 30TiB which is OK.
> 
> The fsck looks like this:
> 
> ,----
> | root@shifter:~/src/tests/2009/06-03# e2fsck -t -t -n -f /dev/mapper/bigvg-bigvol
> | e2fsck 1.41.6 (30-May-2009)
> | Pass 1: Checking inodes, blocks, and sizes
> | Pass 1: Memory used: 31180k/18014398507629424k (31004k/177k), time: 384.17/294.25/ 2.24
> | Pass 1: I/O read: 63MB, write: 0MB, rate: 0.16MB/s
> | Pass 2: Checking directory structure
> | Pass 2: Memory used: 31180k/18014398508200200k (30993k/188k), time:  1.00/ 0.40/ 0.49
> | Pass 2: I/O read: 1MB, write: 0MB, rate: 1.00MB/s
> | Pass 3: Checking directory connectivity
> | Peak memory: Memory used: 31180k/18014398508450540k (30993k/188k), time: 389.75/298.39/ 3.52
> | Pass 3: Memory used: 31180k/18014398508200200k (30993k/188k), time:  0.28/ 0.12/ 0.16
> | Pass 3: I/O read: 1MB, write: 0MB, rate: 3.53MB/s
> | Pass 4: Checking reference counts
> | Pass 4: Memory used: 31180k/1520628k (30993k/188k), time: 70.32/70.17/ 0.13
> | Pass 4: I/O read: 0MB, write: 0MB, rate: 0.00MB/s
> | Pass 5: Checking group summary information
> | Pass 5: Memory used: 31212k/1270288k (30993k/220k), time: 409.82/270.69/ 5.29
> | Pass 5: I/O read: 979MB, write: 0MB, rate: 2.39MB/s
> | /dev/mapper/bigvg-bigvol: 7954/2050768896 files (0.0% non-contiguous), 8203066502/8203075584 blocks
> | Memory used: 31212k/1270288k (30993k/220k), time: 869.92/639.26/ 8.96
> | I/O read: 1058MB, write: 0MB, rate: 1.22MB/s
> | 
> | real	14m31.299s
> | user	10m39.257s
> | sys	0m10.336s
> `----
> 
> The "-t -t" part of the reporting may be truncating large quantities,
> and the "peaK" and "pass 3" memory seem bogus:
> 
>   Peak memory: Memory used: 31180k/18014398508450540k (30993k/188k), time: 389.75/298.39/ 3.52
>   Pass 3: Memory used: 31180k/18014398508200200k (30993k/188k), time:  0.28/ 0.12/ 0.16
> 
> The box has "only" 256GiB of memory and about 36GB of swap.

Part of this can be explained by overflow/wraparound/formatting bugs.
The bogus enormously large values look more like addresses than counters:

[val@fsbox ~]$ bc
bc 1.06
Copyright 1991-1994, 1997, 1998, 2000 Free Software Foundation, Inc.
This is free software with ABSOLUTELY NO WARRANTY.
For details type `warranty'.
obase=16
18014398507629424
3FFFFFFFE3BB70
18014398508200200
3FFFFFFFEC7108
18014398508450540
3FFFFFFFF042EC
18014398508200200
3FFFFFFFEC7108

> In addition, filefrag seems to have some problems. It reports
> that every file has about 512 extents (most of them exactly 512, but a
> few with less than that -- as little as 205 -- and a few more with more
> than that -- as much as 1155. Since the program is single threaded, and
> nothing else is happening on the file system, I (naively?) expected
> maximal extents allocated (iiuc, that's 128MiB - so I'd expect 32
> extents for most of the files).

Eric Sandeen (cc'd) is who I usually send ext4 file fragmentation
problems to.  In my experience, ext4 never allocates just one extent
for a file, but always exactly 512 sounds interesting.  Eric?

> filefrag -v has problems:
> 
> # filefrag -v file010
> Filesystem type is: ef53
> File size of file010 is 4294967296 (1048576 blocks, blocksize 4096)
>  ext logical  physical  expected length flags
>    0       0  40931328             2048 
>    1    2048  40951808  40933375   2048 
>    2    4096  40970240  40953855   2048 
>    3    6144  40988672  40972287   2048 
>    4    8192  41007104  40990719   2048 
>    5   10240  41027584  41009151   2048 
>  ...   .....  ........  ........   ....
> 
>  217 1034240  49362944  49348607   2048 
>  218 1036288  49379328  49364991   2048 
>  219 1038336  49397760  49381375   2048 
>  220 1040384  49414144  49399807   2048 
>  221 1042432  49430528  49416191   2048 
>  222 1044480  49446912  49432575   2048 
>  223 1046528  49463296  49448959   2048 eof
> file010: 224 extents found
> 
> # filefrag file010
> file010: 512 extents found

That ought to help a lot narrowing down the bug.

Thanks,

-VAL

Re: Some 64-bit tests

[Aneesh Kumar K.V]

Can you try this patch ?

commit 6a910bd1d28be09ba3a0e073bae78285ce057a5f
Author: Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com>
Date:   Tue Jun 9 01:38:53 2009 +0530

    ext4: Use different normalization method for allocation size.
    
    Signed-off-by: Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com>

diff --git a/fs/ext4/mballoc.c b/fs/ext4/mballoc.c
index ed8482e..7f2423b 100644
--- a/fs/ext4/mballoc.c
+++ b/fs/ext4/mballoc.c
@@ -633,7 +633,7 @@ static void ext4_mb_mark_free_simple(struct super_block *sb,
 
 	BUG_ON(len > EXT4_BLOCKS_PER_GROUP(sb));
 
-	border = 2 << sb->s_blocksize_bits;
+	border = 1 << (sb->s_blocksize_bits + 1);
 
 	while (len > 0) {
 		/* find how many blocks can be covered since this position */
@@ -3063,8 +3063,10 @@ static void ext4_mb_normalize_group_request(struct ext4_allocation_context *ac)
 ext4_mb_normalize_request(struct ext4_allocation_context *ac,
 				struct ext4_allocation_request *ar)
 {
-	int bsbits, max;
+	int bsbits, i;
+	loff_t max;
 	ext4_lblk_t end;
+	unsigned int s_mb_stream_request;
 	loff_t size, orig_size, start_off;
 	ext4_lblk_t start, orig_start;
 	struct ext4_inode_info *ei = EXT4_I(ac->ac_inode);
@@ -3090,54 +3092,52 @@ ext4_mb_normalize_request(struct ext4_allocation_context *ac,
 	}
 
 	bsbits = ac->ac_sb->s_blocksize_bits;
+	s_mb_stream_request = EXT4_SB(ac->ac_sb)->s_mb_stream_request;
+	/* make sure this is power of 2 */
+	s_mb_stream_request =
+		roundup_pow_of_two((unsigned long)s_mb_stream_request);
 
 	/* first, let's learn actual file size
 	 * given current request is allocated */
 	size = ac->ac_o_ex.fe_logical + ac->ac_o_ex.fe_len;
-	size = size << bsbits;
-	if (size < i_size_read(ac->ac_inode))
-		size = i_size_read(ac->ac_inode);
-
-	/* max size of free chunks */
-	max = 2 << bsbits;
+	if (size < (i_size_read(ac->ac_inode) >> bsbits))
+		size = i_size_read(ac->ac_inode) >> bsbits;
+	/*
+	 * max free chunk blocks. 
+	 * (max buddy cache order is (bsbits + 1).
+	 */
+	max = 1 << (bsbits + 1);
 
 #define NRL_CHECK_SIZE(req, size, max, chunk_size)	\
-		(req <= (size) || max <= (chunk_size))
+	(((req <= (size)) && (req <= (chunk_size))) || max <= (chunk_size))
 
 	/* first, try to predict filesize */
 	/* XXX: should this table be tunable? */
 	start_off = 0;
-	if (size <= 16 * 1024) {
-		size = 16 * 1024;
-	} else if (size <= 32 * 1024) {
-		size = 32 * 1024;
-	} else if (size <= 64 * 1024) {
-		size = 64 * 1024;
-	} else if (size <= 128 * 1024) {
-		size = 128 * 1024;
-	} else if (size <= 256 * 1024) {
-		size = 256 * 1024;
-	} else if (size <= 512 * 1024) {
-		size = 512 * 1024;
-	} else if (size <= 1024 * 1024) {
-		size = 1024 * 1024;
-	} else if (NRL_CHECK_SIZE(size, 4 * 1024 * 1024, max, 2 * 1024)) {
-		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
-						(21 - bsbits)) << 21;
-		size = 2 * 1024 * 1024;
-	} else if (NRL_CHECK_SIZE(size, 8 * 1024 * 1024, max, 4 * 1024)) {
-		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
-							(22 - bsbits)) << 22;
-		size = 4 * 1024 * 1024;
-	} else if (NRL_CHECK_SIZE(ac->ac_o_ex.fe_len,
-					(8<<20)>>bsbits, max, 8 * 1024)) {
-		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
-							(23 - bsbits)) << 23;
-		size = 8 * 1024 * 1024;
-	} else {
-		start_off = (loff_t)ac->ac_o_ex.fe_logical << bsbits;
-		size	  = ac->ac_o_ex.fe_len << bsbits;
+
+	/*
+	 * less than s_mb_stream_request is using locality group
+	 * preallocation
+	 */
+	if (size <= s_mb_stream_request)
+		size = s_mb_stream_request;
+	i = 4;
+	while (1) {
+		/*
+		 * if (size <= 4 * s_mb_stream ||
+		 * max <= 2 * s_mb_stream ) size = 2 * s_mb_stream
+		 */
+		if (NRL_CHECK_SIZE(size, i * s_mb_stream_request,
+					max, ((i * s_mb_stream_request) >> 1))) {
+			/* number of blocks */
+			size = (i * s_mb_stream_request) >> 1;
+			size = size << bsbits;
+			start_off = (loff_t)ac->ac_o_ex.fe_logical & ~(size - 1);
+			break;
+		}
+		i = i << 1;
 	}
+
 	orig_size = size = size >> bsbits;
 	orig_start = start = start_off >> bsbits;
 

Re: Some 64-bit tests

[Nick Dokos]

Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com> wrote:

> Can you try this patch ?
> 
> commit 6a910bd1d28be09ba3a0e073bae78285ce057a5f
> Author: Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com>
> Date:   Tue Jun 9 01:38:53 2009 +0530
> 
>     ext4: Use different normalization method for allocation size.
>     
>     Signed-off-by: Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com>
> 
> diff --git a/fs/ext4/mballoc.c b/fs/ext4/mballoc.c
> index ed8482e..7f2423b 100644
> --- a/fs/ext4/mballoc.c
> +++ b/fs/ext4/mballoc.c
> @@ -633,7 +633,7 @@ static void ext4_mb_mark_free_simple(struct super_block *sb,
>  
>  	BUG_ON(len > EXT4_BLOCKS_PER_GROUP(sb));
>  
> -	border = 2 << sb->s_blocksize_bits;
> +	border = 1 << (sb->s_blocksize_bits + 1);
>  
>  	while (len > 0) {
>  		/* find how many blocks can be covered since this position */
> @@ -3063,8 +3063,10 @@ static void ext4_mb_normalize_group_request(struct ext4_allocation_context *ac)
>  ext4_mb_normalize_request(struct ext4_allocation_context *ac,
>  				struct ext4_allocation_request *ar)
>  {
> -	int bsbits, max;
> +	int bsbits, i;
> +	loff_t max;
>  	ext4_lblk_t end;
> +	unsigned int s_mb_stream_request;
>  	loff_t size, orig_size, start_off;
>  	ext4_lblk_t start, orig_start;
>  	struct ext4_inode_info *ei = EXT4_I(ac->ac_inode);
> @@ -3090,54 +3092,52 @@ ext4_mb_normalize_request(struct ext4_allocation_context *ac,
>  	}
>  
>  	bsbits = ac->ac_sb->s_blocksize_bits;
> +	s_mb_stream_request = EXT4_SB(ac->ac_sb)->s_mb_stream_request;
> +	/* make sure this is power of 2 */
> +	s_mb_stream_request =
> +		roundup_pow_of_two((unsigned long)s_mb_stream_request);
>  
>  	/* first, let's learn actual file size
>  	 * given current request is allocated */
>  	size = ac->ac_o_ex.fe_logical + ac->ac_o_ex.fe_len;
> -	size = size << bsbits;
> -	if (size < i_size_read(ac->ac_inode))
> -		size = i_size_read(ac->ac_inode);
> -
> -	/* max size of free chunks */
> -	max = 2 << bsbits;
> +	if (size < (i_size_read(ac->ac_inode) >> bsbits))
> +		size = i_size_read(ac->ac_inode) >> bsbits;
> +	/*
> +	 * max free chunk blocks. 
> +	 * (max buddy cache order is (bsbits + 1).
> +	 */
> +	max = 1 << (bsbits + 1);
>  
>  #define NRL_CHECK_SIZE(req, size, max, chunk_size)	\
> -		(req <= (size) || max <= (chunk_size))
> +	(((req <= (size)) && (req <= (chunk_size))) || max <= (chunk_size))
>  
>  	/* first, try to predict filesize */
>  	/* XXX: should this table be tunable? */
>  	start_off = 0;
> -	if (size <= 16 * 1024) {
> -		size = 16 * 1024;
> -	} else if (size <= 32 * 1024) {
> -		size = 32 * 1024;
> -	} else if (size <= 64 * 1024) {
> -		size = 64 * 1024;
> -	} else if (size <= 128 * 1024) {
> -		size = 128 * 1024;
> -	} else if (size <= 256 * 1024) {
> -		size = 256 * 1024;
> -	} else if (size <= 512 * 1024) {
> -		size = 512 * 1024;
> -	} else if (size <= 1024 * 1024) {
> -		size = 1024 * 1024;
> -	} else if (NRL_CHECK_SIZE(size, 4 * 1024 * 1024, max, 2 * 1024)) {
> -		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
> -						(21 - bsbits)) << 21;
> -		size = 2 * 1024 * 1024;
> -	} else if (NRL_CHECK_SIZE(size, 8 * 1024 * 1024, max, 4 * 1024)) {
> -		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
> -							(22 - bsbits)) << 22;
> -		size = 4 * 1024 * 1024;
> -	} else if (NRL_CHECK_SIZE(ac->ac_o_ex.fe_len,
> -					(8<<20)>>bsbits, max, 8 * 1024)) {
> -		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
> -							(23 - bsbits)) << 23;
> -		size = 8 * 1024 * 1024;
> -	} else {
> -		start_off = (loff_t)ac->ac_o_ex.fe_logical << bsbits;
> -		size	  = ac->ac_o_ex.fe_len << bsbits;
> +
> +	/*
> +	 * less than s_mb_stream_request is using locality group
> +	 * preallocation
> +	 */
> +	if (size <= s_mb_stream_request)
> +		size = s_mb_stream_request;
> +	i = 4;
> +	while (1) {
> +		/*
> +		 * if (size <= 4 * s_mb_stream ||
> +		 * max <= 2 * s_mb_stream ) size = 2 * s_mb_stream
> +		 */
> +		if (NRL_CHECK_SIZE(size, i * s_mb_stream_request,
> +					max, ((i * s_mb_stream_request) >> 1))) {
> +			/* number of blocks */
> +			size = (i * s_mb_stream_request) >> 1;
> +			size = size << bsbits;
> +			start_off = (loff_t)ac->ac_o_ex.fe_logical & ~(size - 1);
> +			break;
> +		}
> +		i = i << 1;
>  	}
> +
>  	orig_size = size = size >> bsbits;
>  	orig_start = start = start_off >> bsbits;
>  

Aneesh,

I tried this on top of 2.6.30-rc8 and I hit a couple of BUGs, one in pdflush
and the other in the Lustre teest program (liverfs):

Jun  8 22:49:13 shifter kernel: ------------[ cut here ]------------
Jun  8 22:49:13 shifter kernel: kernel BUG at fs/ext4/mballoc.c:3245!
Jun  8 22:49:13 shifter kernel: invalid opcode: 0000 [#1] SMP 
Jun  8 22:49:13 shifter kernel: last sysfs file: /sys/devices/system/cpu/cpu15/cache/index2/shared_cpu_map
Jun  8 22:49:13 shifter kernel: CPU 4 
Jun  8 22:49:13 shifter kernel: Modules linked in: ext4 jbd2 crc16 bridge stp bnep sco l2cap bluetooth sunrpc ipv6 dm_multipath uinput pcspkr serio_raw bnx2 qla2xxx scsi_transport_fc scsi_tgt ipmi_si ipmi_msghandler ata_generic pata_acpi hpwdt pata_amd shpchp cciss [last unloaded: freq_table]
Jun  8 22:49:13 shifter kernel: Pid: 594, comm: pdflush Not tainted 2.6.30-rc8+aneesh.64-bit.patch #8 ProLiant DL585 G5   
Jun  8 22:49:13 shifter kernel: RIP: 0010:[<ffffffffa01be684>]  [<ffffffffa01be684>] ext4_mb_normalize_request+0x29a/0x313 [ext4]
Jun  8 22:49:13 shifter kernel: RSP: 0018:ffff88087c0ff7c0  EFLAGS: 00010246
Jun  8 22:49:13 shifter kernel: RAX: 0000000000002000 RBX: 0000000000000000 RCX: 0000000000002000
Jun  8 22:49:13 shifter kernel: RDX: 0000000000002000 RSI: 0000000000002000 RDI: 0000000000100000
Jun  8 22:49:13 shifter kernel: RBP: ffff88087c0ff800 R08: 0000000000000010 R09: 0000000000002000
Jun  8 22:49:13 shifter kernel: R10: 0000000000002000 R11: ffff88105c1087b0 R12: 0000000000002000
Jun  8 22:49:13 shifter kernel: R13: 0000000000002000 R14: ffff88039e0cf000 R15: 0000000000002000
Jun  8 22:49:13 shifter kernel: FS:  00007f5922f9b6f0(0000) GS:ffffc20000054000(0000) knlGS:0000000000000000
Jun  8 22:49:13 shifter kernel: CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
Jun  8 22:49:13 shifter kernel: CR2: 000000352fc33150 CR3: 00000008282a4000 CR4: 00000000000006e0
Jun  8 22:49:13 shifter kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jun  8 22:49:13 shifter kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jun  8 22:49:13 shifter kernel: Process pdflush (pid: 594, threadinfo ffff88087c0fe000, task ffff88087c100000)
Jun  8 22:49:13 shifter kernel: Stack:
Jun  8 22:49:13 shifter kernel: ffff88087c0ff800 ffff88087c0ff940 ffff88105c108a48 ffff88039e0cf000
Jun  8 22:49:13 shifter kernel: ffff88087c0ff940 0000000000000000 ffff88105c1087b0 ffff88105c1087b0
Jun  8 22:49:13 shifter kernel: ffff88087c0ff8a0 ffffffffa01c15c0 0000006000000008 ffff88105c108700
Jun  8 22:49:13 shifter kernel: Call Trace:
Jun  8 22:49:13 shifter kernel: [<ffffffffa01c15c0>] ext4_mb_new_blocks+0x1f8/0x4b0 [ext4]
Jun  8 22:49:13 shifter kernel: [<ffffffffa01b6d3d>] ? kzalloc+0xf/0x11 [ext4]
Jun  8 22:49:13 shifter kernel: [<ffffffffa01ba19f>] ext4_ext_get_blocks+0xc86/0xe93 [ext4]
Jun  8 22:49:13 shifter kernel: [<ffffffff81055b73>] ? up_read+0x9/0xb
Jun  8 22:49:13 shifter kernel: [<ffffffff8116852c>] ? generic_make_request+0x2b6/0x307
Jun  8 22:49:13 shifter kernel: [<ffffffffa01a8a4c>] ext4_get_blocks_wrap+0x109/0x253 [ext4]
Jun  8 22:49:13 shifter kernel: [<ffffffff8117b79e>] ? radix_tree_gang_lookup_tag_slot+0x85/0xaa
Jun  8 22:49:13 shifter kernel: [<ffffffffa01a8f08>] mpage_da_map_blocks+0xb0/0x5c2 [ext4]
Jun  8 22:49:13 shifter kernel: [<ffffffff8109cbbd>] ? __pagevec_release+0x21/0x2d
Jun  8 22:49:13 shifter kernel: [<ffffffff8109ac16>] ? write_cache_pages+0x311/0x39f
Jun  8 22:49:13 shifter kernel: [<ffffffffa01a99f1>] ? __mpage_da_writepage+0x0/0x135 [ext4]
Jun  8 22:49:13 shifter kernel: [<ffffffffa01a9750>] ext4_da_writepages+0x336/0x52c [ext4]
Jun  8 22:49:13 shifter kernel: [<ffffffff8109acf1>] do_writepages+0x28/0x38
Jun  8 22:49:13 shifter kernel: [<ffffffff810e001f>] __writeback_single_inode+0x194/0x325
Jun  8 22:49:13 shifter kernel: [<ffffffff810e058e>] generic_sync_sb_inodes+0x245/0x375
Jun  8 22:49:13 shifter kernel: [<ffffffff810e08a5>] writeback_inodes+0x9d/0xf0
Jun  8 22:49:13 shifter kernel: [<ffffffff8109b343>] background_writeout+0x92/0xcb
Jun  8 22:49:13 shifter kernel: [<ffffffff8109bb66>] pdflush+0x174/0x255
Jun  8 22:49:13 shifter kernel: [<ffffffff8109b2b1>] ? background_writeout+0x0/0xcb
Jun  8 22:49:13 shifter kernel: [<ffffffff8109b9f2>] ? pdflush+0x0/0x255
Jun  8 22:49:13 shifter kernel: [<ffffffff81052698>] kthread+0x56/0x83
Jun  8 22:49:13 shifter kernel: [<ffffffff8100cbea>] child_rip+0xa/0x20
Jun  8 22:49:13 shifter kernel: [<ffffffff8100c5e9>] ? restore_args+0x0/0x30
Jun  8 22:49:13 shifter kernel: [<ffffffff81052642>] ? kthread+0x0/0x83
Jun  8 22:49:13 shifter kernel: [<ffffffff8100cbe0>] ? child_rip+0x0/0x20
Jun  8 22:49:13 shifter kernel: Code: e1 41 8b 56 10 89 d0 49 39 c4 7f 09 41 39 d5 76 04 0f 0b eb fe 48 85 db 74 11 49 8b 7e 08 48 8b 87 a8 02 00 00 48 3b 58 10 76 04 <0f> 0b eb fe 48 8b 55 c8 45 89 6e 20 41 89 5e 2c 48 8b 72 30 48 
Jun  8 22:49:13 shifter kernel: RIP  [<ffffffffa01be684>] ext4_mb_normalize_request+0x29a/0x313 [ext4]
Jun  8 22:49:13 shifter kernel: RSP <ffff88087c0ff7c0>
Jun  8 22:49:13 shifter kernel: ---[ end trace a55a13c6b40b2ef7 ]---
Jun  8 22:49:26 shifter kernel: ------------[ cut here ]------------
Jun  8 22:49:26 shifter kernel: kernel BUG at fs/ext4/mballoc.c:3245!
Jun  8 22:49:26 shifter kernel: invalid opcode: 0000 [#2] SMP 
Jun  8 22:49:26 shifter kernel: last sysfs file: /sys/devices/system/cpu/cpu15/cache/index2/shared_cpu_map
Jun  8 22:49:26 shifter kernel: CPU 6 
Jun  8 22:49:26 shifter kernel: Modules linked in: ext4 jbd2 crc16 bridge stp bnep sco l2cap bluetooth sunrpc ipv6 dm_multipath uinput pcspkr serio_raw bnx2 qla2xxx scsi_transport_fc scsi_tgt ipmi_si ipmi_msghandler ata_generic pata_acpi hpwdt pata_amd shpchp cciss [last unloaded: freq_table]
Jun  8 22:49:26 shifter kernel: Pid: 4063, comm: liverfs Tainted: G      D    2.6.30-rc8+aneesh.64-bit.patch #8 ProLiant DL585 G5   
Jun  8 22:49:26 shifter kernel: RIP: 0010:[<ffffffffa01be684>]  [<ffffffffa01be684>] ext4_mb_normalize_request+0x29a/0x313 [ext4]
Jun  8 22:49:26 shifter kernel: RSP: 0018:ffff880820553488  EFLAGS: 00010246
Jun  8 22:49:26 shifter kernel: RAX: 0000000000002000 RBX: 0000000000000000 RCX: 0000000000002000
Jun  8 22:49:26 shifter kernel: RDX: 0000000000002000 RSI: 0000000000002000 RDI: 0000000000100000
Jun  8 22:49:26 shifter kernel: RBP: ffff8808205534c8 R08: 0000000000000010 R09: 0000000000002000
Jun  8 22:49:26 shifter kernel: R10: 0000000000002000 R11: ffff88105c108b30 R12: 0000000000002000
Jun  8 22:49:26 shifter kernel: R13: 0000000000002000 R14: ffff8816a4d1d000 R15: 0000000000002000
Jun  8 22:49:26 shifter kernel: FS:  00007fe0f59076f0(0000) GS:ffffc2000007e000(0000) knlGS:0000000000000000
Jun  8 22:49:26 shifter kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jun  8 22:49:26 shifter kernel: CR2: 00000000022d3060 CR3: 0000001d60b23000 CR4: 00000000000006e0
Jun  8 22:49:26 shifter kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jun  8 22:49:26 shifter kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jun  8 22:49:26 shifter kernel: Process liverfs (pid: 4063, threadinfo ffff880820552000, task ffff880874d5e3c0)
Jun  8 22:49:26 shifter kernel: Stack:
Jun  8 22:49:26 shifter kernel: ffff8808205534c8 ffff880820553608 ffff88105c108dc8 ffff8816a4d1d000
Jun  8 22:49:26 shifter kernel: ffff880820553608 0000000000000000 ffff88105c108b30 ffff88105c108b30
Jun  8 22:49:26 shifter kernel: ffff880820553568 ffffffffa01c15c0 0000006000010000 ffff88105c108a80
Jun  8 22:49:26 shifter kernel: Call Trace:
Jun  8 22:49:26 shifter kernel: [<ffffffffa01c15c0>] ext4_mb_new_blocks+0x1f8/0x4b0 [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffffa01b6d3d>] ? kzalloc+0xf/0x11 [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffffa01ba19f>] ext4_ext_get_blocks+0xc86/0xe93 [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffff81097bb5>] ? __rmqueue_smallest+0xff/0x142
Jun  8 22:49:26 shifter kernel: [<ffffffffa01a8a4c>] ext4_get_blocks_wrap+0x109/0x253 [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffff8117b79e>] ? radix_tree_gang_lookup_tag_slot+0x85/0xaa
Jun  8 22:49:26 shifter kernel: [<ffffffffa01a8f08>] mpage_da_map_blocks+0xb0/0x5c2 [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffff8109cbbd>] ? __pagevec_release+0x21/0x2d
Jun  8 22:49:26 shifter kernel: [<ffffffff8109ac16>] ? write_cache_pages+0x311/0x39f
Jun  8 22:49:26 shifter kernel: [<ffffffffa01a99f1>] ? __mpage_da_writepage+0x0/0x135 [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffffa01a9750>] ext4_da_writepages+0x336/0x52c [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffffa018d609>] ? do_get_write_access+0x43b/0x482 [jbd2]
Jun  8 22:49:26 shifter kernel: [<ffffffff8109acf1>] do_writepages+0x28/0x38
Jun  8 22:49:26 shifter kernel: [<ffffffff810e001f>] __writeback_single_inode+0x194/0x325
Jun  8 22:49:26 shifter kernel: [<ffffffff8117adbc>] ? prop_fraction_single+0x3c/0x5e
Jun  8 22:49:26 shifter kernel: [<ffffffff810e058e>] generic_sync_sb_inodes+0x245/0x375
Jun  8 22:49:26 shifter kernel: [<ffffffff810e08a5>] writeback_inodes+0x9d/0xf0
Jun  8 22:49:26 shifter kernel: [<ffffffff8109b562>] balance_dirty_pages_ratelimited_nr+0x152/0x27d
Jun  8 22:49:26 shifter kernel: [<ffffffffa01b4335>] ? __ext4_journal_stop+0x64/0x6a [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffff81094e36>] generic_file_buffered_write+0x1f4/0x2df
Jun  8 22:49:26 shifter kernel: [<ffffffff81095316>] __generic_file_aio_write_nolock+0x25e/0x292
Jun  8 22:49:26 shifter kernel: [<ffffffff81095340>] ? __generic_file_aio_write_nolock+0x288/0x292
Jun  8 22:49:26 shifter kernel: [<ffffffff81095b69>] generic_file_aio_write+0x67/0xc3
Jun  8 22:49:26 shifter kernel: [<ffffffffa01a29af>] ext4_file_write+0x9a/0x123 [ext4]
Jun  8 22:49:26 shifter kernel: [<ffffffff810c67de>] do_sync_write+0xe7/0x12d
Jun  8 22:49:26 shifter kernel: [<ffffffff81052d27>] ? remove_wait_queue+0x2f/0x38
Jun  8 22:49:26 shifter kernel: [<ffffffff81052a5c>] ? autoremove_wake_function+0x0/0x38
Jun  8 22:49:26 shifter kernel: [<ffffffff81146518>] ? security_file_permission+0x11/0x13
Jun  8 22:49:26 shifter kernel: [<ffffffff810c7204>] vfs_write+0xab/0x105
Jun  8 22:49:26 shifter kernel: [<ffffffff810c7322>] sys_write+0x47/0x6f
Jun  8 22:49:26 shifter kernel: [<ffffffff8100bbab>] system_call_fastpath+0x16/0x1b
Jun  8 22:49:26 shifter kernel: Code: e1 41 8b 56 10 89 d0 49 39 c4 7f 09 41 39 d5 76 04 0f 0b eb fe 48 85 db 74 11 49 8b 7e 08 48 8b 87 a8 02 00 00 48 3b 58 10 76 04 <0f> 0b eb fe 48 8b 55 c8 45 89 6e 20 41 89 5e 2c 48 8b 72 30 48 
Jun  8 22:49:26 shifter kernel: RIP  [<ffffffffa01be684>] ext4_mb_normalize_request+0x29a/0x313 [ext4]
Jun  8 22:49:26 shifter kernel: RSP <ffff880820553488>
Jun  8 22:49:26 shifter kernel: ---[ end trace a55a13c6b40b2ef8 ]---

Thanks,
Nick

Re: Some 64-bit tests

[Theodore Tso]

On Mon, Jun 08, 2009 at 11:13:48PM -0400, Nick Dokos wrote:
> 
> I tried this on top of 2.6.30-rc8 and I hit a couple of BUGs, one in pdflush
> and the other in the Lustre teest program (liverfs):
> 
> Jun  8 22:49:13 shifter kernel: ------------[ cut here ]------------
> Jun  8 22:49:13 shifter kernel: kernel BUG at fs/ext4/mballoc.c:3245!
> Jun  8 22:49:13 shifter kernel: invalid opcode: 0000 [#1] SMP 

Hmmm, that would be the BUG_ON check:

     BUG_ON(size <= 0 || size > EXT4_BLOCKS_PER_GROUP(ac->ac_sb));

						- Ted

Re: Some 64-bit tests

[Aneesh Kumar K.V]

On Wed, Jun 10, 2009 at 02:13:20PM -0400, Theodore Tso wrote:
> On Mon, Jun 08, 2009 at 11:13:48PM -0400, Nick Dokos wrote:
> > 
> > I tried this on top of 2.6.30-rc8 and I hit a couple of BUGs, one in pdflush
> > and the other in the Lustre teest program (liverfs):
> > 
> > Jun  8 22:49:13 shifter kernel: ------------[ cut here ]------------
> > Jun  8 22:49:13 shifter kernel: kernel BUG at fs/ext4/mballoc.c:3245!
> > Jun  8 22:49:13 shifter kernel: invalid opcode: 0000 [#1] SMP 
> 
> Hmmm, that would be the BUG_ON check:
> 
>      BUG_ON(size <= 0 || size > EXT4_BLOCKS_PER_GROUP(ac->ac_sb));
> 

I already have a RFC patch which Nick actually tested. It is giving 32MB
extents, which is expected because the max order in buddy cache is
blocksize_bits + 1. I have a Fixme in there regarding scaling the start
block which was hoping to fix soon.

Attaching the patch below.

commit f1fbc2ac43fefb6bac227fc995fe2b79c67ccfad
Author: Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com>
Date:   Tue Jun 9 01:38:53 2009 +0530

    ext4: Use different normalization method for allocation size.
    
    Signed-off-by: Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com>

diff --git a/fs/ext4/mballoc.c b/fs/ext4/mballoc.c
index ed8482e..9745b84 100644
--- a/fs/ext4/mballoc.c
+++ b/fs/ext4/mballoc.c
@@ -633,7 +633,7 @@ static void ext4_mb_mark_free_simple(struct super_block *sb,
 
 	BUG_ON(len > EXT4_BLOCKS_PER_GROUP(sb));
 
-	border = 2 << sb->s_blocksize_bits;
+	border = 1 << (sb->s_blocksize_bits + 1);
 
 	while (len > 0) {
 		/* find how many blocks can be covered since this position */
@@ -3063,8 +3063,10 @@ static void ext4_mb_normalize_group_request(struct ext4_allocation_context *ac)
 ext4_mb_normalize_request(struct ext4_allocation_context *ac,
 				struct ext4_allocation_request *ar)
 {
-	int bsbits, max;
+	loff_t max;
 	ext4_lblk_t end;
+	int bsbits, chunk_blks;
+	unsigned int s_mb_stream_request;
 	loff_t size, orig_size, start_off;
 	ext4_lblk_t start, orig_start;
 	struct ext4_inode_info *ei = EXT4_I(ac->ac_inode);
@@ -3090,54 +3092,61 @@ ext4_mb_normalize_request(struct ext4_allocation_context *ac,
 	}
 
 	bsbits = ac->ac_sb->s_blocksize_bits;
+	s_mb_stream_request = EXT4_SB(ac->ac_sb)->s_mb_stream_request;
+	/* make sure this is power of 2 */
+	s_mb_stream_request =
+		roundup_pow_of_two((unsigned long)s_mb_stream_request);
 
 	/* first, let's learn actual file size
 	 * given current request is allocated */
 	size = ac->ac_o_ex.fe_logical + ac->ac_o_ex.fe_len;
-	size = size << bsbits;
-	if (size < i_size_read(ac->ac_inode))
-		size = i_size_read(ac->ac_inode);
-
-	/* max size of free chunks */
-	max = 2 << bsbits;
+	if (size < (i_size_read(ac->ac_inode) >> bsbits))
+		size = i_size_read(ac->ac_inode) >> bsbits;
+	/*
+	 * max free chunk blocks.
+	 * (max buddy cache order is (bsbits + 1).
+	 */
+	max = 1 << (bsbits + 1);
 
-#define NRL_CHECK_SIZE(req, size, max, chunk_size)	\
-		(req <= (size) || max <= (chunk_size))
+	/*
+	 * If buddy cache says it can have more than
+	 * blocks per group then limit to blocks per group.
+	 */
+	if (max > EXT4_BLOCKS_PER_GROUP(ac->ac_sb))
+		max = EXT4_BLOCKS_PER_GROUP(ac->ac_sb);
 
 	/* first, try to predict filesize */
 	/* XXX: should this table be tunable? */
-	start_off = 0;
-	if (size <= 16 * 1024) {
-		size = 16 * 1024;
-	} else if (size <= 32 * 1024) {
-		size = 32 * 1024;
-	} else if (size <= 64 * 1024) {
-		size = 64 * 1024;
-	} else if (size <= 128 * 1024) {
-		size = 128 * 1024;
-	} else if (size <= 256 * 1024) {
-		size = 256 * 1024;
-	} else if (size <= 512 * 1024) {
-		size = 512 * 1024;
-	} else if (size <= 1024 * 1024) {
-		size = 1024 * 1024;
-	} else if (NRL_CHECK_SIZE(size, 4 * 1024 * 1024, max, 2 * 1024)) {
-		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
-						(21 - bsbits)) << 21;
-		size = 2 * 1024 * 1024;
-	} else if (NRL_CHECK_SIZE(size, 8 * 1024 * 1024, max, 4 * 1024)) {
-		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
-							(22 - bsbits)) << 22;
-		size = 4 * 1024 * 1024;
-	} else if (NRL_CHECK_SIZE(ac->ac_o_ex.fe_len,
-					(8<<20)>>bsbits, max, 8 * 1024)) {
-		start_off = ((loff_t)ac->ac_o_ex.fe_logical >>
-							(23 - bsbits)) << 23;
-		size = 8 * 1024 * 1024;
-	} else {
-		start_off = (loff_t)ac->ac_o_ex.fe_logical << bsbits;
-		size	  = ac->ac_o_ex.fe_len << bsbits;
+	/*
+	 * less than s_mb_stream_request is using
+	 * locality group preallocation
+	 */
+	if (size <= s_mb_stream_request) {
+		size = s_mb_stream_request << bsbits;
+		goto found_size;
+	}
+	chunk_blks = s_mb_stream_request << 1;
+	while (1) {
+		if (size <= chunk_blks) {
+			if (max <= chunk_blks)
+				size = max << bsbits;
+			else
+				size = chunk_blks << bsbits;
+			break;
+		}
+		chunk_blks = chunk_blks << 1;
 	}
+
+found_size:
+#if 0
+	/* Will i end up requesting for less that what i asked for ? */
+	start_off = (loff_t)(ac->ac_o_ex.fe_logical << bsbits) & ~(size - 1);
+	start_off = start_off * size;
+#else
+	start_off = (loff_t)(ac->ac_o_ex.fe_logical << bsbits);
+#endif
+
+	/* convert into blocks */
 	orig_size = size = size >> bsbits;
 	orig_start = start = start_off >> bsbits;
 
@@ -3216,6 +3225,10 @@ ext4_mb_normalize_request(struct ext4_allocation_context *ac,
 	}
 	BUG_ON(start + size <= ac->ac_o_ex.fe_logical &&
 			start > ac->ac_o_ex.fe_logical);
+
+	if (size <= 0 ||  size > EXT4_BLOCKS_PER_GROUP(ac->ac_sb))
+		printk(KERN_ALERT "size is %ld orig size is %ld\n", (long)size, (long)orig_size);
+
 	BUG_ON(size <= 0 || size > EXT4_BLOCKS_PER_GROUP(ac->ac_sb));
 
 	/* now prepare goal request */

Re: Some 64-bit tests

[Theodore Tso]

On Thu, Jun 11, 2009 at 11:20:06AM +0530, Aneesh Kumar K.V wrote:
> 
> I already have a RFC patch which Nick actually tested. It is giving 32MB
> extents, which is expected because the max order in buddy cache is
> blocksize_bits + 1. I have a Fixme in there regarding scaling the start
> block which was hoping to fix soon.

I've dropped this into the unstable section of the ext4 patch queue
for testing purposes.  It definitely does a better job, although first
extent tends to be 8MB, and then after that things tend to be
allocated in 32MB chunks.

						- Ted

   814(f): expecting  57344 actual extent phys  73728 log 16384 len 8192
   814(f): expecting  81920 actual extent phys  90112 log 24576 len 8192
   831(f): expecting  59392 actual extent phys  65536 log 2048 len 8192
   831(f): expecting  73728 actual extent phys  81920 log 10240 len 8192
   831(f): expecting  90112 actual extent phys 106496 log 18432 len 8192
   831(f): expecting 114688 actual extent phys 131072 log 26624 len 6144
   834(f): expecting  65536 actual extent phys 114688 log 4096 len 8192
   834(f): expecting 122880 actual extent phys 155648 log 12288 len 7
   838(f): expecting 102400 actual extent phys 147456 log 2048 len 3693
   839(f): expecting 147456 actual extent phys 180224 log 8192 len 8192
   839(f): expecting 188416 actual extent phys 196608 log 16384 len 2791
   849(f): expecting 155648 actual extent phys 188416 log 4096 len 8192
   849(f): expecting 196608 actual extent phys 204800 log 12288 len 8192
   849(f): expecting 212992 actual extent phys 221184 log 20480 len 8192
   849(f): expecting 229376 actual extent phys 245760 log 28672 len 4096
   850(f): expecting 131072 actual extent phys 212992 log 2048 len 8192
   850(f): expecting 221184 actual extent phys 237568 log 10240 len 8192
   850(f): expecting 245760 actual extent phys 253952 log 18432 len 8192
   850(f): expecting 262144 actual extent phys 270336 log 26624 len 6144
  1080(f): expecting 172032 actual extent phys 262144 log 4096 len 8192
  1080(f): expecting 270336 actual extent phys 286720 log 12288 len 8192
  1080(f): expecting 294912 actual extent phys 303104 log 20480 len 32768
  1080(f): expecting 344064 actual extent phys 352256 log 61440 len 8192
  1080(f): expecting 360448 actual extent phys 368640 log 69632 len 8192
  1080(f): expecting 376832 actual extent phys 385024 log 77824 len 4007
  1082(f): expecting 237568 actual extent phys 360448 log 4096 len 8192
  1082(f): expecting 368640 actual extent phys 376832 log 12288 len 8192
  1082(f): expecting 385024 actual extent phys 425984 log 20480 len 3966
 16386(d): expecting   9259 actual extent phys   9299 log 1 len 2
 26715(f): expecting 696320 actual extent phys 712704 log 8192 len 8192
 26715(f): expecting 720896 actual extent phys 745472 log 16384 len 2240
 26716(f): expecting 700416 actual extent phys 704512 log 4096 len 4352
 26717(f): expecting 704512 actual extent phys 720896 log 4096 len 8192
 26717(f): expecting 729088 actual extent phys 761856 log 12288 len 576
 26718(f): expecting 741376 actual extent phys 770048 log 12288 len 7104
 26719(f): expecting 522240 actual extent phys 753664 log 512 len 8192
 26719(f): expecting 761856 actual extent phys 778240 log 8704 len 8192
 26719(f): expecting 786432 actual extent phys 802816 log 16896 len 8192
 26719(f): expecting 811008 actual extent phys 876544 log 25088 len 512
 26722(f): expecting 712704 actual extent phys 786432 log 2048 len 4096
 26733(f): expecting 753664 actual extent phys 811008 log 4096 len 64
 26735(f): expecting 770048 actual extent phys 827392 log 4096 len 448
 26743(f): expecting 802816 actual extent phys 868352 log 8192 len 448
 26756(f): expecting 765952 actual extent phys 843776 log 2048 len 4608
 26858(f): expecting 827392 actual extent phys 901120 log 4096 len 2560
 26861(f): expecting 901120 actual extent phys 925696 log 8192 len 3072
 26874(f): expecting 835584 actual extent phys 909312 log 4096 len 5184
 26875(f): expecting 876544 actual extent phys 917504 log 4096 len 8192
 26875(f): expecting 925696 actual extent phys 933888 log 12288 len 24576
 26875(f): expecting 958464 actual extent phys 966656 log 36864 len 8192
 26875(f): expecting 974848 actual extent phys 983040 log 45056 len 2304
 26876(f): expecting 823296 actual extent phys 958464 log 2048 len 8192
 26876(f): expecting 966656 actual extent phys 974848 log 10240 len 8192
 26876(f): expecting 983040 actual extent phys 999424 log 18432 len 32768
 26876(f): expecting 1040384 actual extent phys 1097728 log 59392 len 32768
 26901(f): expecting 1572864 actual extent phys 1613824 log 8192 len 32768
 26902(f): expecting 1712128 actual extent phys 1720320 log 8192 len 8192
 26902(f): expecting 1728512 actual extent phys 1736704 log 16384 len 512
 26903(f): expecting 1720320 actual extent phys 1728512 log 8192 len 8192
 26903(f): expecting 1736704 actual extent phys 1744896 log 16384 len 32768
 26903(f): expecting 1818624 actual extent phys 1826816 log 90112 len 32768
 26903(f): expecting 2097152 actual extent phys 2129920 log 360448 len 32768
 26904(f): expecting 2342912 actual extent phys 2351104 log 139264 len 32768
 26904(f): expecting 2621440 actual extent phys 2662400 log 409600 len 32768
 26905(f): expecting 2752512 actual extent phys 2768896 log 40960 len 8192
 26905(f): expecting 2777088 actual extent phys 2785280 log 49152 len 2880
 26906(f): expecting 831488 actual extent phys 2752512 log 2048 len 6272
 26907(f): expecting 884736 actual extent phys 2760704 log 4096 len 8192
 26907(f): expecting 2768896 actual extent phys 2777088 log 12288 len 8192
 26907(f): expecting 2785280 actual extent phys 2793472 log 20480 len 24576
 26907(f): expecting 2818048 actual extent phys 2826240 log 45056 len 8192
 26907(f): expecting 2834432 actual extent phys 2850816 log 53248 len 1408
 26908(f): expecting 843776 actual extent phys 2818048 log 2048 len 8192
 26908(f): expecting 2826240 actual extent phys 2842624 log 10240 len 8192
 26908(f): expecting 2850816 actual extent phys 2859008 log 18432 len 8192
 26908(f): expecting 2867200 actual extent phys 2875392 log 26624 len 5568
 26909(f): expecting 892928 actual extent phys 2867200 log 4096 len 8192
 26909(f): expecting 2875392 actual extent phys 2883584 log 12288 len 32768
 26909(f): expecting 2957312 actual extent phys 2965504 log 86016 len 31104
 26940(f): expecting 3006464 actual extent phys 3014656 log 8192 len 8192
 26941(f): expecting 909312 actual extent phys 3006464 log 4096 len 8192
 26941(f): expecting 3014656 actual extent phys 3031040 log 12288 len 4096
 27217(f): expecting 3031040 actual extent phys 3039232 log 8192 len 8192
 27218(f): expecting 933888 actual extent phys 3047424 log 4096 len 8192
 27218(f): expecting 3055616 actual extent phys 3063808 log 12288 len 4096
 28709(f): expecting 3063808 actual extent phys 3072000 log 8192 len 32768
 28709(f): expecting 3145728 actual extent phys 3178496 log 81920 len 14911
 28748(f): expecting 3227648 actual extent phys 3235840 log 24576 len 8192
 28748(f): expecting 3244032 actual extent phys 3252224 log 32768 len 3264
 28749(f): expecting 872448 actual extent phys 3227648 log 2048 len 8192
 28749(f): expecting 3235840 actual extent phys 3244032 log 10240 len 8192
 28749(f): expecting 3252224 actual extent phys 3268608 log 18432 len 7424
 28750(f): expecting 991232 actual extent phys 3260416 log 4096 len 8192
 28750(f): expecting 3268608 actual extent phys 3276800 log 12288 len 32768
 28750(f): expecting 3350528 actual extent phys 3358720 log 86016 len 32768
 28750(f): expecting 3440640 actual extent phys 3448832 log 167936 len 8192
 28750(f): expecting 3457024 actual extent phys 3465216 log 176128 len 3328
 28751(f): expecting 880640 actual extent phys 3440640 log 2048 len 8192
 28751(f): expecting 3448832 actual extent phys 3457024 log 10240 len 8192
 28751(f): expecting 3465216 actual extent phys 3473408 log 18432 len 32768
 28751(f): expecting 3506176 actual extent phys 3514368 log 51200 len 11328
 29694(f): expecting 868352 actual extent phys 995328 log 1024 len 4096
 29694(f): expecting 999424 actual extent phys 3506176 log 5120 len 1281
 29781(f): expecting 888832 actual extent phys 1044480 log 2048 len 1091
 32235(f): expecting 164896 actual extent phys 848864 log 16 len 1
 35722(f): expecting 1301728 actual extent phys 1564224 log 32 len 1
 37915(f): expecting 1697376 actual extent phys 1703872 log 32 len 1
 38791(d): expecting  12722 actual extent phys  12733 log 1 len 2
 39741(f): expecting 2660352 actual extent phys 3530752 log 2048 len 6594
 39758(f): expecting 2791424 actual extent phys 3538944 log 2048 len 3355
 39885(f): expecting 2859008 actual extent phys 3547136 log 4096 len 2304
 39910(d): expecting  12746 actual extent phys  12815 log 1 len 2
 39912(d): expecting  12748 actual extent phys  13085 log 1 len 4
 39912(d): expecting  13089 actual extent phys  13203 log 5 len 4
 39912(d): expecting  13207 actual extent phys  13214 log 9 len 2
 45373(d): expecting  13343 actual extent phys  13398 log 1 len 2
 45374(d): expecting  13344 actual extent phys  13622 log 1 len 2
 45374(d): expecting  13624 actual extent phys  13754 log 3 len 4
 45374(d): expecting  13758 actual extent phys  13771 log 7 len 1
 50533(f): expecting 3588096 actual extent phys 3620864 log 4096 len 716
 53476(f): expecting 3603456 actual extent phys 3624960 log 256 len 1
 54628(f): expecting 392128 actual extent phys 3625952 log 16 len 1
 54735(f): expecting 3706880 actual extent phys 3719168 log 2048 len 110
 55334(d): expecting  14211 actual extent phys  14223 log 1 len 7
 55334(d): expecting  14230 actual extent phys  14273 log 8 len 1
 55334(d): expecting  14274 actual extent phys  14311 log 9 len 4
 55337(d): expecting  14214 actual extent phys  14335 log 1 len 2
 55337(d): expecting  14337 actual extent phys  14339 log 3 len 3
 55337(d): expecting  14342 actual extent phys  14343 log 6 len 1
 55337(d): expecting  14344 actual extent phys  14395 log 7 len 1
 55337(d): expecting  14396 actual extent phys  14402 log 8 len 1
 55337(d): expecting  14403 actual extent phys  14553 log 9 len 1
 55337(d): expecting  14554 actual extent phys  14563 log 10 len 5
 55337(d): expecting  14568 actual extent phys  14578 log 15 len 1
 55341(d): expecting  14218 actual extent phys  20195 log 1 len 2
 55342(d): expecting  14219 actual extent phys  20193 log 1 len 2
 56045(f): expecting 3743744 actual extent phys 3784704 log 16384 len 8192
 56045(f): expecting 3792896 actual extent phys 3899392 log 24576 len 904
 56640(d): expecting  14246 actual extent phys  14337 log 1 len 2
 57351(d): expecting   9347 actual extent phys   9865 log 1 len 2
 59961(d): expecting  14400 actual extent phys  14682 log 1 len 2
 60070(d): expecting  14502 actual extent phys  15906 log 1 len 3
 60071(d): expecting  14503 actual extent phys  16151 log 1 len 2
 60071(d): expecting  16153 actual extent phys  16203 log 3 len 2
 60075(d): expecting  14507 actual extent phys  16342 log 1 len 2
 60359(d): expecting  14548 actual extent phys  14596 log 1 len 2
 64856(d): expecting  15089 actual extent phys  15326 log 1 len 2
 65292(d): expecting  15129 actual extent phys  15352 log 1 len 2
 67752(f): expecting 424832 actual extent phys 3945440 log 16 len 1
 69893(d): expecting  15892 actual extent phys  16035 log 1 len 2
 71050(d): expecting  15919 actual extent phys  16073 log 1 len 2
 72049(d): expecting  16061 actual extent phys  16278 log 1 len 2
 72456(d): expecting  16088 actual extent phys  16236 log 1 len 2
 73732(d): expecting   9364 actual extent phys  11529 log 1 len 2
 75561(d): expecting  16346 actual extent phys  16775 log 1 len 2
 75854(f): expecting 446688 actual extent phys 4003424 log 16 len 1
 76258(d): expecting  16515 actual extent phys  16883 log 1 len 2
 76264(d): expecting  16521 actual extent phys  17977 log 1 len 2
 76268(d): expecting  16525 actual extent phys  18674 log 1 len 2
 76269(d): expecting  16526 actual extent phys  18687 log 1 len 2
 77026(f): expecting 4096000 actual extent phys 4104192 log 49152 len 8192
 77026(f): expecting 4112384 actual extent phys 4128768 log 57344 len 8192
 77026(f): expecting 4136960 actual extent phys 4284416 log 65536 len 1831
 77043(f): expecting 4030464 actual extent phys 4112384 log 1024 len 1852
 77059(f): expecting 4038656 actual extent phys 4120576 log 2048 len 1105
 84262(d): expecting  17361 actual extent phys  17412 log 1 len 2
 86553(d): expecting  17486 actual extent phys  17538 log 1 len 2
 87086(d): expecting  17518 actual extent phys  17646 log 1 len 2
 88404(d): expecting  17603 actual extent phys  17824 log 1 len 2
 88420(d): expecting  17619 actual extent phys  17875 log 1 len 2
 99009(d): expecting  17992 actual extent phys  18095 log 1 len 2
 99013(d): expecting  17996 actual extent phys  18376 log 1 len 2
 99015(d): expecting  17998 actual extent phys  18516 log 1 len 1
 99015(d): expecting  18517 actual extent phys  18518 log 2 len 1
 99019(d): expecting  18002 actual extent phys  18604 log 1 len 8
108604(d): expecting  18794 actual extent phys  19031 log 1 len 2
108610(d): expecting  18800 actual extent phys  20187 log 1 len 2
108614(d): expecting  18804 actual extent phys  20189 log 1 len 2
108615(d): expecting  18805 actual extent phys  20191 log 1 len 2
109846(f): expecting 4288512 actual extent phys 4320768 log 256 len 1
114703(d): expecting   9451 actual extent phys   9452 log 1 len 302
115949(d): expecting  19495 actual extent phys  19585 log 1 len 2
118017(d): expecting  19609 actual extent phys  19660 log 1 len 2
119532(d): expecting  19734 actual extent phys  19750 log 1 len 2
120741(d): expecting  19776 actual extent phys  19918 log 1 len 2
120771(d): expecting  19794 actual extent phys  19811 log 1 len 2
122162(d): expecting  19873 actual extent phys  20084 log 1 len 2
122179(d): expecting  19889 actual extent phys  20161 log 1 len 2
122895(d): expecting   9452 actual extent phys   9754 log 1 len 111
122895(d): expecting   9865 actual extent phys   9875 log 112 len 2
122895(d): expecting   9877 actual extent phys  10010 log 114 len 3
122895(d): expecting  10013 actual extent phys  10039 log 117 len 1
122895(d): expecting  10040 actual extent phys  10041 log 118 len 11
124197(f): expecting 513920 actual extent phys 4328640 log 16 len 1
130091(f): expecting 564608 actual extent phys 4420416 log 16 len 1
139265(d): expecting 532515 actual extent phys 532561 log 1 len 2
139418(d): expecting 532980 actual extent phys 533428 log 1 len 1
139418(d): expecting 533429 actual extent phys 533430 log 2 len 1
139422(d): expecting 532984 actual extent phys 533512 log 1 len 3
139422(d): expecting 533515 actual extent phys 533541 log 4 len 1
139422(d): expecting 533542 actual extent phys 533564 log 5 len 4
142824(d): expecting 533736 actual extent phys 534064 log 1 len 2
142827(d): expecting 533739 actual extent phys 535033 log 1 len 4
142830(d): expecting 533742 actual extent phys 535514 log 1 len 2
142834(d): expecting 533746 actual extent phys 536918 log 1 len 2
142835(d): expecting 533747 actual extent phys 536971 log 1 len 2
150919(d): expecting 534498 actual extent phys 534579 log 1 len 2
152114(d): expecting 534587 actual extent phys 534646 log 1 len 2
153682(d): expecting 534711 actual extent phys 534752 log 1 len 2
155803(d): expecting 534842 actual extent phys 534889 log 1 len 2
156768(d): expecting 534875 actual extent phys 534904 log 1 len 2
156969(d): expecting 534892 actual extent phys 534902 log 1 len 2
157780(f): expecting 4528128 actual extent phys 4554752 log 2048 len 348
158990(d): expecting 534943 actual extent phys 535051 log 1 len 2
158997(d): expecting 534950 actual extent phys 535057 log 1 len 2
158997(d): expecting 535059 actual extent phys 535070 log 3 len 1
159014(d): expecting 534965 actual extent phys 535079 log 1 len 2
159017(d): expecting 534968 actual extent phys 535113 log 1 len 2
159017(d): expecting 535115 actual extent phys 535118 log 3 len 2
159028(d): expecting 534978 actual extent phys 535164 log 1 len 2
159037(d): expecting 534986 actual extent phys 535232 log 1 len 4
159037(d): expecting 535236 actual extent phys 535237 log 5 len 4
159055(d): expecting 535000 actual extent phys 535299 log 1 len 2
159059(d): expecting 535003 actual extent phys 535304 log 1 len 2
159059(d): expecting 535306 actual extent phys 535345 log 3 len 2
159073(d): expecting 535016 actual extent phys 535442 log 1 len 4
159181(d): expecting 535023 actual extent phys 535040 log 1 len 2
163790(d): expecting 535106 actual extent phys 535139 log 1 len 2
165210(d): expecting 535134 actual extent phys 535179 log 1 len 2
166639(f): expecting 4619648 actual extent phys 4620160 log 32 len 1
170682(d): expecting 535260 actual extent phys 535274 log 1 len 2
174697(d): expecting 535373 actual extent phys 535401 log 1 len 4
174698(d): expecting 535374 actual extent phys 535405 log 1 len 2
177953(d): expecting 535494 actual extent phys 535520 log 1 len 3
180225(d): expecting 532525 actual extent phys 532578 log 1 len 2
181856(d): expecting 535530 actual extent phys 535829 log 1 len 2
181856(d): expecting 535831 actual extent phys 536099 log 3 len 1
181856(d): expecting 536100 actual extent phys 536139 log 4 len 1
181856(d): expecting 536140 actual extent phys 536283 log 5 len 1
181860(d): expecting 535534 actual extent phys 536885 log 1 len 8
188421(d): expecting 532590 actual extent phys 532634 log 1 len 2
188421(d): expecting 532636 actual extent phys 532689 log 3 len 1
188421(d): expecting 532690 actual extent phys 532692 log 4 len 1
190179(d): expecting 536938 actual extent phys 536981 log 1 len 2
190188(d): expecting 536947 actual extent phys 536990 log 1 len 5
190198(d): expecting 536957 actual extent phys 537011 log 1 len 2
190747(d): expecting 536977 actual extent phys 536984 log 1 len 4
194667(f): expecting 1294016 actual extent phys 5002592 log 16 len 1
195345(d): expecting 537075 actual extent phys 537108 log 1 len 2
197126(d): expecting 537125 actual extent phys 537703 log 1 len 2
197165(d): expecting 537161 actual extent phys 537783 log 1 len 2
197165(d): expecting 537785 actual extent phys 537796 log 3 len 2
197182(d): expecting 537178 actual extent phys 537898 log 1 len 2
197182(d): expecting 537900 actual extent phys 538071 log 3 len 1
197182(d): expecting 538072 actual extent phys 538128 log 4 len 1
197182(d): expecting 538129 actual extent phys 538359 log 5 len 1
197182(d): expecting 538360 actual extent phys 538411 log 6 len 1
197182(d): expecting 538412 actual extent phys 538514 log 7 len 1
197182(d): expecting 538515 actual extent phys 538577 log 8 len 1
197182(d): expecting 538578 actual extent phys 538909 log 9 len 1
197182(d): expecting 538910 actual extent phys 538994 log 10 len 1
197182(d): expecting 538995 actual extent phys 539144 log 11 len 1
197182(d): expecting 539145 actual extent phys 539151 log 12 len 1
197182(d): expecting 539152 actual extent phys 539163 log 13 len 1
197363(d): expecting 537355 actual extent phys 544238 log 1 len 2
197492(f): expecting 5019136 actual extent phys 5038464 log 32 len 1
197980(f): expecting 5028992 actual extent phys 5041152 log 64 len 1
198415(d): expecting 537525 actual extent phys 537526 log 1 len 22
198416(d): expecting 537526 actual extent phys 537548 log 1 len 2
198416(d): expecting 537550 actual extent phys 537558 log 3 len 2
198416(d): expecting 537560 actual extent phys 537582 log 5 len 4
198416(d): expecting 537586 actual extent phys 537681 log 9 len 1
198416(d): expecting 537682 actual extent phys 537683 log 10 len 7
203063(d): expecting 537695 actual extent phys 537724 log 1 len 2
206133(d): expecting 538029 actual extent phys 539257 log 1 len 4
216081(d): expecting 539535 actual extent phys 539617 log 1 len 2
217967(f): expecting 5081728 actual extent phys 5083456 log 32 len 1
219321(d): expecting 539814 actual extent phys 539819 log 1 len 4
219322(d): expecting 539815 actual extent phys 539854 log 1 len 4
219326(d): expecting 539818 actual extent phys 539858 log 1 len 4
220371(d): expecting 539853 actual extent phys 539862 log 1 len 4
220372(d): expecting 539854 actual extent phys 539866 log 1 len 16
220372(d): expecting 539882 actual extent phys 539924 log 17 len 2
220372(d): expecting 539926 actual extent phys 539943 log 19 len 6
220372(d): expecting 539949 actual extent phys 539964 log 25 len 1
220372(d): expecting 539965 actual extent phys 539966 log 26 len 2
220372(d): expecting 539968 actual extent phys 539971 log 28 len 5
221255(f): expecting 5105664 actual extent phys 5136384 log 2048 len 3093
223509(d): expecting 539889 actual extent phys 539978 log 1 len 2
225129(d): expecting 539977 actual extent phys 539993 log 1 len 5
225129(d): expecting 539998 actual extent phys 540002 log 6 len 3
226133(d): expecting 539983 actual extent phys 540005 log 1 len 2
226137(d): expecting 539986 actual extent phys 540039 log 1 len 2
226141(d): expecting 539989 actual extent phys 540068 log 1 len 2
226144(d): expecting 539991 actual extent phys 540101 log 1 len 2
226165(d): expecting 539993 actual extent phys 540012 log 1 len 4
237618(f): expecting 2655264 actual extent phys 5190112 log 16 len 1
240416(d): expecting 542904 actual extent phys 542938 log 1 len 2
240432(d): expecting 542909 actual extent phys 542959 log 1 len 2
240433(d): expecting 542910 actual extent phys 542963 log 1 len 2
241784(d): expecting 542957 actual extent phys 542961 log 1 len 2
245906(d): expecting 543107 actual extent phys 543118 log 1 len 2
245906(d): expecting 543120 actual extent phys 543137 log 3 len 2
245914(d): expecting 543115 actual extent phys 543120 log 1 len 2
246865(d): expecting 543130 actual extent phys 543151 log 1 len 2
247099(d): expecting 543140 actual extent phys 543149 log 1 len 2
247099(d): expecting 543151 actual extent phys 543168 log 3 len 2
247106(d): expecting 543147 actual extent phys 543153 log 1 len 2
248534(d): expecting 543156 actual extent phys 543166 log 1 len 2
248534(d): expecting 543168 actual extent phys 543186 log 3 len 2
248541(d): expecting 543163 actual extent phys 543170 log 1 len 2
249587(d): expecting 543179 actual extent phys 543203 log 1 len 2
249846(d): expecting 543189 actual extent phys 543199 log 1 len 2
249846(d): expecting 543201 actual extent phys 543231 log 3 len 2
249853(d): expecting 543196 actual extent phys 543201 log 1 len 2
251277(d): expecting 543220 actual extent phys 543229 log 1 len 2
251277(d): expecting 543231 actual extent phys 543296 log 3 len 2
251283(d): expecting 543226 actual extent phys 543233 log 1 len 2
252584(d): expecting 543338 actual extent phys 543591 log 1 len 2
254065(d): expecting 543688 actual extent phys 543689 log 1 len 2
254171(d): expecting 543689 actual extent phys 543838 log 1 len 3
255779(d): expecting 543956 actual extent phys 544015 log 1 len 6
255779(d): expecting 544021 actual extent phys 544025 log 7 len 3
255779(d): expecting 544028 actual extent phys 544032 log 10 len 7
255781(d): expecting 543958 actual extent phys 544021 log 1 len 4
255781(d): expecting 544025 actual extent phys 544028 log 5 len 4
255781(d): expecting 544032 actual extent phys 544039 log 9 len 9
255783(d): expecting 543960 actual extent phys 544060 log 1 len 2
255786(d): expecting 543963 actual extent phys 544093 log 1 len 5
260965(d): expecting 544082 actual extent phys 544234 log 1 len 4
270566(d): expecting 1057112 actual extent phys 1057156 log 1 len 2
274457(d): expecting 1057944 actual extent phys 1058003 log 1 len 2
274458(d): expecting 1057945 actual extent phys 1058300 log 1 len 2
274458(d): expecting 1058302 actual extent phys 1058547 log 3 len 1
274458(d): expecting 1058548 actual extent phys 1058671 log 4 len 1
274458(d): expecting 1058672 actual extent phys 1058736 log 5 len 1
274459(d): expecting 1057946 actual extent phys 1059236 log 1 len 2
274459(d): expecting 1059238 actual extent phys 1059259 log 3 len 1
274459(d): expecting 1059260 actual extent phys 1059261 log 4 len 1
274459(d): expecting 1059262 actual extent phys 1059300 log 5 len 1
274459(d): expecting 1059301 actual extent phys 1059312 log 6 len 1
282892(f): expecting 2960992 actual extent phys 5311424 log 16 len 1
283067(d): expecting 1060283 actual extent phys 1060374 log 1 len 2
283071(d): expecting 1060287 actual extent phys 1060390 log 1 len 2
283076(d): expecting 1060292 actual extent phys 1060420 log 1 len 2
283076(d): expecting 1060422 actual extent phys 1060433 log 3 len 2
283076(d): expecting 1060435 actual extent phys 1060500 log 5 len 4
287981(d): expecting 1060655 actual extent phys 1060714 log 1 len 2
287982(d): expecting 1060656 actual extent phys 1061011 log 1 len 2
287982(d): expecting 1061013 actual extent phys 1061263 log 3 len 1
287982(d): expecting 1061264 actual extent phys 1061347 log 4 len 1
287982(d): expecting 1061348 actual extent phys 1061447 log 5 len 1
287983(d): expecting 1060657 actual extent phys 1061947 log 1 len 2
287983(d): expecting 1061949 actual extent phys 1061970 log 3 len 1
287983(d): expecting 1061971 actual extent phys 1061972 log 4 len 1
287983(d): expecting 1061973 actual extent phys 1062011 log 5 len 1
287983(d): expecting 1062012 actual extent phys 1062023 log 6 len 1
296004(d): expecting 1062994 actual extent phys 1063085 log 1 len 2
296008(d): expecting 1062998 actual extent phys 1063101 log 1 len 2
296013(d): expecting 1063003 actual extent phys 1063131 log 1 len 2
296013(d): expecting 1063133 actual extent phys 1063144 log 3 len 2
296013(d): expecting 1063146 actual extent phys 1063211 log 5 len 4
300906(d): expecting 1063368 actual extent phys 1063653 log 1 len 2
300906(d): expecting 1063655 actual extent phys 1063938 log 3 len 1
300906(d): expecting 1063939 actual extent phys 1064022 log 4 len 1
300906(d): expecting 1064023 actual extent phys 1064114 log 5 len 1
300907(d): expecting 1063369 actual extent phys 1064677 log 1 len 2
300907(d): expecting 1064679 actual extent phys 1064709 log 3 len 1
300907(d): expecting 1064710 actual extent phys 1064714 log 4 len 1
300907(d): expecting 1064715 actual extent phys 1064784 log 5 len 1
300907(d): expecting 1064785 actual extent phys 1064790 log 6 len 1
300907(d): expecting 1064791 actual extent phys 1064809 log 7 len 1
300907(d): expecting 1064810 actual extent phys 1064811 log 8 len 1
309546(d): expecting 1065312 actual extent phys 1065399 log 1 len 2
310606(d): expecting 1065415 actual extent phys 1065543 log 1 len 2
310759(d): expecting 1065536 actual extent phys 1065584 log 1 len 2
311202(d): expecting 1065584 actual extent phys 1065807 log 1 len 2
313586(d): expecting 1066076 actual extent phys 1066135 log 1 len 2
313586(d): expecting 1066137 actual extent phys 1066149 log 3 len 2
313586(d): expecting 1066151 actual extent phys 1066208 log 5 len 4
317650(d): expecting 1066867 actual extent phys 1066878 log 1 len 2
319808(d): expecting 1067370 actual extent phys 1067680 log 1 len 2
319808(d): expecting 1067682 actual extent phys 1067891 log 3 len 1
319808(d): expecting 1067892 actual extent phys 1067937 log 4 len 1
319812(d): expecting 1067374 actual extent phys 1068678 log 1 len 8
328044(d): expecting 1068921 actual extent phys 1068936 log 1 len 2
328049(d): expecting 1068926 actual extent phys 1068954 log 1 len 2
328052(d): expecting 1068929 actual extent phys 1068956 log 1 len 2
328055(d): expecting 1068932 actual extent phys 1068958 log 1 len 2
328057(d): expecting 1068934 actual extent phys 1068960 log 1 len 2
328058(d): expecting 1068935 actual extent phys 1068962 log 1 len 2
328211(d): expecting 1068939 actual extent phys 1068964 log 1 len 2
328212(d): expecting 1068940 actual extent phys 1068966 log 1 len 2
328214(d): expecting 1068942 actual extent phys 1068984 log 1 len 2
328215(d): expecting 1068943 actual extent phys 1068986 log 1 len 2
328216(d): expecting 1068944 actual extent phys 1068988 log 1 len 2
328217(d): expecting 1068945 actual extent phys 1068990 log 1 len 2
328218(d): expecting 1068946 actual extent phys 1068992 log 1 len 2
328220(d): expecting 1068948 actual extent phys 1068994 log 1 len 2
328221(d): expecting 1068949 actual extent phys 1068996 log 1 len 2
328222(d): expecting 1068950 actual extent phys 1068998 log 1 len 2
328223(d): expecting 1068951 actual extent phys 1069000 log 1 len 2
329488(d): expecting 1068969 actual extent phys 1069002 log 1 len 2
329491(d): expecting 1068972 actual extent phys 1069020 log 1 len 2
329494(d): expecting 1068975 actual extent phys 1069022 log 1 len 2
329495(d): expecting 1068976 actual extent phys 1069024 log 1 len 2
329500(d): expecting 1068981 actual extent phys 1069026 log 1 len 2
329502(d): expecting 1068983 actual extent phys 1069028 log 1 len 2
329503(d): expecting 1068984 actual extent phys 1069030 log 1 len 2
330719(d): expecting 1069008 actual extent phys 1069048 log 1 len 2
330721(d): expecting 1069010 actual extent phys 1069050 log 1 len 2
330726(d): expecting 1069015 actual extent phys 1069052 log 1 len 2
330727(d): expecting 1069016 actual extent phys 1069054 log 1 len 2
330728(d): expecting 1069017 actual extent phys 1069056 log 1 len 2
331980(d): expecting 1069036 actual extent phys 1069074 log 1 len 2
331981(d): expecting 1069037 actual extent phys 1069076 log 1 len 2
331982(d): expecting 1069038 actual extent phys 1069078 log 1 len 2
331985(d): expecting 1069041 actual extent phys 1069080 log 1 len 2
333117(d): expecting 1069059 actual extent phys 1069082 log 1 len 2
333118(d): expecting 1069060 actual extent phys 1069084 log 1 len 2
333122(d): expecting 1069064 actual extent phys 1069102 log 1 len 2
333125(d): expecting 1069067 actual extent phys 1069104 log 1 len 2
333127(d): expecting 1069069 actual extent phys 1069106 log 1 len 2
333130(d): expecting 1069072 actual extent phys 1069108 log 1 len 2
333132(d): expecting 1069074 actual extent phys 1069110 log 1 len 2
334377(d): expecting 1069090 actual extent phys 1069128 log 1 len 2
334378(d): expecting 1069091 actual extent phys 1069130 log 1 len 2
334379(d): expecting 1069092 actual extent phys 1069132 log 1 len 2
334380(d): expecting 1069093 actual extent phys 1069134 log 1 len 2
334383(d): expecting 1069096 actual extent phys 1069136 log 1 len 2
334384(d): expecting 1069097 actual extent phys 1069138 log 1 len 2
334386(d): expecting 1069099 actual extent phys 1069140 log 1 len 2
334388(d): expecting 1069101 actual extent phys 1069142 log 1 len 2
335581(d): expecting 1069116 actual extent phys 1069160 log 1 len 2
335582(d): expecting 1069117 actual extent phys 1069162 log 1 len 2
335586(d): expecting 1069121 actual extent phys 1069164 log 1 len 2
335587(d): expecting 1069122 actual extent phys 1069166 log 1 len 2
335588(d): expecting 1069123 actual extent phys 1069168 log 1 len 2
336776(d): expecting 1069152 actual extent phys 1069186 log 1 len 2
336777(d): expecting 1069153 actual extent phys 1069188 log 1 len 2
337942(d): expecting 1069171 actual extent phys 1069190 log 1 len 2
337943(d): expecting 1069172 actual extent phys 1069192 log 1 len 2
337951(d): expecting 1069178 actual extent phys 1069210 log 1 len 2
337953(d): expecting 1069179 actual extent phys 1069212 log 1 len 2
337954(d): expecting 1069180 actual extent phys 1069214 log 1 len 2
337955(d): expecting 1069181 actual extent phys 1069216 log 1 len 2
337957(d): expecting 1069183 actual extent phys 1069218 log 1 len 2
337958(d): expecting 1069184 actual extent phys 1069220 log 1 len 2
339159(d): expecting 1069195 actual extent phys 1069222 log 1 len 2
339161(d): expecting 1069197 actual extent phys 1069224 log 1 len 2
339164(d): expecting 1069200 actual extent phys 1069242 log 1 len 2
339166(d): expecting 1069202 actual extent phys 1069244 log 1 len 2
339170(d): expecting 1069205 actual extent phys 1069246 log 1 len 2
339171(d): expecting 1069206 actual extent phys 1069248 log 1 len 2
339173(d): expecting 1069207 actual extent phys 1069250 log 1 len 2
339175(d): expecting 1069209 actual extent phys 1069252 log 1 len 2
339176(d): expecting 1069210 actual extent phys 1069254 log 1 len 2
340398(d): expecting 1069229 actual extent phys 1069256 log 1 len 2
340399(d): expecting 1069230 actual extent phys 1069274 log 1 len 2
340400(d): expecting 1069231 actual extent phys 1069276 log 1 len 2
340404(d): expecting 1069235 actual extent phys 1069278 log 1 len 2
340406(d): expecting 1069237 actual extent phys 1069280 log 1 len 2
340408(d): expecting 1069239 actual extent phys 1069282 log 1 len 2
341637(d): expecting 1069260 actual extent phys 1069284 log 1 len 2
341640(d): expecting 1069263 actual extent phys 1069302 log 1 len 2
341641(d): expecting 1069264 actual extent phys 1069304 log 1 len 2
341643(d): expecting 1069265 actual extent phys 1069306 log 1 len 2
341644(d): expecting 1069266 actual extent phys 1069308 log 1 len 2
341645(d): expecting 1069267 actual extent phys 1069310 log 1 len 2
341646(d): expecting 1069268 actual extent phys 1069312 log 1 len 2
341647(d): expecting 1069269 actual extent phys 1069314 log 1 len 2
341650(d): expecting 1069272 actual extent phys 1069316 log 1 len 2
341651(d): expecting 1069273 actual extent phys 1069318 log 1 len 2
341652(d): expecting 1069274 actual extent phys 1069320 log 1 len 2
342865(d): expecting 1069289 actual extent phys 1069338 log 1 len 2
342869(d): expecting 1069293 actual extent phys 1069340 log 1 len 2
342873(d): expecting 1069297 actual extent phys 1069342 log 1 len 2
342874(d): expecting 1069298 actual extent phys 1069344 log 1 len 2
342876(d): expecting 1069300 actual extent phys 1069346 log 1 len 2
342877(d): expecting 1069301 actual extent phys 1069348 log 1 len 2
344043(d): expecting 1069324 actual extent phys 1069350 log 1 len 2
344048(d): expecting 1069328 actual extent phys 1069368 log 1 len 2
344049(d): expecting 1069329 actual extent phys 1069370 log 1 len 2
344050(d): expecting 1069330 actual extent phys 1069372 log 1 len 2
344053(d): expecting 1069333 actual extent phys 1069374 log 1 len 2
344055(d): expecting 1069335 actual extent phys 1069376 log 1 len 2
344056(d): expecting 1069336 actual extent phys 1069378 log 1 len 2
345283(d): expecting 1069353 actual extent phys 1069380 log 1 len 2
345284(d): expecting 1069354 actual extent phys 1069382 log 1 len 2
345287(d): expecting 1069357 actual extent phys 1069428 log 1 len 2
345288(d): expecting 1069358 actual extent phys 1069453 log 1 len 1
345288(d): expecting 1069454 actual extent phys 1069455 log 2 len 1
345290(d): expecting 1069360 actual extent phys 1069502 log 1 len 1
345290(d): expecting 1069503 actual extent phys 1069504 log 2 len 1
345291(d): expecting 1069361 actual extent phys 1069512 log 1 len 2
345295(d): expecting 1069365 actual extent phys 1069530 log 1 len 2
345296(d): expecting 1069366 actual extent phys 1069537 log 1 len 2
345297(d): expecting 1069367 actual extent phys 1069559 log 1 len 2
345298(d): expecting 1069368 actual extent phys 1069561 log 1 len 2
347117(d): expecting 1069511 actual extent phys 1069519 log 1 len 2
347898(d): expecting 1069556 actual extent phys 1069563 log 1 len 50
347898(d): expecting 1069613 actual extent phys 1069616 log 51 len 1
347898(d): expecting 1069617 actual extent phys 1069728 log 52 len 4
347898(d): expecting 1069732 actual extent phys 1069958 log 56 len 1
347898(d): expecting 1069959 actual extent phys 1070015 log 57 len 6
348317(f): expecting 5402624 actual extent phys 5414912 log 2048 len 558
Pass 1: Memory used: 405k/3836k (299k/107k), time:  5.58/ 3.23/ 0.85
Pass 1: I/O read: 93MB, write: 0MB, rate: 16.66MB/s
Pass 2: Checking directory structure
Pass 2: Memory used: 405k/3904k (299k/107k), time:  4.57/ 2.10/ 1.60
Pass 2: I/O read: 158MB, write: 0MB, rate: 34.54MB/s
Pass 3: Checking directory connectivity
Peak memory: Memory used: 765k/3904k (555k/211k), time: 10.28/ 5.38/ 2.45
Pass 3: Memory used: 765k/3904k (299k/467k), time:  0.01/ 0.01/ 0.00
Pass 3: I/O read: 1MB, write: 0MB, rate: 82.37MB/s
Pass 4: Checking reference counts
Pass 4: Memory used: 765k/1940k (298k/467k), time:  0.22/ 0.22/ 0.00
Pass 4: I/O read: 0MB, write: 0MB, rate: 0.00MB/s
Pass 5: Checking group summary information
Pass 5: Memory used: 765k/1420k (554k/211k), time:  1.92/ 1.66/ 0.02
Pass 5: I/O read: 1MB, write: 0MB, rate: 0.52MB/s

  358197 inodes used (17.08%)
      55 non-contiguous files (0.0%)
     272 non-contiguous directories (0.1%)
         # of inodes with ind/dind/tind blocks: 0/0/0
         Extent depth histogram: 338562/31
 5086544 blocks used (60.64%)
       0 bad blocks
       1 large file

  303132 regular files
   33428 directories
      69 character device files
      26 block device files
       7 fifos
     626 links
   21523 symbolic links (19489 fast symbolic links)
       3 sockets
--------
  358814 files
Memory used: 765k/1420k (554k/211k), time: 12.43/ 7.28/ 2.47
I/O read: 253MB, write: 0MB, rate: 20.36MB/s

Re: Some 64-bit tests

[Theodore Tso]

On Thu, Jun 11, 2009 at 11:20:06AM +0530, Aneesh Kumar K.V wrote:
> 
> I already have a RFC patch which Nick actually tested. It is giving 32MB
> extents, which is expected because the max order in buddy cache is
> blocksize_bits + 1. I have a Fixme in there regarding scaling the start
> block which was hoping to fix soon.

FYI, this patch seems to cause the system to lock up on umount when
running xfstests #135.

I'm removing it from the unstable patch queue for now; do you have an
update for this patch?

						- Ted

Re: Some 64-bit tests

[Aneesh Kumar K.V]

On Thu, Jun 18, 2009 at 05:11:12PM -0400, Theodore Tso wrote:
> On Thu, Jun 11, 2009 at 11:20:06AM +0530, Aneesh Kumar K.V wrote:
> > 
> > I already have a RFC patch which Nick actually tested. It is giving 32MB
> > extents, which is expected because the max order in buddy cache is
> > blocksize_bits + 1. I have a Fixme in there regarding scaling the start
> > block which was hoping to fix soon.
> 
> FYI, this patch seems to cause the system to lock up on umount when
> running xfstests #135.
> 
> I'm removing it from the unstable patch queue for now; do you have an
> update for this patch?

I haven't got time to work on the changes needed. Will check what is
causing the system lockup

-aneesh