Problem mounting FhGFS storage

Emir Imamagic

unread,

Mar 5, 2013, 2:50:55 PM3/5/13

to fhgfs...@googlegroups.com

Hello,

we have a 4 node FhGFS storage setup using version 2011.04.r21. All four
nodes are running meta and storage services and have IB cards. Most of
our clients are accessing via IB, but we have few that use TCP.

Today mount hung on one of TCP clients. I looked through all the logs
and couldn't find any change on system level. Also, there is no problem
in network connectivity between the client and servers.

The repeating error message in fhgfs-client.log is:
Failed to receive response from: hpc-storage3.srce (10.8.16.153:8003).
Expected response type: 2032
Here is the full client log:
(1) Mar05 19:55:09 Main [App] >> FhGFS Helper Daemon Version: 2011.04-r21
(1) Mar05 19:55:09 Main [App] >> Client log messages will be prefixed
with an asterisk (*) symbol.
(3) Mar05 19:55:14 *mount(570) [DatagramListener (init sock)] >>
Listening for UDP datagrams: Port 8004
(1) Mar05 19:55:14 *mount(570) [App_logInfos] >> FhGFS Client Version:
2011.04-r21
(2) Mar05 19:55:14 *mount(570) [App_logInfos] >> ClientID:
tannat.srce-51363F92-23A
(2) Mar05 19:55:14 *mount(570) [App_logInfos] >> Usable NICs: eth0(TCP)
eth1(TCP) eth2(TCP)
(3) Mar05 19:55:14 *fhgfs_HBeatMgr(572) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 127.0.0.1:8006
(3) Mar05 19:55:14 *fhgfs_HBeatMgr(572) [NodeConn (acquire stream)] >>
Connected: 127.0.0.1:8006
(2) Mar05 19:55:14 *fhgfs_DGramLis(571) [Heartbeat incoming] >> New node
[ID: hpc-storage1.srce; Type: Management; Source: 10.8.16.151]
(3) Mar05 19:55:14 *fhgfs_HBeatMgr(572) [Init] >> Management node found.
Downloading node groups...
(3) Mar05 19:55:14 *fhgfs_HBeatMgr(572) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 192.168.1.151:8008
(1) Mar05 19:55:16 *df(580) [Remoting (stat storage targets)] >> No
storage targets known.
(3) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [NodeConn (acquire stream)] >>
Connect failed: 192.168.1.151:8008
(3) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 10.8.16.151:8008
(3) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [NodeConn (acquire stream)] >>
Connected: 10.8.16.151:8008
(2) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [Sync] >> Nodes added (sync
results): 4 (Type: Meta)
(2) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [Sync] >> Nodes added (sync
results): 4 (Type: Storage)
(3) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [Init] >> Node registration...
(2) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [Registration] >> Node
registration successful.
(3) Mar05 19:55:19 *fhgfs_HBeatMgr(572) [Init] >> Init complete.
(3) Mar05 19:55:28 *fhgfs_Worker/3(575) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 192.168.1.151:8003
(3) Mar05 19:55:28 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 192.168.1.152:8003
(3) Mar05 19:55:28 *fhgfs_Worker/1(573) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 192.168.1.153:8003
(3) Mar05 19:55:33 *fhgfs_Worker/3(575) [NodeConn (acquire stream)] >>
Connect failed: 192.168.1.151:8003
(3) Mar05 19:55:33 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Connect failed: 192.168.1.152:8003
(3) Mar05 19:55:33 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 10.8.16.152:8003
(3) Mar05 19:55:33 *fhgfs_Worker/1(573) [NodeConn (acquire stream)] >>
Connect failed: 192.168.1.153:8003
(3) Mar05 19:55:33 *fhgfs_Worker/1(573) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 10.8.16.153:8003
(3) Mar05 19:55:33 *fhgfs_Worker/3(575) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 10.8.16.151:8003
(3) Mar05 19:55:33 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Connected: 10.8.16.152:8003
(3) Mar05 19:55:33 *fhgfs_Worker/1(573) [NodeConn (acquire stream)] >>
Connected: 10.8.16.153:8003
(3) Mar05 19:55:33 *fhgfs_Worker/3(575) [NodeConn (acquire stream)] >>
Connected: 10.8.16.151:8003
(3) Mar05 19:55:33 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 192.168.1.154:8003
(3) Mar05 19:55:38 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Connect failed: 192.168.1.154:8003
(3) Mar05 19:55:38 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Establishing new TCP connection to: 10.8.16.154:8003
(3) Mar05 19:55:38 *fhgfs_Worker/2(574) [NodeConn (acquire stream)] >>
Connected: 10.8.16.154:8003
(2) Mar05 19:56:28 *fhgfs_Worker/2(32708) [Messaging (RPC)] >> Failed to
receive response from: hpc-storage3.srce (10.8.16.153:8003). Expected
response type: 2032
(3) Mar05 19:56:28 *fhgfs_Worker/2(32708) [NodeConn (invalidate stream)]
>> Disconnected: 10.8.16.153:8003
(0) Mar05 19:58:05 *fhgfs_RtrWrk/1(32710) [MessagingTk (recv msg)] >>
[10.8.16.153:8003] SocketException: ErrCode: 0
(2) Mar05 19:58:05 *fhgfs_RtrWrk/1(32710) [Messaging (RPC)] >> Failed to
receive response from: hpc-storage3.srce (10.8.16.153:8003). Expected
response type: 2032
(3) Mar05 19:58:05 *fhgfs_RtrWrk/1(32710) [NodeConn (invalidate stream)]
>> Disconnected: 10.8.16.153:8003

On server 10.8.16.153 in fhgfs-storage.log I see (client IP is 10.8.16.10):
(0) Mar05 19:49:10 Worker8 [WriteLocalFileMsg incoming] >>
SocketException occured: SocketDisconnectException: Soft Disconnect from
10.8.16.10:35744
(2) Mar05 19:49:10 Worker8 [WriteLocalFileMsg incoming] >> Details:
sessionID: tannat.srce-50A34E82-7FC0; FD: 112; offset: 0; count: 524288;
(3) Mar05 19:49:10 Worker8 [Work (process incoming data)] >> Problem
encountered during processing of a message. Disconnecting: 10.8.16.10:35744
...
(3) Mar05 19:53:11 StreamLis [StreamLis] >> Accepted new connection from
10.8.16.10:42984 [SockFD: 326]
...
(3) Mar05 19:55:33 StreamLis [StreamLis] >> Accepted new connection from
10.8.16.10:43225 [SockFD: 356]
...
(3) Mar05 19:58:10 StreamLis [StreamLis] >> Accepted new connection from
10.8.16.10:43246 [SockFD: 477]
...
(3) Mar05 20:04:10 Worker5 [Work (process incoming data)] >>
SocketDisconnectException: Soft Disconnect from 10.8.16.10:58164
(3) Mar05 20:04:10 Worker5 [Work (process incoming data)] >>
SocketDisconnectException: Soft Disconnect from 10.8.16.10:58329
(0) Mar05 20:04:10 Worker5 [WriteLocalFileMsg incoming] >>
SocketException occured: SocketDisconnectException: Soft Disconnect from
10.8.16.10:35802
(2) Mar05 20:04:10 Worker5 [WriteLocalFileMsg incoming] >> Details:
sessionID: tannat.srce-50A34E82-7FC0; FD: 112; offset: 0; count: 524288;
(3) Mar05 20:04:10 Worker5 [Work (process incoming data)] >> Problem
encountered during processing of a message. Disconnecting: 10.8.16.10:35802

(... are messages related to other servers)

The only thing I haven't tried yet is rebooting the client. Any suggestion?

Thanks in advance,
Emir Imamagic

Emir Imamagic

unread,

Mar 5, 2013, 4:07:00 PM3/5/13

to fhgfs...@googlegroups.com

Further analysis showed that the problem was in storage service on two
nodes:

(0) Mar05 12:49:47 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 12:59:47 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(2) Mar05 12:59:48 XNodeSync [Update capacities (mapped)] >> Target
moved to emergency pool for unreachable nodeID: hpc-storage3.srce
(targetID: 1-4E5CFC37-hpc-storage3.srce)
(2) Mar05 13:06:58 Worker4 [Heartbeat incoming] >> New node [ID:
node003.srce.cro-ngi.hr-5118ED5B-1B3D; Type: Client; Source:
192.168.1.203:51615; RDMA]
(2) Mar05 13:06:58 Worker4 [Heartbeat incoming] >> Number of nodes in
the system: Meta: 4; Storage: 4; Client: 369; Mgmt: 1
(0) Mar05 13:12:48 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 13:22:49 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(2) Mar05 13:31:31 Worker1 [Heartbeat incoming] >> New node [ID:
node015.srce.cro-ngi.hr-5135E5A3-1AFA; Type: Client; Source:
192.168.1.215:60099; RDMA]
(2) Mar05 13:31:31 Worker1 [Heartbeat incoming] >> Number of nodes in
the system: Meta: 4; Storage: 4; Client: 370; Mgmt: 1
(0) Mar05 13:35:49 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 13:45:50 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 13:58:50 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 14:08:51 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 14:21:51 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 14:31:52 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 14:53:56 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 15:03:57 XNodeSync [RPC: hpc-storage3.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.153:8003
timed out
(0) Mar05 15:16:57 XNodeSync [RPC: hpc-storage1.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.151:8003
timed out
(0) Mar05 15:26:58 XNodeSync [RPC: hpc-storage1.srce] >>
SocketException: SocketTimeoutException: Receive from 192.168.1.151:8003
timed out
(2) Mar05 15:26:58 XNodeSync [Update capacities (mapped)] >> Target
moved to emergency pool for unreachable nodeID: hpc-storage1.srce
(targetID: 1-4E5CFC37-hpc-storage1.srce)

After I restarted fhgfs-mgmtd everything got back to normal. Any ideas
how to solve this more elegantly or what exactly happened?

Thanks in advance

Emir Imamagic

unread,

Mar 6, 2013, 5:36:01 AM3/6/13

to fhgfs...@googlegroups.com

Hello again,

On 5.3.2013 22:07, Emir Imamagic wrote:
> After I restarted fhgfs-mgmtd everything got back to normal. Any ideas
> how to solve this more elegantly or what exactly happened?

The problem happened again after couple of hours. I restarted
fhgfs-storage on two problematic nodes and things got back to normal for
couple of hours and then problem appeared again. I tried rebooting all 4
nodes now and started fhgfs-fsck fullcheck.

Any help/suggestion would be very appreciated.

Thanks,
emir

Frank Kautz

unread,

Mar 7, 2013, 2:50:16 AM3/7/13

to fhgfs...@googlegroups.com

Hello Emir,

you have the problem only on the nodes which are only connected by
Ethernet, right?

In the log files I could see different IP networks 192.168.1.x and
10.8.16.x. On is the Ethernet network and one is the Infiniband network,
right?

It looks like the client uses the wrong IP addresses (Infiniband) of the
server. In the configuration file of the client, the management, the
metadata server and the storage server you could define a white list for
useful IP networks and useful network interfaces. There are two
configuration parameters connNetFilterFile and connInterfacesFile. Add
only the IP networks and the network interfaces which are needed to
connect with the fhgfs daemons/clients.

More details you could find in the description in the configuration file
and in the wiki: http://www.fhgfs.com/wiki/wikka.php?wakka=FAQ#multiple_nics

kind regards,
Frank

frank_kautz.vcf

Emir Imamagic

unread,

Mar 7, 2013, 5:14:45 AM3/7/13

to fhgfs...@googlegroups.com, fhgfs...@googlegroups.com

Hello

I apologize for not clarifying in my 2. email - the problem affects both Eth and IB nodes. FhGFS nodes indeed have two networks:
- 192.168.1.x - IB
- 10.8.16.x - Eth
I didnt limit interfaces in FhGFS config because one is used by IB nodes and other by Eth.

This setup has been working fine for us for quite a while. FhGFS gives higher priority to IB network. Eth clients try to access IB first and after it fails they simply use Eth network.

All daemons are running on four servers which have IB. In mgmtd log you can see that mgmtd daemon was using IB network for communication with storage.

However I can't find the reason why storage daemon on hpc-storage3 stopped responding.

Also, what is the policy for storage nodes in emergency pool? Can I tell mgmtd to automatically move them back to normal pool?

Thanks in advance
--
em...@iphone.hk

> --
> You received this message because you are subscribed to the Google Groups "fhgfs-user" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to fhgfs-user+...@googlegroups.com.
> For more options, visit https://groups.google.com/groups/opt_out.
>
>
> <frank_kautz.vcf>

Emir Imamagic

unread,

Mar 10, 2013, 2:39:54 PM3/10/13

to fhgfs...@googlegroups.com

Hello,

any suggestions what can we do in this situation? Nodes hpc-storage1 and
hpc-storage3 keep on dying after two hours of work with the same
messages in mgmt (listed below) making the cluster permanently broken.

Thanks in advance,
emir

(1) Mar08 09:06:05 Main [App] >> Version: 2011.04-r21
(2) Mar08 09:06:05 Main [App] >> LocalNodeID: hpc-storage1.srce
(2) Mar08 09:06:05 Main [App] >> Usable NICs: ib0(TCP) eth0(TCP)
(0) Mar08 11:22:38 XNodeSync [RPC: hpc-storage3.srce] >>