Hi,
I have 2 questions about a Straceoutput of Glusterfs I hope someone can
help me to understand.
We have a Webserver who is requesting files from a Gluserfs mount, and
sometimes it takes a lot of time to get the content so we died a strace
-f on the glusterfs process on each of the glusterfs servers at the same
time to see what took him so long to answer.
We found out that
1. each of the Glusterfs Servers do an open on the file witch is
requested.
Why is the open done on both servers an witch one delivers the
file ??
2. in the strace there is one call that seem to take very long ( <...
lstat resumed> {st_mode=S_IFREG|0644, st_size=4314, ...}) = 0
<0.393390> )but just on one server,what does this mean and what is
this doing. Can anyone tell me why this take so long ?
The Strace :
auszug vom strace vom gfs am vgfs-01-001:
----------------
11709 18:12:18.824980
lstat("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
<unfinished ...>
11709 18:12:19.218386 <... lstat resumed> {st_mode=S_IFREG|0644,
st_size=4314, ...}) = 0 <0.393390>
11709 18:12:19.218431
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.posix.gen", "LR\xdc\xd5\x00\xe1\x06\xea", 8) = 8 <0.000010>
11709 18:12:19.218472
open("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg", O_RDONLY)
= 45 <0.000031>
11709 18:12:19.218533 read(45,
"\377\330\377\340\0\20JFIF\0\1\1\0\0\1\0\1\0\0\377\376\0>CREATOR:"...,
4314) = 4314 <0.037724>
11709 18:12:19.256296 close(45) = 0 <0.000005>
11709 18:12:19.256330
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute1", 0x0, 0) = 12 <0.000008>
11709 18:12:19.256367
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute1",
"\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", 12) = 12 <0.000007>
11709 18:12:19.256405
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute2", 0x0, 0) = 12 <0.000029>
11709 18:12:19.256465
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute2",
"\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", 12) = 12 <0.000025>
11709 18:12:19.256526
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"glusterfs.inodelk-count", 0x0, 0) = -1 EOPNOTSUPP (Operation not
supported) <0.000007>
11709 18:12:19.256564
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"glusterfs.entrylk-count", 0x0, 0) = -1 EOPNOTSUPP (Operation not
supported) <0.000008>
11709 18:12:19.256613
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.glusterfs.dht", 0x0, 0) = -1 ENODATA (No data available) <0.000027>
11709 18:12:19.256669
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.glusterfs.dht.linkto", 0x0, 0) = -1 ENODATA (No data available)
<0.000024>
11709 18:12:19.256725
lstat("/gluster-storage/macm01//videos07/15535/preview",
{st_mode=S_IFDIR|0777, st_size=20480, ...}) = 0 <0.000006>
11709 18:12:19.256766
lgetxattr("/gluster-storage/macm01//videos07/15535/preview",
"trusted.posix.gen", "LR\xdc\xd5\x00\xe0\xf3\xb6", 8) = 8 <0.000008>
11709 18:12:19.256815 writev(9, [{":O\0\0\0\22\306\0\0\0\0*", 12},
{"\0\0\0\0\0\21\210\315\0\0\0\4\0\0\0\33\0\0\22Z\0\0\0\0\0\0\0\26\0\0\0\0"...,
4806}], 2) = 4818 <0.000019>
11709 18:12:19.256884 futex(0x613be8, FUTEX_WAIT_PRIVATE, 0, {179,
743122000} <unfinished ...>
11709 18:12:19.434375 <... futex resumed> ) = 0 <0.177477>
----------------
auszug vom strace vom gfs am vgfs-01-002:
----------------
14254 18:12:18.825614
lstat("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
<unfinished ...>
14254 18:12:18.901377 <... lstat resumed> {st_mode=S_IFREG|0644,
st_size=4314, ...}) = 0 <0.075746>
14254 18:12:18.901434
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.posix.gen", "LR\xdc\xdd\x00\xe1\x06\xef", 8) = 8 <0.000010>
14254 18:12:18.901481
open("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg", O_RDONLY)
= 51 <0.000082>
14254 18:12:18.901594 read(51, <unfinished ...>
14254 18:12:18.914166 <... read resumed>
"\377\330\377\340\0\20JFIF\0\1\1\0\0\1\0\1\0\0\377\376\0>CREATOR:"...,
4314) = 4314 <0.012298>
14254 18:12:18.914192 close(51) = 0 <0.000005>
14254 18:12:18.914218
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute1", 0x0, 0) = 12 <0.000009>
14254 18:12:18.914255
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute1",
"\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", 12) = 12 <0.000008>
14254 18:12:18.914293
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute2", 0x0, 0) = 12 <0.000078>
14254 18:12:18.914405
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.afr.distribute2",
"\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", 12) = 12 <0.000077>
14254 18:12:18.914521
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"glusterfs.inodelk-count", 0x0, 0) = -1 EOPNOTSUPP (Operation not
supported) <0.000007>
14254 18:12:18.914559
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"glusterfs.entrylk-count", 0x0, 0) = -1 EOPNOTSUPP (Operation not
supported) <0.000008>
14254 18:12:18.914614
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.glusterfs.dht", 0x0, 0) = -1 ENODATA (No data available) <0.000077>
14254 18:12:18.914725
lgetxattr("/gluster-storage/macm01//videos07/15535/preview/49be466c51d05.jpg",
"trusted.glusterfs.dht.linkto", 0x0, 0) = -1 ENODATA (No data available)
<0.000076>
----------------
THX
