[Gluster-users] Very slow ls

[Franco Broi]

________________________________________
From: Vijay Bellur [vbellur at redhat.com]
Sent: Monday, February 17, 2014 10:13 AM
To: Franco Broi; gluster-users at gluster.org
Subject: Re: [Gluster-users] Very slow ls

On 02/17/2014 07:00 AM, Franco Broi wrote:
>
> I mounted the filesystem with trace logging turned on and can see that
> after the last successful READDIRP there is a lot of other connections
> being made the clients repeatedly which takes minutes to complete.

> I did not observe anything specific which points to clients repeatedly
> reconnecting. Can you point to the appropriate line numbers for this?

This is the READDIRP that returned the last entry in the directory:

[2014-02-17 01:21:20.828742] T [fuse-bridge.c:2594:fuse_readdirp_cbk] 0-glusterfs-fuse: 34: READDIRP => 11/4096,8498796000
[2014-02-17 01:21:20.828877] T [fuse-bridge.c:2672:fuse_readdirp_resume] 0-glusterfs-fuse: 35: READDIRP (0x10ddb2c, size=4096, offset=8581931696)


and this is the READDIRP that returns NULL:

[2014-02-17 01:22:53.823017] T [fuse-bridge.c:2594:fuse_readdirp_cbk] 0-glusterfs-fuse: 35: READDIRP => 0/4096,8581931696
[2014-02-17 01:22:53.823396] T [fuse-bridge.c:2720:fuse_releasedir] 0-glusterfs-fuse: 36: RELEASEDIR 0x10ddb2c

note how long it took to complete .

> Can you also please describe the directory structure being referred here?

The directory being read itself contains about 600 other directories.

Here's another example of what I'm seeing:

[franco at charlie9 02_postwib]$ time set list=*
0.006u 0.030s 3:31.36 0.0%      0+0k 0+0io 0pf+0w

[franco at charlie9 02_postwib]$ echo $list | wc -w
607

This took 3.5 minutes to list the ~600 directories

[franco at charlie9 02_postwib]$ time ls -d $list
....
0.012u 0.024s 0:33.54 0.0%      0+0k 0+0io 0pf+0w

listing the directory contents explicitly takes 34 seconds.  All the wasted time is in waiting for the last readdir call to return NULL.

This is a very serious problem for us, it makes Gluster almost unusable.

This is my perl script I've been using to test and which produced the log file you've been looking at.

$dir=shift();

opendir(D, "$dir");
$then=time();
while($file=readdir(D)){
    print "$file ",time()-$then,"\n";
    $then=time();
}
print  "last ",time()-$then,"\n";
print $?, "\n";


And this is what it produces, note the directory names are 8 digit numbers.

[franco at charlie9 02_postwib]$ perl ~/dir.pl .
. 0
.. 0
12578248 0
32958783 0
98841022 0
87252299 0
90090733 0
79566203 0
47155616 0
72790643 0
....
98841018 0
15174257 0
24310895 0
last 106
0

It took 106 seconds to return NULL for the last readdir call.

Hope this helps explain my predicament.

Cheers,

________________________________


This email and any files transmitted with it are confidential and are intended solely for the use of the individual or entity to whom they are addressed. If you are not the original recipient or the person responsible for delivering the email to the intended recipient, be advised that you have received this email in error, and that any use, dissemination, forwarding, printing, or copying of this email is strictly prohibited. If you received this email in error, please immediately notify the sender and delete the original.