[Gluster-users] locking in 3.6.1

Tue Nov 25 13:38:09 UTC 2014

On 11/24/14, 11:56 PM, Atin Mukherjee wrote:
> Can you please find/point out the first instance of the command and its
> associated glusterd log which failed to acquire the cluster wide lock.

Can you help me identify what I should be looking for in the logs?

I restarted the glusterd service and see the following on server gluster2:

[2014-11-25 13:34:50.552695] W [glusterfsd.c:1194:cleanup_and_exit] (-->
0-: received signum (15), shutting down
[2014-11-25 13:34:50.569445] I [MSGID: 100030] [glusterfsd.c:2018:main]
0-/usr/sbin/glusterd: Started running /usr/sbin/glusterd version 3.6.1
(args: /usr/sbin/glusterd -p /var/run/glusterd.pid)
[2014-11-25 13:34:50.576951] I [glusterd.c:1214:init] 0-management:
Maximum allowed open file descriptors set to 65536
[2014-11-25 13:34:50.577008] I [glusterd.c:1259:init] 0-management:
Using /var/lib/glusterd as working directory
[2014-11-25 13:34:50.581436] E [rpc-transport.c:266:rpc_transport_load]
0-rpc-transport: /usr/lib64/glusterfs/3.6.1/rpc-transport/rdma.so:
cannot open shared object file: No such file or directory
[2014-11-25 13:34:50.581469] W [rpc-transport.c:270:rpc_transport_load]
0-rpc-transport: volume 'rdma.management': transport-type 'rdma' is not
valid or not found on this machine
[2014-11-25 13:34:50.581486] W [rpcsvc.c:1524:rpcsvc_transport_create]
0-rpc-service: cannot create listener, initing the transport failed
[2014-11-25 13:34:50.583680] I
[glusterd.c:413:glusterd_check_gsync_present] 0-glusterd:
geo-replication module not installed in the system
[2014-11-25 13:34:50.584503] I
[glusterd-store.c:2043:glusterd_restore_op_version] 0-glusterd:
retrieved op-version: 30501
[2014-11-25 13:34:51.074904] I
[glusterd-handler.c:3146:glusterd_friend_add_from_peerinfo]
0-management: connect returned 0
[2014-11-25 13:34:51.075024] I
[glusterd-handler.c:3146:glusterd_friend_add_from_peerinfo]
0-management: connect returned 0
[2014-11-25 13:34:51.075107] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:51.082647] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:51.089136] I
[glusterd-store.c:3501:glusterd_store_retrieve_missed_snaps_list]
0-management: No missed snaps list.
[2014-11-25 13:34:51.094388] I [glusterd.c:146:glusterd_uuid_init]
0-management: retrieved UUID: 23989211-4f0d-4087-b9c5-bc82295b2c38
Final graph:
+------------------------------------------------------------------------------+
  1: volume management
  2:     type mgmt/glusterd
  3:     option rpc-auth.auth-glusterfs on
  4:     option rpc-auth.auth-unix on
  5:     option rpc-auth.auth-null on
  6:     option transport.socket.listen-backlog 128
  7:     option ping-timeout 30
  8:     option transport.socket.read-fail-log off
  9:     option transport.socket.keepalive-interval 2
 10:     option transport.socket.keepalive-time 10
 11:     option transport-type rdma
 12:     option working-directory /var/lib/glusterd
 13: end-volume
 14:
+------------------------------------------------------------------------------+
[2014-11-25 13:34:57.330091] W [socket.c:611:__socket_rwv] 0-management:
readv on 192.168.30.107:24007 failed (No data available)
[2014-11-25 13:34:57.330583] E [rpc-clnt.c:362:saved_frames_unwind] (-->
/lib64/libglusterfs.so.0(_gf_log_callingfn+0x186)[0x7f7065b04396] (-->
/lib64/libgfrpc.so.0(saved_frames_unwind+0x1de)[0x7f70658d6fce] (-->
/lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7f70658d70de] (-->
/lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0x82)[0x7f70658d8a42]
(--> /lib64/libgfrpc.so.0(rpc_clnt_notify+0x48)[0x7f70658d91f8] )))))
0-management: forced unwinding frame type(Peer mgmt) op(--(2)) called at
2014-11-25 13:34:51.150255 (xid=0x5)
[2014-11-25 13:34:57.330641] I [MSGID: 106004]
[glusterd-handler.c:4365:__glusterd_peer_rpc_notify] 0-management: Peer
bb61111b-b048-4dc9-b54d-12a0cc2dd8a9, in Peer in Cluster state, has
disconnected from glusterd.
[2014-11-25 13:34:57.338507] I
[glusterd-rpc-ops.c:436:__glusterd_friend_add_cbk] 0-glusterd: Received
ACC from uuid: 60b2251f-2d69-41a6-91da-fd3f14c5a1e6, host:
gluster3.innova.local, port: 0
[2014-11-25 13:34:57.361000] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:57.361306] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:57.361535] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:57.361781] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:57.362014] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:57.362241] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:57.362458] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:57.369468] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:58.379351] I [rpc-clnt.c:969:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2014-11-25 13:34:58.379587] W [socket.c:2992:socket_connect]
0-management: Ignore failed connection attempt on , (No such file or
directory)
[2014-11-25 13:34:58.413871] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/9bdd01b8b5f546ce04b25ce7d68e3ace.socket failed
(Invalid argument)
[2014-11-25 13:34:58.413933] I [MSGID: 106006]
[glusterd-handler.c:4257:__glusterd_nodesvc_rpc_notify] 0-management:
nfs has disconnected from glusterd.
[2014-11-25 13:34:58.414015] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/2df1fa6567b898d24c7d5f4c98b073a2.socket failed
(Invalid argument)
[2014-11-25 13:34:58.414047] I [MSGID: 106006]
[glusterd-handler.c:4257:__glusterd_nodesvc_rpc_notify] 0-management:
glustershd has disconnected from glusterd.
[2014-11-25 13:34:58.414832] I
[glusterd-handshake.c:1061:__glusterd_mgmt_hndsk_versions_ack]
0-management: using the op-version 30501
[2014-11-25 13:34:58.436428] I
[glusterd-handler.c:2216:__glusterd_handle_incoming_friend_req]
0-glusterd: Received probe from uuid: bb61111b-b048-4dc9-b54d-12a0cc2dd8a9
[2014-11-25 13:35:00.572692] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/9bdd01b8b5f546ce04b25ce7d68e3ace.socket failed
(Invalid argument)
[2014-11-25 13:35:00.608802] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /bricks/criteria1/brick on port 49162
[2014-11-25 13:35:00.781618] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /bricks/admin1/brick on port 49161
[2014-11-25 13:35:00.972159] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /bricks/integration/epa/brick on port 49159
[2014-11-25 13:35:01.089892] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /bricks/epa1/brick on port 49160
[2014-11-25 13:35:01.094994] I
[glusterd-handler.c:2373:__glusterd_handle_friend_update] 0-glusterd:
Received friend update from uuid: 60b2251f-2d69-41a6-91da-fd3f14c5a1e6
[2014-11-25 13:35:01.095056] I
[glusterd-handler.c:2416:__glusterd_handle_friend_update] 0-management:
Received my uuid as Friend
[2014-11-25 13:35:01.095074] I
[glusterd-handler.c:2416:__glusterd_handle_friend_update] 0-management:
Received my uuid as Friend
[2014-11-25 13:35:01.095310] I
[glusterd-handler.c:3334:glusterd_xfer_friend_add_resp] 0-glusterd:
Responded to gluster1.innova.local (0), ret: 0
[2014-11-25 13:35:01.134052] I
[glusterd-rpc-ops.c:633:__glusterd_friend_update_cbk] 0-management:
Received ACC from uuid: 60b2251f-2d69-41a6-91da-fd3f14c5a1e6
[2014-11-25 13:35:01.136058] I
[glusterd-handshake.c:1061:__glusterd_mgmt_hndsk_versions_ack]
0-management: using the op-version 30501
[2014-11-25 13:35:01.156932] I
[glusterd-handler.c:2216:__glusterd_handle_incoming_friend_req]
0-glusterd: Received probe from uuid: 60b2251f-2d69-41a6-91da-fd3f14c5a1e6
[2014-11-25 13:35:01.157314] I
[glusterd-handler.c:3334:glusterd_xfer_friend_add_resp] 0-glusterd:
Responded to gluster3.innova.local (0), ret: 0
[2014-11-25 13:35:01.196912] I
[glusterd-handshake.c:1061:__glusterd_mgmt_hndsk_versions_ack]
0-management: using the op-version 30501
[2014-11-25 13:35:01.210446] I
[glusterd-rpc-ops.c:633:__glusterd_friend_update_cbk] 0-management:
Received ACC from uuid: 60b2251f-2d69-41a6-91da-fd3f14c5a1e6
[2014-11-25 13:35:01.211188] I
[glusterd-handler.c:2216:__glusterd_handle_incoming_friend_req]
0-glusterd: Received probe from uuid: 60b2251f-2d69-41a6-91da-fd3f14c5a1e6
[2014-11-25 13:35:01.211587] I
[glusterd-handler.c:3334:glusterd_xfer_friend_add_resp] 0-glusterd:
Responded to gluster3.innova.local (0), ret: 0
[2014-11-25 13:35:01.246642] I
[glusterd-rpc-ops.c:633:__glusterd_friend_update_cbk] 0-management:
Received ACC from uuid: 60b2251f-2d69-41a6-91da-fd3f14c5a1e6
[2014-11-25 13:35:01.283379] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /bricks/integration/criteria/brick on port 49164
[2014-11-25 13:35:01.425581] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /bricks/store1/brick on port 49165
[2014-11-25 13:35:01.529235] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /bricks/forms1/brick on port 49163
[2014-11-25 13:35:03.573038] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/9bdd01b8b5f546ce04b25ce7d68e3ace.socket failed
(Invalid argument)
[2014-11-25 13:35:06.573340] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/9bdd01b8b5f546ce04b25ce7d68e3ace.socket failed
(Invalid argument)
[2014-11-25 13:35:07.623762] I
[glusterd-rpc-ops.c:436:__glusterd_friend_add_cbk] 0-glusterd: Received
ACC from uuid: bb61111b-b048-4dc9-b54d-12a0cc2dd8a9, host:
gluster1.innova.local, port: 0
[2014-11-25 13:35:07.641170] I
[glusterd-handler.c:2373:__glusterd_handle_friend_update] 0-glusterd:
Received friend update from uuid: bb61111b-b048-4dc9-b54d-12a0cc2dd8a9
[2014-11-25 13:35:07.641226] I
[glusterd-handler.c:2416:__glusterd_handle_friend_update] 0-management:
Received my uuid as Friend
[2014-11-25 13:35:08.041722] I
[glusterd-handler.c:2373:__glusterd_handle_friend_update] 0-glusterd:
Received friend update from uuid: bb61111b-b048-4dc9-b54d-12a0cc2dd8a9
[2014-11-25 13:35:08.041778] I
[glusterd-handler.c:2416:__glusterd_handle_friend_update] 0-management:
Received my uuid as Friend
[2014-11-25 13:35:08.103189] I
[glusterd-handler.c:2373:__glusterd_handle_friend_update] 0-glusterd:
Received friend update from uuid: bb61111b-b048-4dc9-b54d-12a0cc2dd8a9
[2014-11-25 13:35:08.103245] I
[glusterd-handler.c:2416:__glusterd_handle_friend_update] 0-management:
Received my uuid as Friend
[2014-11-25 13:35:09.580234] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/9bdd01b8b5f546ce04b25ce7d68e3ace.socket failed
(Invalid argument)
[2014-11-25 13:35:12.580567] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/9bdd01b8b5f546ce04b25ce7d68e3ace.socket failed
(Invalid argument)
[2014-11-25 13:35:15.580900] W [socket.c:611:__socket_rwv] 0-management:
readv on /var/run/9bdd01b8b5f546ce04b25ce7d68e3ace.socket failed
(Invalid argument)

> There are few cases related to rebalance commands where we may end up
> having stale locks, have you performed rebalance in between?

All of the volumes on this server pair are replica 2 volumes, so there
should be nothing to rebalance.  I have not explicitly performed any
rebalance commands.

Thanks,
Scott