[Gluster-users] file descriptor in bad state
Anand Avati
avati at zresearch.com
Thu Aug 7 13:43:34 UTC 2008
Michael,
the first log snippet provided us a few hints. can you provide logs from
this run as well?
avati
2008/8/7 Michael Di Domenico <mdidomenico4 at gmail.com>
> oops, spoke too soon, but i did get a bit farther into the test
> 16384 4 4021 4155 11464 11468 4237 4157
> 4128 4175 4139 4018 4166 11449 11447
> 16384 8 5285 5392 11466 11465 5459 5391
> 5358 5409 5354 5274 4925 11372 11446
> 16384 16 7549 7711 11467 11465 7802 7702
> 7662 7756 7690 7524 7704 11447 11446
> 16384 32 8718 8900 11441 10001 8998 8591
> 8597 8396 7724 8686 8544
> Error freading block 382 3a900000
> read: File descriptor in bad state
>
> On Thu, Aug 7, 2008 at 9:11 AM, Michael Di Domenico <
> mdidomenico4 at gmail.com> wrote:
>
>> As a followup, I added a fourth storage brick and a seperate namespace
>> server into the mix, and now this problem seems to have gone away. I'm not
>> sure if it was the 4th storage brick or the seperate name server that
>> corrected it just yet.
>>
>>
>> On Sun, Aug 3, 2008 at 8:20 PM, Michael Di Domenico <
>> mdidomenico4 at gmail.com> wrote:
>>
>>> [root at green gluster]# /opt/gluster/sbin/glusterfs -V
>>> glusterfs 1.3.10 built on Aug 1 2008 12:08:22
>>> Repository revision: glusterfs--mainline--2.5--patch-788
>>> Copyright (c) 2006, 2007, 2008 Z RESEARCH Inc. <http://www.zresearch.com
>>> >
>>> GlusterFS comes with ABSOLUTELY NO WARRANTY.
>>> You may redistribute copies of GlusterFS under the terms of the GNU
>>> General Public License.
>>>
>>> [root at green gluster]# ./iozone -a
>>> ...output snipped....
>>> Error freading block 7 bc700000
>>> read: File descriptor in bad state
>>>
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1701:fuse_flush] glusterfs-fuse:
>>> 25151: FLUSH 0x1f33dbb0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25151: (16) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1728:fuse_release] glusterfs-fuse:
>>> 25152: CLOSE 0x1f33dbb0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1746:fuse_fsync] glusterfs-fuse:
>>> 25153: FSYNC 0x1f33fc80
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25153: (18) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1701:fuse_flush] glusterfs-fuse:
>>> 25154: FLUSH 0x1f33fc80
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25152: (17) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25154: (16) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1728:fuse_release] glusterfs-fuse:
>>> 25155: CLOSE 0x1f33fc80
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1553:fuse_open] glusterfs-fuse:
>>> 25156: OPEN /iozone.tmp
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25155: (17) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:687:fuse_fd_cbk] glusterfs-fuse:
>>> 25156: (12) /iozone.tmp => 0x1f33d8d0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1553:fuse_open] glusterfs-fuse:
>>> 25157: OPEN /iozone.tmp
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:687:fuse_fd_cbk] glusterfs-fuse:
>>> 25157: (12) /iozone.tmp => 0x1f340b10
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1746:fuse_fsync] glusterfs-fuse:
>>> 25158: FSYNC 0x1f340b10
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25158: (18) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1701:fuse_flush] glusterfs-fuse:
>>> 25159: FLUSH 0x1f340b10
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25159: (16) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1728:fuse_release] glusterfs-fuse:
>>> 25160: CLOSE 0x1f340b10
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25161: READ (0x1f33d8d0, size=131072, offset=0)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25162: READ (0x1f33d8d0, size=131072, offset=131072)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1582:fuse_readv_cbk] glusterfs-fuse:
>>> 25161: READ => 131072/131072,0/1048576
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25160: (17) ERR => 0
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25163: READ (0x1f33d8d0, size=131072, offset=262144)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1582:fuse_readv_cbk] glusterfs-fuse:
>>> 25162: READ => 131072/131072,131072/1048576
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25164: READ (0x1f33d8d0, size=131072, offset=393216)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1582:fuse_readv_cbk] glusterfs-fuse:
>>> 25163: READ => 131072/131072,262144/1048576
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25165: READ (0x1f33d8d0, size=131072, offset=524288)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1582:fuse_readv_cbk] glusterfs-fuse:
>>> 25164: READ => 131072/131072,393216/1048576
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25166: READ (0x1f33d8d0, size=131072, offset=655360)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1582:fuse_readv_cbk] glusterfs-fuse:
>>> 25165: READ => 131072/131072,524288/1048576
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25167: READ (0x1f33d8d0, size=131072, offset=786432)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1582:fuse_readv_cbk] glusterfs-fuse:
>>> 25166: READ => 131072/131072,655360/1048576
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25168: READ (0x1f33d8d0, size=131072, offset=917504)
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1582:fuse_readv_cbk] glusterfs-fuse:
>>> 25167: READ => 131072/131072,786432/1048576
>>> 2008-08-03 20:18:30 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25169: READ (0x1f33d8d0, size=131072, offset=1048576)
>>> 2008-08-03 20:19:17 W [client-protocol.c:205:call_bail] remote1:
>>> activating bail-out. pending frames = 1. last sent = 2008-08-03 20:18:30.
>>> last received = 2008-08-03 20:18:30 transport-timeout = 42
>>> 2008-08-03 20:19:17 C [client-protocol.c:212:call_bail] remote1: bailing
>>> transport
>>> 2008-08-03 20:19:17 D [tcp.c:137:cont_hand] tcp: forcing poll/read/write
>>> to break on blocked socket (if any)
>>> 2008-08-03 20:19:17 W [client-protocol.c:205:call_bail] remote2:
>>> activating bail-out. pending frames = 1. last sent = 2008-08-03 20:18:30.
>>> last received = 2008-08-03 20:18:30 transport-timeout = 42
>>> 2008-08-03 20:19:17 C [client-protocol.c:212:call_bail] remote2: bailing
>>> transport
>>> 2008-08-03 20:19:17 D [tcp.c:137:cont_hand] tcp: forcing poll/read/write
>>> to break on blocked socket (if any)
>>> 2008-08-03 20:19:17 E [protocol.c:376:gf_block_unserialize_transport]
>>> remote1: full_read of block failed: peer (192.168.0.254:6996)
>>> 2008-08-03 20:19:17 W [client-protocol.c:4777:client_protocol_cleanup]
>>> remote1: cleaning up state in transport object 0x1f3349a0
>>> 2008-08-03 20:19:17 E [client-protocol.c:4827:client_protocol_cleanup]
>>> remote1: forced unwinding frame type(1) op(13) reply=@0x1f33c070
>>> 2008-08-03 20:19:17 E [client-protocol.c:3193:client_readv_cbk] remote1:
>>> no proper reply from server, returning ENOTCONN
>>> 2008-08-03 20:19:17 E [fuse-bridge.c:1587:fuse_readv_cbk] glusterfs-fuse:
>>> 25168: READ => -1 (107)
>>> 2008-08-03 20:19:17 D [tcp.c:87:tcp_disconnect] remote1: connection
>>> disconnected
>>> 2008-08-03 20:19:17 W [client-protocol.c:4777:client_protocol_cleanup]
>>> remote2: cleaning up state in transport object 0x1f337300
>>> 2008-08-03 20:19:17 E [client-protocol.c:4827:client_protocol_cleanup]
>>> remote2: forced unwinding frame type(1) op(13) reply=@0x1f33d3b0
>>> 2008-08-03 20:19:17 E [client-protocol.c:3193:client_readv_cbk] remote2:
>>> no proper reply from server, returning ENOTCONN
>>> 2008-08-03 20:19:17 E [fuse-bridge.c:1587:fuse_readv_cbk] glusterfs-fuse:
>>> 25169: READ => -1 (107)
>>> 2008-08-03 20:19:17 D [tcp.c:87:tcp_disconnect] remote2: connection
>>> disconnected
>>> 2008-08-03 20:19:17 D [fuse-bridge.c:1613:fuse_readv] glusterfs-fuse:
>>> 25170: READ (0x1f33d8d0, size=4096, offset=917504)
>>> 2008-08-03 20:19:17 E [client-protocol.c:1105:client_readv] remote1: :
>>> returning EBADFD
>>> 2008-08-03 20:19:17 E [fuse-bridge.c:1587:fuse_readv_cbk] glusterfs-fuse:
>>> 25170: READ => -1 (77)
>>> 2008-08-03 20:19:17 D [fuse-bridge.c:1728:fuse_release] glusterfs-fuse:
>>> 25171: CLOSE 0x1f33eae0
>>> 2008-08-03 20:19:17 W [client-protocol.c:1296:client_close] remote2: no
>>> valid fd found, returning
>>> 2008-08-03 20:19:17 D [fuse-bridge.c:1701:fuse_flush] glusterfs-fuse:
>>> 25172: FLUSH 0x1f33d8d0
>>> 2008-08-03 20:19:17 D [dict.c:357:dict_destroy] dict: @this=(nil)
>>> 2008-08-03 20:19:17 E [client-protocol.c:1238:client_flush] remote1: :
>>> returning EBADFD
>>> 2008-08-03 20:19:17 W [stripe.c:198:stripe_stack_unwind_cbk] stripe0:
>>> remote1 returned errno 77
>>> 2008-08-03 20:19:17 D [dict.c:357:dict_destroy] dict: @this=(nil)
>>> 2008-08-03 20:19:17 E [client-protocol.c:1238:client_flush] remote2: :
>>> returning EBADFD
>>> 2008-08-03 20:19:17 W [stripe.c:198:stripe_stack_unwind_cbk] stripe0:
>>> remote2 returned errno 77
>>> 2008-08-03 20:19:17 W [client-protocol.c:1296:client_close] remote1: no
>>> valid fd found, returning
>>> 2008-08-03 20:19:17 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25171: (17) ERR => 0
>>> 2008-08-03 20:19:17 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25172: (16) ERR => 0
>>> 2008-08-03 20:19:17 D [fuse-bridge.c:1728:fuse_release] glusterfs-fuse:
>>> 25173: CLOSE 0x1f33d8d0
>>> 2008-08-03 20:19:17 W [client-protocol.c:1296:client_close] remote2: no
>>> valid fd found, returning
>>> 2008-08-03 20:19:17 W [client-protocol.c:1296:client_close] remote1: no
>>> valid fd found, returning
>>> 2008-08-03 20:19:17 D [fuse-bridge.c:939:fuse_err_cbk] glusterfs-fuse:
>>> 25173: (17) ERR => 0
>>> 2008-08-03 20:19:17 D [client-protocol.c:4750:client_protocol_reconnect]
>>> remote1: attempting reconnect
>>> 2008-08-03 20:19:17 D [tcp-client.c:77:tcp_connect] remote1: socket fd =
>>> 6
>>> 2008-08-03 20:19:17 D [tcp-client.c:107:tcp_connect] remote1: finalized
>>> on port `1023'
>>> 2008-08-03 20:19:17 D [tcp-client.c:128:tcp_connect] remote1: defaulting
>>> remote-port to 6996
>>> 2008-08-03 20:19:17 D [common-utils.c:179:gf_resolve_ip] resolver: DNS
>>> cache not present, freshly probing hostname: n1
>>> 2008-08-03 20:19:17 D [common-utils.c:204:gf_resolve_ip] resolver:
>>> returning IP:192.168.0.254[0] for hostname: n1
>>> 2008-08-03 20:19:17 D [common-utils.c:212:gf_resolve_ip] resolver:
>>> flushing DNS cache
>>> 2008-08-03 20:19:17 D [tcp-client.c:161:tcp_connect] remote1: connect on
>>> 6 in progress (non-blocking)
>>> 2008-08-03 20:19:17 D [tcp-client.c:205:tcp_connect] remote1: connection
>>> on 6 success
>>> 2008-08-03 20:19:17 D [client-protocol.c:5355:notify] remote1: got
>>> GF_EVENT_CHILD_UP
>>> 2008-08-03 20:19:17 D [client-protocol.c:4750:client_protocol_reconnect]
>>> remote2: attempting reconnect
>>> 2008-08-03 20:19:17 D [tcp-client.c:77:tcp_connect] remote2: socket fd =
>>> 7
>>> 2008-08-03 20:19:17 D [tcp-client.c:107:tcp_connect] remote2: finalized
>>> on port `1022'
>>> 2008-08-03 20:19:17 D [tcp-client.c:128:tcp_connect] remote2: defaulting
>>> remote-port to 6996
>>> 2008-08-03 20:19:17 D [common-utils.c:179:gf_resolve_ip] resolver: DNS
>>> cache not present, freshly probing hostname: n2
>>> 2008-08-03 20:19:17 D [common-utils.c:204:gf_resolve_ip] resolver:
>>> returning IP:192.168.0.253[0] for hostname: n2
>>> 2008-08-03 20:19:17 D [common-utils.c:212:gf_resolve_ip] resolver:
>>> flushing DNS cache
>>> 2008-08-03 20:19:17 D [tcp-client.c:161:tcp_connect] remote2: connect on
>>> 7 in progress (non-blocking)
>>> 2008-08-03 20:19:17 D
>>> [client-protocol.c:5096:client_protocol_handshake_reply] remote1: reply
>>> frame has callid: 424242
>>> 2008-08-03 20:19:17 D
>>> [client-protocol.c:5130:client_protocol_handshake_reply] remote1: SETVOLUME
>>> on remote-host succeeded
>>> 2008-08-03 20:19:17 D [tcp-client.c:205:tcp_connect] remote2: connection
>>> on 7 success
>>> 2008-08-03 20:19:17 D [client-protocol.c:5355:notify] remote2: got
>>> GF_EVENT_CHILD_UP
>>> 2008-08-03 20:19:17 D
>>> [client-protocol.c:5096:client_protocol_handshake_reply] remote2: reply
>>> frame has callid: 424242
>>> 2008-08-03 20:19:17 D
>>> [client-protocol.c:5130:client_protocol_handshake_reply] remote2: SETVOLUME
>>> on remote-host succeeded
>>> 2008-08-03 20:19:18 D [client-protocol.c:4756:client_protocol_reconnect]
>>> remote1: breaking reconnect chain
>>> 2008-08-03 20:19:18 D [client-protocol.c:4756:client_protocol_reconnect]
>>> remote2: breaking reconnect chain
>>>
>>> On Fri, Aug 1, 2008 at 4:36 PM, Amar S. Tumballi <amar at zresearch.com>wrote:
>>>
>>>> Version of glusterfs used will help us a lot. (Get it by 'glustersf -V')
>>>>
>>>> Also, any snippet of log files (mostly the last few lines) which
>>>> contains errors logs related to this would help too.
>>>>
>>>> Regards,
>>>> Amar
>>>>
>>>> 2008/8/1 Michael Di Domenico <mdidomenico4 at gmail.com>
>>>>
>>>>> I've just setup a simple gluster storage system on Centos 5.2 x64 w/
>>>>> gluster 1.3.10
>>>>>
>>>>> I have three storage bricks and one client
>>>>>
>>>>> Everytime i run iozone across this setup, i seem to get a bad file
>>>>> descriptor around the 4k mark.
>>>>>
>>>>> Any thoughts why? I'm sure more info is wanted, i'm just not sure what
>>>>> else to include at this point.
>>>>>
>>>>> thanks
>>>>>
>>>>> [root at green gluster]# cat /opt/gluster/etc/glusterfs/gluster.client
>>>>> volume remote1
>>>>> type protocol/client
>>>>> option transport-type tcp/client
>>>>> option remote-host n1
>>>>> option remote-subvolume brick
>>>>> end-volume
>>>>>
>>>>> volume remote2
>>>>> type protocol/client
>>>>> option transport-type tcp/client
>>>>> option remote-host n2
>>>>> option remote-subvolume brick
>>>>> end-volume
>>>>>
>>>>> volume remote3
>>>>> type protocol/client
>>>>> option transport-type tcp/client
>>>>> option remote-host n3
>>>>> option remote-subvolume brick
>>>>> end-volume
>>>>>
>>>>> volume stripe0
>>>>> type cluster/stripe
>>>>> option block-size *:1MB
>>>>> subvolumes remote1 remote2 remote3
>>>>> end-volume
>>>>>
>>>>> [root at green gluster]# cat /opt/gluster/etc/glusterfs/gluster.server
>>>>> volume brick
>>>>> type storage/posix
>>>>> option directory /gluster
>>>>> end-volume
>>>>>
>>>>> volume server
>>>>> type protocol/server
>>>>> option transport-type tcp/server
>>>>> option auth.ip.brick.allow *
>>>>> subvolumes brick
>>>>> end-volume
>>>>>
>>>>> --- iozone snipped...
>>>>>
>>>>> 4096 4 4109 4228 7336 10409 4245
>>>>> 4209 4163 4232 4178 4098 4215 10218 6782
>>>>> 4096 8 5951 6093 11445 11450 6096
>>>>> 6085 6028 6104 6054 5935 6077 11409 6792
>>>>> 4096 16 7609 7757 11395 7353 7825
>>>>> 7747 7705 7793 7776 7595 7753 11396 7078
>>>>> 4096 32 8915 9074 11313 10268 9166
>>>>> 9074 8977 9118 9127 8922 9083
>>>>>
>>>>> Error freading block 62 9d800000
>>>>> read: File descriptor in bad state
>>>>> [root at green gluster]#
>>>>> [root at green gluster]#
>>>>>
>>>>> _______________________________________________
>>>>> Gluster-users mailing list
>>>>> Gluster-users at gluster.org
>>>>> http://zresearch.com/cgi-bin/mailman/listinfo/gluster-users
>>>>>
>>>>>
>>>>
>>>>
>>>> --
>>>> Amar Tumballi
>>>> Gluster/GlusterFS Hacker
>>>> [bulde on #gluster/irc.gnu.org]
>>>> http://www.zresearch.com - Commoditizing Super Storage!
>>>>
>>>
>>>
>>
>
> _______________________________________________
> Gluster-users mailing list
> Gluster-users at gluster.org
> http://zresearch.com/cgi-bin/mailman/listinfo/gluster-users
>
>
--
If I traveled to the end of the rainbow
As Dame Fortune did intend,
Murphy would be there to tell me
The pot's at the other end.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://supercolony.gluster.org/pipermail/gluster-users/attachments/20080807/b9b58ea4/attachment.html>
More information about the Gluster-users
mailing list