[Gluster-devel] Connect taking a loooong time on loopback

Sebastien LELIEVRE slelievre at tbs-internet.com
Fri Jul 13 13:41:13 UTC 2007


Hi everyone,

I'm begining glusterfs integration on our new datacenter, and my really
first tests show me really odd things, just see :

Client:

volume brickc
  type protocol/client
  option transport-type tcp/client
  option remote-host 127.0.0.1
  option remote-port 6996
  option remote-subvolume brick
end-volume


Server:

volume brick
  type storage/posix
  option directory /home/slelievre/gluster-test/server1
end-volume

volume server
  type protocol/server
  option transport-type tcp/server
  option bind-address 127.0.0.1
  option listen-port 6996
  subvolumes brick
  option auth.ip.brick.allow *
end-volume


As you can see on the log below, the client took nearly 10 mins to
connect to the server, and connection was broken a little after.

We are running on mainline-2.5 patch 266 with fuse 2.6.5 and kernel
2.6.16 'customed' to our needs

Is this a 'bug' ? If so, is it fixed on latest versions ?

Cheers,

Sebastien.

logs are :

Server-side :

2007-07-13 12:46:37 D [spec.y:116:new_section] libglusterfs/parser: New
node for 'brick'
2007-07-13 12:46:37 D [spec.y:132:section_type] libglusterfs/parser:
Type:brick:storage/posix
2007-07-13 12:46:37 D [xlator.c:100:xlator_set_type]
libglusterfs/xlator: attempt to load type storage/posix
2007-07-13 12:46:37 D [xlator.c:107:xlator_set_type]
libglusterfs/xlator: attempt to load file
/usr/lib/glusterfs/1.3.0-pre5.2/xlator/storage/posix.so
2007-07-13 12:46:37 D [spec.y:152:section_option] libglusterfs/parser:
Option:brick:directory:/home/slelievre/gluster-test/server1
2007-07-13 12:46:37 D [spec.y:209:section_end] libglusterfs/parser:
end:brick
2007-07-13 12:46:37 D [spec.y:116:new_section] libglusterfs/parser: New
node for 'server'
2007-07-13 12:46:37 D [spec.y:132:section_type] libglusterfs/parser:
Type:server:protocol/server
2007-07-13 12:46:37 D [xlator.c:100:xlator_set_type]
libglusterfs/xlator: attempt to load type protocol/server
2007-07-13 12:46:37 D [xlator.c:107:xlator_set_type]
libglusterfs/xlator: attempt to load file
/usr/lib/glusterfs/1.3.0-pre5.2/xlator/protocol/server.so
2007-07-13 12:46:37 D [spec.y:152:section_option] libglusterfs/parser:
Option:server:transport-type:tcp/server
2007-07-13 12:46:37 D [spec.y:152:section_option] libglusterfs/parser:
Option:server:bind-address:127.0.0.1
2007-07-13 12:46:37 D [spec.y:152:section_option] libglusterfs/parser:
Option:server:listen-port:6996
2007-07-13 12:46:37 D [spec.y:194:section_sub] liglusterfs/parser:
child:server->brick
2007-07-13 12:46:37 D [spec.y:152:section_option] libglusterfs/parser:
Option:server:auth.ip.brick.allow:*
2007-07-13 12:46:37 D [spec.y:209:section_end] libglusterfs/parser:
end:server
2007-07-13 12:46:37 D [posix.c:1776:init] brick: missing
'inode-lru-limit'. defaulting to 1000
2007-07-13 12:46:37 D [inode.c:481:__create_inode] brick/inode: create
inode(1)
2007-07-13 12:46:37 D [inode.c:279:__active_inode] brick/inode:
activating inode(1), lru=0/1000
2007-07-13 12:46:37 D [server-protocol.c:5670:init] protocol/server:
protocol/server xlator loaded
2007-07-13 12:46:37 D [transport.c:81:transport_load]
libglusterfs/transport: attempt to load type tcp/server
2007-07-13 12:46:37 D [transport.c:86:transport_load]
libglusterfs/transport: attempt to load file
/usr/lib/glusterfs/1.3.0-pre5.2/transport/tcp/server.so
2007-07-13 12:46:50 D [tcp-server.c:136:tcp_server_notify] server:
Registering socket (8) for new transport object of 127.0.0.1
2007-07-13 12:46:50 D [server-protocol.c:5024:mop_setvolume]
server-protocol: mop_setvolume: received port = 1023
2007-07-13 12:46:50 D [server-protocol.c:5040:mop_setvolume]
server-protocol: mop_setvolume: IP addr = *, received ip addr = 127.0.0.1
2007-07-13 12:46:50 D [server-protocol.c:5051:mop_setvolume]
server-protocol: mop_setvolume: accepted client from 127.0.0.1
2007-07-13 12:49:07 D [server-protocol.c:5649:server_protocol_cleanup]
protocol/server: cleaned up xl_private of 0x8054330
2007-07-13 12:49:07 C [tcp.c:81:tcp_disconnect] server: connection
disconnected
2007-07-13 12:49:07 D [tcp-server.c:230:gf_transport_fini] server:
destroying transport object for 127.0.0.1:1023 (fd=8)
2007-07-13 12:52:15 D [tcp-server.c:136:tcp_server_notify] server:
Registering socket (5) for new transport object of 127.0.0.1
2007-07-13 12:52:15 D [server-protocol.c:5024:mop_setvolume]
server-protocol: mop_setvolume: received port = 1023
2007-07-13 12:52:15 D [server-protocol.c:5040:mop_setvolume]
server-protocol: mop_setvolume: IP addr = *, received ip addr = 127.0.0.1
2007-07-13 12:52:15 D [server-protocol.c:5051:mop_setvolume]
server-protocol: mop_setvolume: accepted client from 127.0.0.1

Client-side:

2007-07-13 12:52:15 D [glusterfs.c:118:get_spec_fp] glusterfs: loading
spec from /etc/glusterfs/glusterfs-basic.vol
2007-07-13 12:52:15 W [fuse-bridge.c:1887:fuse_transport_notify]
glusterfs-fuse: Ignoring notify event 4
2007-07-13 12:52:15 D [spec.y:116:new_section] libglusterfs/parser: New
node for 'brickc'
2007-07-13 12:52:15 D [spec.y:132:section_type] libglusterfs/parser:
Type:brickc:protocol/client
2007-07-13 12:52:15 D [xlator.c:100:xlator_set_type]
libglusterfs/xlator: attempt to load type protocol/client
2007-07-13 12:52:15 D [xlator.c:107:xlator_set_type]
libglusterfs/xlator: attempt to load file
/usr/lib/glusterfs/1.3.0-pre5.2/xlator/protocol/client.so
2007-07-13 12:52:15 D [spec.y:152:section_option] libglusterfs/parser:
Option:brickc:transport-type:tcp/client
2007-07-13 12:52:15 D [spec.y:152:section_option] libglusterfs/parser:
Option:brickc:remote-host:127.0.0.1
2007-07-13 12:52:15 D [spec.y:152:section_option] libglusterfs/parser:
Option:brickc:remote-port:6996
2007-07-13 12:52:15 D [spec.y:152:section_option] libglusterfs/parser:
Option:brickc:remote-subvolume:brick
2007-07-13 12:52:15 D [spec.y:209:section_end] libglusterfs/parser:
end:brickc
2007-07-13 12:52:15 D [inode.c:481:__create_inode] fuse/inode: create
inode(1)
2007-07-13 12:52:15 D [inode.c:279:__active_inode] fuse/inode:
activating inode(1), lru=0/0
2007-07-13 12:52:15 D [client-protocol.c:4255:init] brickc: missing
'inode-lru-limit'. defaulting to 1000
2007-07-13 12:52:15 D [client-protocol.c:4272:init] brickc: defaulting
transport-timeout to 120
2007-07-13 12:52:15 D [transport.c:81:transport_load]
libglusterfs/transport: attempt to load type tcp/client
2007-07-13 12:52:15 D [transport.c:86:transport_load]
libglusterfs/transport: attempt to load file
/usr/lib/glusterfs/1.3.0-pre5.2/transport/tcp/client.so
2007-07-13 12:52:15 D [inode.c:481:__create_inode] brickc/inode: create
inode(1)
2007-07-13 12:52:15 D [inode.c:279:__active_inode] brickc/inode:
activating inode(1), lru=0/1000
2007-07-13 12:52:15 D [client-protocol.c:4550:notify] brickc: got
GF_EVENT_PARENT_UP, attempting connect on transport
2007-07-13 12:52:15 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:52:15 D [tcp-client.c:71:tcp_connect] brickc: socket fd = 4
2007-07-13 12:52:15 D [tcp-client.c:89:tcp_connect] brickc: finalized on
port `1023'
2007-07-13 12:52:15 D [tcp-client.c:142:tcp_connect] brickc: connect on
4 in progress (non-blocking)
2007-07-13 12:52:15 D [tcp-client.c:186:tcp_connect] brickc: connection
on 4 success
2007-07-13 12:52:15 D [client-protocol.c:4571:notify] brickc: got
GF_EVENT_CHILD_UP
2007-07-13 12:52:16 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:52:18 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:52:21 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:52:26 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:52:34 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:52:47 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:53:08 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:53:42 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:54:37 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:56:06 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 12:58:30 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 13:02:24 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 13:08:41 W [client-protocol.c:4008:client_protocol_reconnect]
brickc: attempting reconnect
2007-07-13 13:11:01 D
[client-protocol.c:4335:client_protocol_handshake_reply] brickc: reply
frame has callid: 424242
2007-07-13 13:11:01 D
[client-protocol.c:4369:client_protocol_handshake_reply] brickc:
SETVOLUME on remote-host succeeded
2007-07-13 13:18:51 W [client-protocol.c:4016:client_protocol_reconnect]
brickc: breaking reconnect chain


More information about the Gluster-devel mailing list