XFS regression?

* XFS regression?
@ 2007-10-10 14:27 Andrew Clayton
  2007-10-11  1:01 ` David Chinner
  0 siblings, 1 reply; 13+ messages in thread
From: Andrew Clayton @ 2007-10-10 14:27 UTC (permalink / raw)
  To: linux-fsdevel

Hi,

(Seeing as I haven't been able to subscribe or post to the XFS mailing
list, I'll try here)

I'll try not to flood with information on the first post.

In trying to track down this issue here:
http://www.spinics.net/lists/raid/msg17195.html

I think I'm seeing a regression in XFS

If I run the following program (This was on an Athlon XP, Seagate IDE,
with a 2.6.23-rc9-git2)

/* fslattest.c */

#define _GNU_SOURCE

#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <sys/stat.h>
#include <sys/types.h>
#include <fcntl.h>
#include <string.h>

int main(int argc, char *argv[])
{
        char file[255];

        if (argc < 2) {
                printf("Usage: fslattest file\n");
                exit(1);
        }

        strncpy(file, argv[1], 254);
        printf("Opening %s\n", file);

        while (1) {
                int testfd = open(file, 
		O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 
															0600); 
		close(testfd);
		unlink(file); 
		sleep(1);
	}

	exit(0);
}

e.g $ strace -T -e open fslattest test

And then after a few seconds run

$ dd if=/dev/zero of=bigfile bs=1M count=500

I see the following

Before dd kicks in

open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<0.005043> open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE,
0600) = 3 <0.000212> open("test",
O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3 <0.016844>

while dd is running

open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<2.000348> open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE,
0600) = 3 <1.594441> open("test",
O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3 <2.224636>
open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<1.074615>

dd stopped

open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<0.013224> open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE,
0600) = 3 <0.007109> open("test",
O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3 <0.007108>

Doing the same thing with ext3 shows no such stalls. e.g before, during
and after the above dd

open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<0.015423> open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE,
0600) = 3 <0.000092> open("test",
O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3 <0.000093>
open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<0.000088> open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE,
0600) = 3 <0.000103> open("test",
O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3 <0.000096>
open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<0.000094> open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE,
0600) = 3 <0.000114> open("test",
O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3 <0.000091>
open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0600) = 3
<0.000274> open("test", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE,
0600) = 3 <0.000107>

I have found a machine in the office to do more testing on and that can
run older kernels.

It seems this problem was introduced between 2.6.18 and 2.6.19. 

The other thing I've found is that if I do the dd to an ext3 fs (on
the same disk at least) while running the test in the XFS fs then I
also see the latencies.

I can replicate this behaviour on at least 4 different machines so far.

Just ask it you'd like more details.

Cheers,

Andrew

^ permalink raw reply	[flat|nested] 13+ messages in thread