Description of problem: Gluster volume has 4 bricks on 2 servers, two from each server. Volume Name: gluster0 Type: Distributed-Replicate Number of Bricks: 2 x 2 = 4 On the client, access is via FUSE. Starting from a fresh state, I'm seeing ~25MB/s synced transfer rate to a loop device backed by a file on Gluster. dd if=/dev/zero of=/dev/loop1 bs=1024k count=2000 oflag=sync 2097152000 bytes (2.1 GB) copied, 81.7174 s, 25.7 MB/s Using "volume profile" shows us that most writes are done with 32kb requests. After some time, I've seen it mostly around 24 hours, the transfer rate drops down to around 10% of the original rate. dd if=/dev/zero of=/dev/loop1 bs=1024k count=2000 oflag=sync 1156579328 bytes (1.2 GB) copied, 353.585 s, 3.3 MB/s Using "volume profile" shows us that all writes are now 4kb requests. If we toggle any setting using "gluster volume set", the original transfer rate is re-established. In addition, unmapping and remapping the loop device also brings back the original transfer rate. This seems to work even for long-lived FD's, for example on a running Xen instance where the disk is a loop device backed by a file on Gluster. Version-Release number of selected component (if applicable): OS is Debian stable, some with kernels from backports. Kernels are 2.6.32-46 and 3.2.35-2~bpo60+1. Gluster is at 3.3.1-1, it's installed from Gluster Debian repo. How reproducible: I see it happen every night, although not always at the same time. I'm guessing it happens after some amount of time, not dependent on walltime. Steps to Reproduce: 1. Set up a loop device backed by a file on Gluster, test and see high xfer rates 2. Wait for some time, maybe 24 hours 3. Test xfer rate on loop device, see low transfer rates 4. Adjust some setting, or remap loop device 5. Test xfer rate on loop device, see high transfer rates Actual results: Transfer rates are really slow, all writes in "gluster profile" are 4kb Expected results: "Reasonable" transfer rates Additional info: There has been some discussion about this on the mailing list. http://supercolony.gluster.org/pipermail/gluster-users/2013-February/035558.html http://supercolony.gluster.org/pipermail/gluster-users/2013-March/035621.html
I want to add that this situation seems to happen per-fd. Newly created loop devices are always fast, even if I have a slow and "old" loop already created.
After setting the logging level to DEBUG, I found some log entries which seem to correspond with the performance degradation. torbjorn@xen-storage01:~$ grep 'disabling wb' glusterfs.log -B 2 [2013-03-08 01:11:43.428095] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-0: Source selected as 0 for /hennec.vps.trollweb.net/disk0 [2013-03-08 01:11:43.428110] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-0: Building lookup response from 0 [2013-03-08 01:11:43.452718] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc [2013-03-08 01:11:43.470332] D [write-behind.c:1349:wb_disable_all] 4-gluster0-write-behind: disabling wb on 0x7f7139c23abc because 0x7f71249023cc is O_SYNC -- [2013-03-08 01:24:22.051955] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-1: Source selected as 0 for /iotest.trollweb.net/disk0 [2013-03-08 01:24:22.051985] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-1: Building lookup response from 0 [2013-03-08 01:24:22.052691] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc -- [2013-03-08 01:26:22.112784] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-1: Source selected as 1 for /tmp/bigfile [2013-03-08 01:26:22.112798] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-1: Building lookup response from 1 [2013-03-08 01:26:22.114299] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc -- [2013-03-08 01:26:52.177231] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-0: Source selected as 1 for /tmp/fila [2013-03-08 01:26:52.177245] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-0: Building lookup response from 1 [2013-03-08 01:26:52.179240] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc -- [2013-03-08 01:27:13.734188] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-1: Source selected as 1 for /tmp/loopback.img [2013-03-08 01:27:13.734202] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-1: Building lookup response from 1 [2013-03-08 01:27:13.735775] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc [2013-03-08 01:27:13.735796] D [write-behind.c:1349:wb_disable_all] 4-gluster0-write-behind: disabling wb on 0x7f7139c23b20 because 0x7f71249023cc is O_SYNC -- [2013-03-08 01:27:44.260709] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-0: Source selected as 0 for /tmp/loopback2.img [2013-03-08 01:27:44.260724] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-0: Building lookup response from 0 [2013-03-08 01:27:44.261945] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc -- [2013-03-08 01:28:18.834794] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-0: Source selected as 1 for /tmp/loopback3.img [2013-03-08 01:28:18.834810] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-0: Building lookup response from 1 [2013-03-08 01:28:18.836625] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc -- [2013-03-08 01:29:09.427066] D [afr-common.c:1294:afr_lookup_select_read_child] 4-gluster0-replicate-1: Source selected as 0 for /tmp/loopback4.img [2013-03-08 01:29:09.427080] D [afr-common.c:1097:afr_lookup_build_response_params] 4-gluster0-replicate-1: Building lookup response from 0 [2013-03-08 01:29:09.427915] D [write-behind.c:1392:wb_open_cbk] 4-gluster0-write-behind: disabling wb on 0x7f71249023cc
3.4.0-alpha2 has now been running for a couple of days, and I'm not experiencing the performance degradation on that version.
Closing the bug as per comment-3