[Gluster-devel] extraneous log entries

Mon Jul 23 06:17:58 UTC 2007

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 <harrisl at lhjonline.com>:
>
> 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" <avati at zresearch.com>
> To: "Harris Landgarten" <harrisl at lhjonline.com>
> Cc: "gluster-devel" <gluster-devel at nongnu.org>
> 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 < harrisl at lhjonline.com >:
>
> 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
> Gluster-devel at nongnu.org
> http://lists.nongnu.org/mailman/listinfo/gluster-devel
>
>
>
> --
> Anand V. Avati
>

-- 
Anand V. Avati