lkml.org 
[lkml]   [2012]   [Oct]   [9]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectLinux 3.0+ Disk performance problem - wrong pdflush behaviour
Hello,

Since Kernel version 3.0 pdflush blocks writes even the dirty bytes are
well below /proc/sys/vm/dirty_bytes or /proc/sys/vm/dirty_ratio.
The kernel 2.6.39 works nice.

How this hurt us in the real life: We have a very high performance game
server where the MySQL have to do many writes along the reads. All
writes and reads are very simple and have to be very quick. If we run
the system with Linux 3.2 we get unacceptable performance. Now we are
stuck with 2.6.32 kernel here because this problem.

I attach the test program wrote by me which shows the problem. The
program just writes blocks continously to random position to a given big
file. The write rate limited to 100 MByte/s. In a well-working kernel it
have to run with constant 100 MBit/s speed for indefinite long. The test
have to be run on a simple HDD.

Test steps:
1. You have to use an XFS, EXT2 or ReiserFS partition for the test, Ext4
forces flushes periodically. I recommend to use XFS.
2. create a big file on the test partiton. For 8 GByte RAM you can
create a 2 GByte file. For 2 GB RAM I recommend to create 500MByte file.
File creation can be done with this command: dd if=/dev/zero
of=bigfile2048M.bin bs=1M count=2048
3. compile pdflushtest.c: (gcc -o pdflushtest pdflushtest.c)
4. run pdflushtest: ./pdflushtest --file=/where/is/the/bigfile2048M.bin

In the beginning there can be some slowness even on well-working
kernels. If you create the bigfile in the same run then it runs usually
smootly from the beginning.

I don't know a setting of /proc/sys/vm variables which runs this test
smootly on a 3.2.29 (3.0+) kernel. I think this is a kernel bug, because
if I have much more "/proc/sys/vm/dirty_bytes" than the testfile size
the test program should never be blocked.

A sample result:
11:20:05: speed: 99.994 MiB/s, time usage: 4.60 %, avg. block
time: 1.8 us, max. block time: 18 us
11:20:06: speed: 99.994 MiB/s, time usage: 4.60 %, avg. block
time: 1.8 us, max. block time: 10 us
11:20:07: speed: 99.994 MiB/s, time usage: 4.62 %, avg. block
time: 1.8 us, max. block time: 11 us
11:20:08: speed: 99.989 MiB/s, time usage: 4.59 %, avg. block
time: 1.8 us, max. block time: 58 us
11:20:09: speed: 99.997 MiB/s, time usage: 4.55 %, avg. block
time: 1.8 us, max. block time: 13 us
11:20:10: speed: 28.840 MiB/s, time usage: 96.47 %, avg. block time:
130.7 us, max. block time: 114076 us
11:20:11: speed: 30.505 MiB/s, time usage: 98.14 %, avg. block time:
125.7 us, max. block time: 135008 us
11:20:12: speed: 25.956 MiB/s, time usage: 99.71 %, avg. block time:
150.1 us, max. block time: 129839 us
11:20:13: speed: 25.088 MiB/s, time usage: 96.43 %, avg. block time:
150.1 us, max. block time: 149649 us
11:20:14: speed: 32.438 MiB/s, time usage: 98.64 %, avg. block time:
118.8 us, max. block time: 145649 us
11:20:15: speed: 22.765 MiB/s, time usage: 99.11 %, avg. block time:
170.1 us, max. block time: 159749 us

At 11:20:10 the pdflush started its work, based on the
"dirty_expire_centisecs". The test file was 2GByte, the
/proc/sys/vm/dirty_bytes/dirty_bytes was 4000000000. The system (i5-3.4
GHz, 8G RAM, Kernel 3.2.29-amd64) was booted to run this test only so it
had 2,2 GByte RAM for cache, and 5.1 GByte RAM free (totally unused).
Sorry if I not found the right place to report this, please advise me
were to send.

Best regards
Viktor Nagy

#include <stdio.h>
#include <string.h>
#include <getopt.h>
#include <inttypes.h>
#include <sys/time.h>
#include <time.h>
#include <stdlib.h>
#include <unistd.h>
#include <sys/stat.h>
#include <fcntl.h>
// parameters

char * filename = NULL;
enum testermode {READ, WRITE} mode = WRITE;
float speedlimit = 100; // MiB / s
int burstcount = 10;
// internals

int blocksize = 4096;
int blockcount = 0;

int fh = 0;

char filebuffer[65536];

static struct option long_options[] =
{
{"mode", required_argument, 0, 0 },
{"m", required_argument, 0, 0 },
{"file", required_argument, 0, 0 },
{"f", required_argument, 0, 0 },
{"limit", required_argument, 0, 0 },
{"l", required_argument, 0, 0 },
{"burst", required_argument, 0, 0 },
{"b", required_argument, 0, 0 },
{0, 0, 0, 0 }
};
void parse_commandline(int argc, char **argv)
{
int r;
int option_index = 0;
while (0 <= (r = getopt_long_only(argc, argv, "", long_options, &option_index)))
{
const char * optname = long_options[option_index].name;
if (r == 0)
{
if (strcmp("file", optname) == 0 || strcmp("f", optname) == 0)
{
filename = strdup(optarg);
}
else if (strcmp("mode", optname) == 0 || strcmp("m", optname) == 0)
{
if (strcmp("reader", optarg) == 0 || strcmp("read", optarg) == 0)
{
mode = READ;
}
else if (strcmp("writer", optarg) == 0 || strcmp("write", optarg) == 0)
{
mode = WRITE;
}
else
{
printf("Invalid mode: \"%s\"\n", optarg);
}
}
else if (strcmp("burst", optname) == 0 || strcmp("b", optname) == 0)
{
burstcount = atoi(optarg);
if (burstcount < 1) burstcount = 1;
}
else if (strcmp("limit", optname) == 0 || strcmp("l", optname) == 0)
{
speedlimit = atoi(optarg);
if (speedlimit < 1) speedlimit = 1;
}
else
{
printf("Unhandled option: \"%s\"\n", optname);
}
}
else
{
exit(1);
break;
}
}
}
char * getmodename(enum testermode amode)
{
if (READ == amode) return "reader";
if (WRITE == amode) return "writer";
return "unknown";
}
int64_t getusecs()
{
struct timeval tv;
struct timezone tz;
gettimeofday(&tv, &tz);
return (tv.tv_sec * 1000000 + tv.tv_usec);
}
void print_timestamp()
{
struct tm *tmp;
time_t t;
char outstr[200];
t = time(NULL);
tmp = localtime(&t);

if (strftime(outstr, sizeof(outstr), "%H:%M:%S", tmp) == 0)
{
return;
}
printf("%s", outstr);
}
void read_block(int blockindex)
{
lseek(fh, blockindex * blocksize, SEEK_SET);
int64_t r = read(fh, &filebuffer, blocksize);

if (r <= 0)
{
printf("Error reading block %i\n", blockindex);
exit(1);
}
}
void write_block(int blockindex)
{
lseek(fh, blockindex * blocksize, SEEK_SET);
int64_t r = write(fh, &filebuffer, blocksize);

if (r <= 0)
{
printf("Error writing block %i\n", blockindex);
exit(1);
}
}
void run_worker() // generates disk writes
{
printf("Running %s...\n", getmodename(mode));
int bcnt = 0;
int64_t bytecnt = 0;
int n;

int64_t t1 = getusecs();
int64_t t2 = 0;
float interval = 0;
float speed = 0;

int64_t worktime = 0;

int64_t maxblocktime = 0;

while (1)
{
int64_t bwt1 = getusecs();
// some burst read
for (n = 1; n <= burstcount; n++)
{
int bi = rand() % blockcount;
int64_t sbt1 = getusecs();
if (WRITE == mode)
{
write_block(bi);
}
else
{
read_block(bi);
}
int64_t sblocktime = getusecs() - sbt1;
if (maxblocktime < sblocktime) maxblocktime = sblocktime;
bcnt++;
bytecnt += blocksize;
}
worktime += (getusecs() - bwt1);

// some wait
while (1)
{
t2 = getusecs();
interval = (float) (t2 - t1) / 1000000.;
speed = (float) bytecnt / (interval * 1024. * 1024.);

if ((speed > speedlimit) && (interval < 1))
{
usleep(100);
}
else
{
break;
}
}
if (interval >= 1)
{
float avgblocktime = (float) worktime / (float) bcnt;
print_timestamp();
printf(": speed: %8.3f MiB/s, time usage: %5.2f %%, avg. block time: %6.1f us, max. block time: %ld us\n",
speed,
100 * ((float) worktime / 1000000.) / interval,
avgblocktime,
maxblocktime
);
if (interval > 1.1)
{
printf(" Work was blocked for a long time! Test interval: %8.3f s\n", interval);
}
t1 = getusecs();
bcnt = 0;
bytecnt = 0;
worktime = 0;
maxblocktime = 0;
}
}
}
int main(int argc, char **argv)
{
struct stat sst;
srand(time(NULL));

printf("Linux kernel pdflush tester\n\n");
printf("Usage: pdflushtest --mode read|write --file filename\n");
printf("Options:\n --limit x : limit the maximal speed to x MiB/s\n");
printf(" --burst x : do the work with x block bursts\n\n");
parse_commandline(argc, argv);

printf("Current parameters: \n");
printf(" mode: %s\n", getmodename(mode));
printf(" file: %s\n", filename);
printf(" burst length: %i\n", burstcount);
printf(" speed limit: %f MiB/s\n", speedlimit);
printf("\n");
// getting scratchfile parameters
printf("Working file \"%s\":\n", filename);

if (stat(filename, &sst) == 0)
{
blocksize = sst.st_blksize;
blockcount = sst.st_size / blocksize;
printf(" size: %ld\n", sst.st_size);
printf(" blocksize: %i\n", blocksize);
printf(" number of blocks: %i\n", blockcount);
}
else
{
printf("Error getting info for file \"%s\"\n", filename);
exit(1);
}
printf("\n");

fh = open(filename, O_RDWR);
if (fh < 0)
{
printf("Error opening file \"%s\"\n", filename);
exit(1);
}
run_worker();

printf("finished.\n");

return 0;
}
\
 
 \ /
  Last update: 2012-10-09 12:41    [from the cache]
©2003-2011 Jasper Spaans