[Gluster-users] nfs bug when do dd write
shuau li
lishuai_ujs at 126.com
Fri Dec 12 03:33:18 UTC 2014
hi all,
I add some codes in glusterfs 3.6.1, this codes is used to print log when a lock be hold for more than 20 seconds.
Now I use two nodes to replay the problem, 192.168.51.115 and 192.168.51.116. I create a replica volume with 3 bricks in 51.115, than mount the volume in 51.116 and 51.115 at the same time, I run "dd if=/dev/zero of=/mnt/ida/data1 bs=128k" in 51.116 and "dd if=/dev/zero of=/mnt/ida/data2 bs=128k", several miniutes later, problem arise:
git diff
diff --git a/xlators/features/locks/src/inodelk.c b/xlators/features/locks/src/inodelk.c
index ef06531..cc46d21 100644
--- a/xlators/features/locks/src/inodelk.c
+++ b/xlators/features/locks/src/inodelk.c
@@ -192,6 +192,19 @@ __owner_has_lock (pl_dom_list_t *dom, pl_inode_lock_t *newlock)
return 0;
}
+void
+lock_timeout (void *p)
+{
+ pl_inode_lock_t *lock = (pl_inode_lock_t *)p;
+
+ gf_log (" ", GF_LOG_INFO,
+ "%s (pid=%d) lk-owner:%s %"PRId64" - %"PRId64" => 20s timeouted",
+ lock->fl_type == F_UNLCK ? "Unlock" : "Lock",
+ lock->client_pid,
+ lkowner_utoa (&lock->owner),
+ lock->user_flock.l_start,
+ lock->user_flock.l_len);
+}
/* Determines if lock can be granted and adds the lock. If the lock
* is blocking, adds it to the blocked_inodelks list of the domain.
@@ -202,6 +215,7 @@ __lock_inodelk (xlator_t *this, pl_inode_t *pl_inode, pl_inode_lock_t *lock,
{
pl_inode_lock_t *conf = NULL;
int ret = -EINVAL;
+ struct timespec tv = {0, };
conf = __inodelk_grantable (dom, lock);
if (conf) {
@@ -247,6 +261,8 @@ __lock_inodelk (xlator_t *this, pl_inode_t *pl_inode, pl_inode_lock_t *lock,
}
__pl_inodelk_ref (lock);
gettimeofday (&lock->granted_time, NULL);
+ tv.tv_sec = 20;
+ lock->timer = gf_timer_call_after (this->ctx, tv, lock_timeout, lock);
list_add (&lock->list, &dom->inodelk_list);
ret = 0;
@@ -298,6 +314,7 @@ __inode_unlock_lock (xlator_t *this, pl_inode_lock_t *lock, pl_dom_list_t *dom)
goto out;
}
__delete_inode_lock (conf);
+ if (conf->timer) gf_timer_call_cancel (this->ctx, conf->timer);
gf_log (this->name, GF_LOG_DEBUG,
" Matching lock found for unlock %llu-%llu, by %s on %p",
(unsigned long long)lock->fl_start,
@@ -460,6 +477,7 @@ pl_inodelk_client_cleanup (xlator_t *this, pl_ctx_t *ctx)
list_add_tail (&l->client_list,
&unwind);
}
+ if (l->timer) gf_timer_call_cancel (this->ctx, l->timer);
}
pthread_mutex_unlock (&pl_inode->mutex);
}
diff --git a/xlators/features/locks/src/locks.h b/xlators/features/locks/src/locks.h
index f761b3d..863f810 100644
--- a/xlators/features/locks/src/locks.h
+++ b/xlators/features/locks/src/locks.h
@@ -22,6 +22,7 @@
#include "client_t.h"
#include "lkowner.h"
+#include "timer.h"
struct __pl_fd;
@@ -82,6 +83,7 @@ struct __pl_inode_lock {
char *connection_id; /* stores the client connection id */
struct list_head client_list; /* list of all locks from a client */
+ gf_timer_t *timer;
};
typedef struct __pl_inode_lock pl_inode_lock_t;
diff --git a/xlators/features/locks/src/posix.c b/xlators/features/locks/src/posix.c
index af25a10..5b207e3 100644
--- a/xlators/features/locks/src/posix.c
+++ b/xlators/features/locks/src/posix.c
@@ -1745,6 +1745,7 @@ pl_forget (xlator_t *this,
"Pending inode locks found, releasing.");
list_for_each_entry_safe (ino_l, ino_tmp, &dom->inodelk_list, list) {
+ if (ino_l->timer) gf_timer_call_cancel (this->ctx, ino_l->timer);
__delete_inode_lock (ino_l);
__pl_inodelk_unref (ino_l);
}
[root at dcs115 d1]# ls -lh
total 21G
-rw-r--r-- 2 root root 14G Dec 10 14:18 data
-rw-r--r-- 2 root root 3.7G Dec 10 14:18 data2
dmesg:
nfs: server 192.168.100.115 not responding, still trying
nfs: server 192.168.100.115 not responding, still trying
nfs: server 192.168.100.115 not responding, still trying
nfs: server 192.168.100.115 not responding, still trying
nfs: server 192.168.100.115 not responding, still trying
nfs log:
[2014-12-10 06:15:44.109630] I [dht-common.c:1822:dht_lookup_cbk] 0-ida-dht: Entry /data missing on subvol ida-replicate-0
[2014-12-10 06:17:35.990049] I [dht-common.c:1822:dht_lookup_cbk] 0-ida-dht: Entry /data2 missing on subvol ida-replicate-0
[2014-12-10 06:19:41.234231] C [rpc-clnt-ping.c:109:rpc_clnt_ping_timer_expired] 0-ida-client-0: server 192.168.100.115:49152 has not responded in the last 42 seconds, disconnecting.
[2014-12-10 06:19:41.234347] C [rpc-clnt-ping.c:109:rpc_clnt_ping_timer_expired] 0-ida-client-1: server 192.168.100.115:49153 has not responded in the last 42 seconds, disconnecting.
[2014-12-10 06:19:42.234466] C [rpc-clnt-ping.c:109:rpc_clnt_ping_timer_expired] 0-ida-client-2: server 192.168.100.115:49154 has not responded in the last 42 seconds, disconnecting.
~
all bricks has the same logs:
[2014-12-10 06:16:05.196094] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:1c7f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:17:05.204617] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:1c7f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:17:41.207394] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:1c7f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.208998] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=1) lk-owner:1c7f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209057] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=1) lk-owner:1c7f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209070] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=1) lk-owner:1c7f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209080] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=1) lk-owner:1c7f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209090] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:887f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209100] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:887f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209111] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:887f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209122] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:887f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209132] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:887f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209143] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:887f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:18:07.209153] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=0) lk-owner:887f1b0200000000 0 - 0 => 20s timeouted
[2014-12-10 06:19:03.224007] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=-6) lk-owner:80823be0627f0000 0 - 0 => 20s timeouted
[2014-12-10 06:19:07.224577] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=-6) lk-owner:a45e3be0627f0000 0 - 0 => 20s timeouted
[2014-12-10 06:19:41.234401] W [socket.c:1244:__socket_read_simple_msg] 0-tcp.ida-server: reading from socket failed. Error (No data available), peer (192.168.100.115:947)
[2014-12-10 06:19:41.234513] I [server.c:518:server_rpc_notify] 0-ida-server: disconnecting connection from dcs115-3200-2014/12/10-06:14:38:192810-ida-client-0-0-0
[2014-12-10 06:19:41.234560] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on 3c841f93-c637-4119-a7a8-0b39871a0956 held by {client=0x209d290, pid=1 lk-owner=1c7f1b0200000000}
[2014-12-10 06:19:41.234593] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on 3c841f93-c637-4119-a7a8-0b39871a0956 held by {client=0x209d290, pid=1 lk-owner=1c7f1b0200000000}
[2014-12-10 06:19:41.234619] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on 3c841f93-c637-4119-a7a8-0b39871a0956 held by {client=0x209d290, pid=1 lk-owner=1c7f1b0200000000}
[2014-12-10 06:19:41.234645] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on 3c841f93-c637-4119-a7a8-0b39871a0956 held by {client=0x209d290, pid=1 lk-owner=1c7f1b0200000000}
[2014-12-10 06:19:41.234670] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on be43df9a-b6dd-4745-aff4-e8162c5e9f6f held by {client=0x209d290, pid=0 lk-owner=887f1b0200000000}
[2014-12-10 06:19:41.234697] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on be43df9a-b6dd-4745-aff4-e8162c5e9f6f held by {client=0x209d290, pid=0 lk-owner=887f1b0200000000}
[2014-12-10 06:19:41.234722] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on be43df9a-b6dd-4745-aff4-e8162c5e9f6f held by {client=0x209d290, pid=0 lk-owner=887f1b0200000000}
[2014-12-10 06:19:41.234747] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on be43df9a-b6dd-4745-aff4-e8162c5e9f6f held by {client=0x209d290, pid=0 lk-owner=887f1b0200000000}
[2014-12-10 06:19:41.234779] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on be43df9a-b6dd-4745-aff4-e8162c5e9f6f held by {client=0x209d290, pid=0 lk-owner=887f1b0200000000}
[2014-12-10 06:19:41.234823] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on be43df9a-b6dd-4745-aff4-e8162c5e9f6f held by {client=0x209d290, pid=0 lk-owner=887f1b0200000000}
[2014-12-10 06:19:41.234845] W [inodelk.c:409:pl_inodelk_log_cleanup] 0-ida-server: releasing lock on be43df9a-b6dd-4745-aff4-e8162c5e9f6f held by {client=0x209d290, pid=0 lk-owner=887f1b0200000000}
[2014-12-10 06:19:41.235008] I [client_t.c:417:gf_client_unref] 0-ida-server: Shutting down connection dcs115-3200-2014/12/10-06:14:38:192810-ida-client-0-0-0
[2014-12-10 06:20:02.270229] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=-6) lk-owner:80823be0627f0000 9223372036854775805 - 1 => 20s timeouted
[2014-12-10 06:20:02.270267] I [inodelk.c:206:lock_timeout] 0- : Lock (pid=-6) lk-owner:a45e3be0627f0000 9223372036854775805 - 1 => 20s timeouted
在 2014-12-09 17:43:41，"Raghavendra Bhat" <rabhat at redhat.com> 写道：
On Tuesday 09 December 2014 02:47 PM, shuau li wrote:
hi all,
In my environment, I meet a nfs problem.When I do dd write for a while, nfs client will report "nfs server no responding".I think this maybe a bug of nfs server, Is anybody meet similar problem?
The details of my environment and test are as follow:
glusterfs version:
3.6.1
3 nodes:
cpu with 8 core 3.20 GHz, 16 GB memory, 10000baseT/Full network card
I use two nodes create a replica volume with two bricks, another nodes act as client, client use protocol nfs3 to mount volume through the 10000baseT/Full network card, then use command "dd if=/dev/zero of=/mnt/ida/testdata bs=128k" to write data.
Generally, onlydataabout10G can be write successfully. Then client will say "nfs server ip no responding".At the same time, I use gdb to trace nfs process in nfs server, the result is that nfs server keeps staying in epoll_wait, why nfs server can not listen requests from nfs client ?
In addition, I noticed the difference between fuse and nfs. When access through fuse, two threads will work together, one responsible for fuse-bridge, another responsible for listening socket. But in nfs, only one thread work in background, both responsible for nfs server and listening socket. Will the cause process bottleneck?
Best wishes！！
Looking forward to yourreply！
Hi,
Can you please attach the nfs server and brick log files? You can find the log files in /var/log/glusterfs.
Regards,
Raghavendra Bhat
_______________________________________________
Gluster-users mailing list
Gluster-users at gluster.orghttp://supercolony.gluster.org/mailman/listinfo/gluster-users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://supercolony.gluster.org/pipermail/gluster-users/attachments/20141212/027584de/attachment.html>
More information about the Gluster-users
mailing list