gluster-devel
[Top][All Lists]
Advanced

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Gluster-devel] extraneous log entries


From: Harris Landgarten
Subject: Re: [Gluster-devel] extraneous log entries
Date: Tue, 24 Jul 2007 08:39:09 -0400 (EDT)

Better info. This is from today's logs in WARNING mode.

Client:

2007-07-24 08:30:44 W [client-protocol.c:211:call_bail] client2: activating 
bail-out. pending frames = 1. last sent = 2007-07-24 08:29:17. last received = 
2007-07-24 08:29:17 transport-timeout = 60
2007-07-24 08:30:44 C [client-protocol.c:219:call_bail] client2: bailing 
transport
2007-07-24 08:30:44 W [client-protocol.c:4185:client_protocol_cleanup] client2: 
cleaning up state in transport object 0x8091578
2007-07-24 08:30:44 W [client-protocol.c:4234:client_protocol_cleanup] client2: 
forced unwinding frame type(1) op(2)
2007-07-24 08:30:44 C [tcp.c:81:tcp_disconnect] client2: connection disconnected
2007-07-24 08:30:44 E [client-protocol.c:336:client_protocol_xfer] client2: 
transport_submit failed
2007-07-24 08:30:44 W [client-protocol.c:4154:client_protocol_reconnect] 
client2: attempting reconnect
2007-07-24 08:30:45 W [client-protocol.c:4162:client_protocol_reconnect] 
client2: breaking reconnect chain
2007-07-24 08:32:17 W [client-protocol.c:211:call_bail] client1: activating 
bail-out. pending frames = 1. last sent = 2007-07-24 08:30:44. last received = 
2007-07-24 08:30:44 transport-timeout = 60
2007-07-24 08:32:17 C [client-protocol.c:219:call_bail] client1: bailing 
transport
2007-07-24 08:32:17 W [client-protocol.c:4185:client_protocol_cleanup] client1: 
cleaning up state in transport object 0x8091068
2007-07-24 08:32:17 W [client-protocol.c:4234:client_protocol_cleanup] client1: 
forced unwinding frame type(1) op(2)
2007-07-24 08:32:17 C [tcp.c:81:tcp_disconnect] client1: connection disconnected
2007-07-24 08:32:17 E [client-protocol.c:336:client_protocol_xfer] client1: 
transport_submit failed
2007-07-24 08:32:17 W [client-protocol.c:4154:client_protocol_reconnect] 
client1: attempting reconnect
2007-07-24 08:32:18 W [client-protocol.c:4162:client_protocol_reconnect] 
client1: breaking reconnect chain
2007-07-24 08:33:44 W [client-protocol.c:211:call_bail] client2: activating 
bail-out. pending frames = 1. last sent = 2007-07-24 08:32:17. last received = 
2007-07-24 08:32:17 transport-timeout = 60
2007-07-24 08:33:44 C [client-protocol.c:219:call_bail] client2: bailing 
transport
2007-07-24 08:33:44 W [client-protocol.c:4185:client_protocol_cleanup] client2: 
cleaning up state in transport object 0x8091578
2007-07-24 08:33:44 W [client-protocol.c:4234:client_protocol_cleanup] client2: 
forced unwinding frame type(1) op(2)
2007-07-24 08:33:44 C [tcp.c:81:tcp_disconnect] client2: connection disconnected
2007-07-24 08:33:44 E [client-protocol.c:336:client_protocol_xfer] client2: 
transport_submit failed
2007-07-24 08:33:44 W [client-protocol.c:4154:client_protocol_reconnect] 
client2: attempting reconnect
2007-07-24 08:33:45 W [client-protocol.c:4162:client_protocol_reconnect] 
client2: breaking reconnect chain
2007-07-24 08:35:17 W [client-protocol.c:211:call_bail] client1: activating 
bail-out. pending frames = 1. last sent = 2007-07-24 08:33:44. last received = 
2007-07-24 08:33:44 transport-timeout = 60
2007-07-24 08:35:17 C [client-protocol.c:219:call_bail] client1: bailing 
transport
2007-07-24 08:35:17 W [client-protocol.c:4185:client_protocol_cleanup] client1: 
cleaning up state in transport object 0x8091068
2007-07-24 08:35:17 W [client-protocol.c:4234:client_protocol_cleanup] client1: 
forced unwinding frame type(1) op(2)
2007-07-24 08:35:17 C [tcp.c:81:tcp_disconnect] client1: connection disconnected
2007-07-24 08:35:17 E [client-protocol.c:336:client_protocol_xfer] client1: 
transport_submit failed
2007-07-24 08:35:17 W [client-protocol.c:4154:client_protocol_reconnect] 
client1: attempting reconnect
2007-07-24 08:35:18 W [client-protocol.c:4162:client_protocol_reconnect] 
client1: breaking reconnect chain
...

Brick1:

2007-07-24 08:26:16 W [inode.c:1058:inode_table_new] brick: creating new inode 
table with lru_limit=1024, sizeof(inode_t)=116
2007-07-24 08:27:16 E [protocol.c:251:gf_block_unserialize_transport] 
libglusterfs/protocol: EOF from peer (10.255.62.81:1022)
2007-07-24 08:27:16 C [tcp.c:81:tcp_disconnect] server: connection disconnected
2007-07-24 08:29:17 E [protocol.c:251:gf_block_unserialize_transport] 
libglusterfs/protocol: EOF from peer (10.255.62.81:1020)
2007-07-24 08:29:17 C [tcp.c:81:tcp_disconnect] server: connection disconnected
2007-07-24 08:32:17 E [protocol.c:251:gf_block_unserialize_transport] 
libglusterfs/protocol: EOF from peer (10.255.62.81:1022)
2007-07-24 08:32:17 C [tcp.c:81:tcp_disconnect] server: connection disconnected
2007-07-24 08:35:17 E [protocol.c:251:gf_block_unserialize_transport] 
libglusterfs/protocol: EOF from peer (10.255.62.81:1021)
2007-07-24 08:35:17 C [tcp.c:81:tcp_disconnect] server: connection disconnected

Brick2:

2007-07-24 08:27:38 W [inode.c:1058:inode_table_new] brick: creating new inode 
table with lru_limit=1024, sizeof(inode_t)=116
2007-07-24 08:27:38 W [inode.c:1058:inode_table_new] brick-ns: creating new 
inode table with lru_limit=1024, sizeof(inode_t)=116
2007-07-24 08:30:41 E [protocol.c:251:gf_block_unserialize_transport] 
libglusterfs/protocol: EOF from peer (10.255.62.81:1021)
2007-07-24 08:30:41 C [tcp.c:81:tcp_disconnect] server: connection disconnected
2007-07-24 08:33:42 E [protocol.c:251:gf_block_unserialize_transport] 
libglusterfs/protocol: EOF from peer (10.255.62.81:1020)
2007-07-24 08:33:42 C [tcp.c:81:tcp_disconnect] server: connection disconnected
2007-07-24 08:36:42 E [protocol.c:251:gf_block_unserialize_transport] 
libglusterfs/protocol: EOF from peer (10.255.62.81:1022)
2007-07-24 08:36:42 C [tcp.c:81:tcp_disconnect] server: connection disconnected

Harris

----- Original Message -----
From: "Anand Avati" <address@hidden>
To: "Harris Landgarten" <address@hidden>
Cc: "gluster-devel" <address@hidden>
Sent: Monday, July 23, 2007 2:17:58 AM (GMT-0500) America/New_York
Subject: Re: [Gluster-devel] extraneous log entries

Harris, 
this log seems to be from a pretty old glusterfs version (not that it only 
tells that there is 1 pending frame and does not tell the type/op of the 
frame.) i want to know what is the type/op of the pending frame which caused 
the bailing out. 

thanks, 
avati 


2007/7/22 , Harris Landgarten < address@hidden >: 

You are right. It was on default log level. Here is an example from a earlier 
log: 

2007-07-02 16:50:07 C [client-protocol.c:215:call_bail] client2: bailing 
transport 
2007-07-02 16:50:07 W [client-protocol.c:4039:client_protocol_cleanup] client2: 
cleaning up state in transport object 0x8092900 
2007-07-02 16:50:07 C [tcp.c:81:tcp_disconnect] client2: connection 
disconnected 
2007-07-02 16:50:07 E [client-protocol.c:328:client_protocol_xfer] client2: 
transport_submit failed 
2007-07-02 16:50:07 W [client-protocol.c :4008:client_protocol_reconnect] 
client2: attempting reconnect 
2007-07-02 16:50:08 W [client-protocol.c:4016:client_protocol_reconnect] 
client2: breaking reconnect chain 
2007-07-02 16:50:40 W [client-protocol.c:207:call_bail] client1: activating 
bail-out. pending frames = 1. last sent = 2007-07-02 16:50:07. last received = 
2007-07-02 16:50:07transport-timeout = 30 
2007-07-02 16:50:40 C [client-protocol.c:215:call_bail] client1: bailing 
transport 
2007-07-02 16:50:40 W [client-protocol.c:4039:client_protocol_cleanup] client1: 
cleaning up state in transport object 0x80902a0 
2007-07-02 16:50:40 C [tcp.c:81:tcp_disconnect] client1: connection 
disconnected 
2007-07-02 16:50:40 E [client-protocol.c:328:client_protocol_xfer] client1: 
transport_submit failed 
2007-07-02 16:50:40 W [client-protocol.c :4008:client_protocol_reconnect] 
client1: attempting reconnect 
2007-07-02 16:50:41 W [client-protocol.c:4016:client_protocol_reconnect] 
client1: breaking reconnect chain 
2007-07-02 16:51:37 W [client-protocol.c:207:call_bail] client2: activating 
bail-out. pending frames = 1. last sent = 2007-07-02 16:50:40. last received = 
2007-07-02 16:50:40transport-timeout = 30 
2007-07-02 16:51:37 C [client-protocol.c:215:call_bail] client2: bailing 
transport 
2007-07-02 16:51:37 W [client-protocol.c:4039:client_protocol_cleanup] client2: 
cleaning up state in transport object 0x8092900 
2007-07-02 16:51:37 C [tcp.c:81:tcp_disconnect] client2: connection 
disconnected 
2007-07-02 16:51:37 E [client-protocol.c:328:client_protocol_xfer] client2: 
transport_submit failed 
2007-07-02 16:51:37 W [client-protocol.c :4008:client_protocol_reconnect] 
client2: attempting reconnect 
2007-07-02 16:51:38 W [client-protocol.c:4016:client_protocol_reconnect] 
client2: breaking reconnect chain 
2007-07-02 16:52:10 W [client-protocol.c:207:call_bail] client1: activating 
bail-out. pending frames = 1. last sent = 2007-07-02 16:51:37. last received = 
2007-07-02 16:51:37transport-timeout = 30 

Note: This only occurs when the bricks are restarted with the client running. 
The client is idle. I see this every time I upgrade all my clients and servers 
and restart the client first. Restarting the client stops the log entries. 

Harris 

----- Original Message ----- 
From: "Anand Avati" < address@hidden > 
To: "Harris Landgarten" < address@hidden > 
Cc: "gluster-devel" < address@hidden > 
Sent: Sunday, July 22, 2007 8:20:32 AM (GMT-0500) America/New_York 
Subject: Re: [Gluster-devel] extraneous log entries 

Harris, 
Are you sure the client was running with WARNING log level? during a bailout 
there is a warning log which gives the reason of bailing and without that log 
being printed the transport never bails out. Is it possible to confirm again if 
the client was running in WARNING log level? It would be very helpful to see 
those logs around a bailout which are printed with WARNING level. 

avati 


2007/7/22 , Harris Landgarten < address@hidden >: 

On one for my clients running Gentoo, I get the following log entries if I 
restart glusterfsd on my bricks with the client running: 

2007-07-21 17:50:33 E [client-protocol.c:336:client_protocol_xfer] client2: 
transport_submit failed 
2007-07-21 17:52:18 C [client-protocol.c:219:call_bail] client1: bailing 
transport 
2007-07-21 17:52:18 C [tcp.c :81:tcp_disconnect] client1: connection 
disconnected 
2007-07-21 17:52:18 E [client-protocol.c:336:client_protocol_xfer] client1: 
transport_submit failed 
2007-07-21 17:53:34 C [client-protocol.c:219:call_bail] client2: bailing 
transport 
2007-07-21 17:53:34 C [tcp.c:81:tcp_disconnect] client2: connection 
disconnected 
2007-07-21 17:53:34 E [client-protocol.c:336:client_protocol_xfer] client2: 
transport_submit failed 
2007-07-21 17:55:18 C [client-protocol.c :219:call_bail] client1: bailing 
transport 
2007-07-21 17:55:18 C [tcp.c:81:tcp_disconnect] client1: connection 
disconnected 
2007-07-21 17:55:18 E [client-protocol.c:336:client_protocol_xfer] client1: 
transport_submit failed 
2007-07-21 17:56:34 C [client-protocol.c:219:call_bail] client2: bailing 
transport 
2007-07-21 17:56:34 C [tcp.c:81:tcp_disconnect] client2: connection 
disconnected 
2007-07-21 17:56:34 E [client-protocol.c:336:client_protocol_xfer] client2: 
transport_submit failed 
2007-07-21 17:58:18 C [client-protocol.c:219:call_bail] client1: bailing 
transport 
2007-07-21 17:58:18 C [tcp.c:81:tcp_disconnect] client1: connection 
disconnected 
2007-07-21 17:58:18 E [client-protocol.c:336:client_protocol_xfer] client1: 
transport_submit failed 
2007-07-21 17:59:34 C [client-protocol.c:219:call_bail] client2: bailing 
transport 
2007-07-21 17:59:34 C [tcp.c:81:tcp_disconnect] client2: connection 
disconnected 
2007-07-21 17:59:34 E [client-protocol.c:336:client_protocol_xfer] client2: 
transport_submit failed 
... 

These log entries continue even though the client see no apparent effect. If 
glusterfs is restarted after the bricks are restarted, the log entries do not 
appear. Note: the logging is in WARNING mode. 

These are the corresponding brick logs: 

brick1: 

2007-07-21 17:36:16 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:36:16 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:39:16 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:39:16 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:40:17 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:40:17 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:43:17 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:43:17 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:46:17 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:46:17 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:49:17 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:49:17 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:52:18 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:52:18 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:55:18 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:55:18 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:58:18 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:58:18 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 18:03:23 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 18:03:23 C [tcp.c:81:tcp_disconnect] server: connection disconnected 


brick2 and ns: 
2007-07-21 17:34:30 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:34:30 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:37:30 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:37:30 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:41:30 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:41:30 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:44:31 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:44:31 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:47:31 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:47:31 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:50:31 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:50:31 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:53:31 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:53:31 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:56:32 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:56:32 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 17:59:32 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 17:59:32 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 18:03:21 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 18:03:21 C [tcp.c:81:tcp_disconnect] server: connection disconnected 
2007-07-21 18:03:21 E [protocol.c:262:gf_block_unserialize_transport] 
libglusterfs/protocol: full_read of header failed: peer ( 10.255.62.81 ) 
2007-07-21 18:03:21 C [tcp.c:81:tcp_disconnect] server: connection disconnected 


As with the client, once glusterfs is restarted on the client the server log 
entries stop. This does not occur on my Ubuntu client. 


Harrisl 







_______________________________________________ 
Gluster-devel mailing list 
address@hidden 
http://lists.nongnu.org/mailman/listinfo/gluster-devel 



-- 
Anand V. Avati 



-- 
Anand V. Avati 




reply via email to

[Prev in Thread] Current Thread [Next in Thread]