Hi, I've been running bonnie++ 1.03a more than 24hrs ago, and only recently it has failed. It is an AFR setup. $ bonnie++ -u bonnie -d /home/storage -s 7904m:256k -n 1024:-2:5m:30 -x 10 Using uid:100, gid:65534. name,file_size,putc,putc_cpu,put_block,put_block_cpu,rewrite,rewrite_cpu,getc,getc_cpu,get_block,get_block_cpu,seeks,seeks_cpu,num_files,seq_create,seq_create_cpu,seq_stat,seq_stat_cpu,seq_del,seq_del_cpu,ran_create,ran_create_cpu,ran_stat,ran_stat_cpu,ran_del,ran_del_cpu Writing with putc()...Can't putc() - disk full? Space is never a problem. $ df -h Filesystem Size Used Avail Use% Mounted on /dev/hdv1 922G 11G 911G 2% / Here are the GlusterFS 1.4.0-pre5 logs: (can't paste everything, so only the relevant bits) ===== Client ===== 2008-09-13 07:14:50 D [fuse-bridge.c:1510:fuse_writev_cbk] glusterfs-fuse: 445455: WRITE => 4096/4096,750338048/750342144 2008-09-13 07:14:50 D [fuse-bridge.c:1548:fuse_write] glusterfs-fuse: 445456: WRITE (0x515690, size=4096, offset=750342144) 2008-09-13 07:15:14 D [fuse-bridge.c:1510:fuse_writev_cbk] glusterfs-fuse: 445456: WRITE => 4096/4096,750342144/750346240 2008-09-13 07:15:14 D [fuse-bridge.c:1548:fuse_write] glusterfs-fuse: 445457: WRITE (0x515690, size=4096, offset=750346240) 2008-09-13 07:15:53 E [client-protocol.c:216:call_bail] gfs-client1: activating bail-out. pending frames = 1. last sent = 2008-09-13 07:15:14. last received = 2008-09-13 07:15:14. transport-timeout = 30 2008-09-13 07:15:53 C [client-protocol.c:223:call_bail] gfs-client1: bailing transport 2008-09-13 07:15:53 D [socket.c:183:__socket_disconnect] gfs-client1: shutdown() returned 0. setting connection state to -1 2008-09-13 07:15:53 W [socket.c:93:__socket_rwv] gfs-client1: EOF from peer 62.212.91.119:37268 2008-09-13 07:15:53 D [socket.c:568:socket_proto_state_machine] gfs-client1: socket read failed (Transport endpoint is not connected) in state 1 ( 62.212.91.119:37268) 2008-09-13 07:15:53 D [client-protocol.c:4153:protocol_client_cleanup] gfs-client1: cleaning up state in transport object 0x50dd30 2008-09-13 07:15:53 E [client-protocol.c:4205:protocol_client_cleanup] gfs-client1: forced unwinding frame type(1) op(WRITE) reply=@0x2aaaaae00940 2008-09-13 07:15:53 E [afr.c:2651:afr_writev_cbk] gfs-afr: (path=/Bonnie.12457.001 child=gfs-client1) op_ret=-1 op_errno=107(Transport endpoint is not connected) 2008-09-13 07:15:53 E [fuse-bridge.c:1516:fuse_writev_cbk] glusterfs-fuse: 445457: WRITE => -1 (Transport endpoint is not connected) 2008-09-13 07:15:53 D [afr.c:6333:notify] gfs-afr: GF_EVENT_CHILD_DOWN from gfs-client1 2008-09-13 07:15:53 D [fuse-bridge.c:1548:fuse_write] glusterfs-fuse: 445458: WRITE (0x515c90, size=4096, offset=1073737728) 2008-09-13 07:15:53 E [afr.c:2651:afr_writev_cbk] gfs-afr: (path=/Bonnie.12457.000 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:2651:afr_writev_cbk] gfs-afr: (path=/Bonnie.12457.000 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:1516:fuse_writev_cbk] glusterfs-fuse: 445458: WRITE => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445459: FLUSH 0x515c90 2008-09-13 07:15:53 E [afr.c:2974:afr_flush] gfs-afr: afrfdp->fdstate[] is 0, returning ENOTCONN 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445459: FLUSH() ERR => -1 (Transport endpoint is not connected) 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445460: CLOSE 0x515c90 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445461: FLUSH 0x515690 2008-09-13 07:15:53 E [afr.c:2974:afr_flush] gfs-afr: afrfdp->fdstate[] is 0, returning ENOTCONN 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445461: FLUSH() ERR => -1 (Transport endpoint is not connected) 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445462: CLOSE 0x515690 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445463: FLUSH 0x5151b0 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.002 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.002 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445463: FLUSH() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:937:afr_incver_internal_lock_cbk] gfs-afr: (path=/Bonnie.12457.000) none of the subvols are up for locking 2008-09-13 07:15:53 E [afr.c:940:afr_incver_internal_lock_cbk] gfs-afr: afrfdp is NULL, for /Bonnie.12457.000 2008-09-13 07:15:53 E [afr.c:937:afr_incver_internal_lock_cbk] gfs-afr: (path=/Bonnie.12457.001) none of the subvols are up for locking 2008-09-13 07:15:53 E [afr.c:940:afr_incver_internal_lock_cbk] gfs-afr: afrfdp is NULL, for /Bonnie.12457.001 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.000 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.000 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445460: CLOSE() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] fuse/inode: passivating inode(2013354535) lru=1/0 active=8 purge=20 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.001 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.001 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445462: CLOSE() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] fuse/inode: passivating inode(2013354536) lru=2/0 active=7 purge=20 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445464: CLOSE 0x5151b0 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445465: FLUSH 0x516760 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.003 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.003 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445465: FLUSH() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445466: CLOSE 0x516760 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445467: FLUSH 0x517260 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.004 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.004 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445467: FLUSH() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.002 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.002 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445464: CLOSE() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] fuse/inode: passivating inode(2013354537) lru=3/0 active=6 purge=20 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445468: CLOSE 0x517260 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445469: FLUSH 0x518140 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.005 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.005 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445469: FLUSH() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.003 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.003 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445466: CLOSE() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] fuse/inode: passivating inode(2013354538) lru=4/0 active=5 purge=20 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445470: CLOSE 0x518140 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445471: FLUSH 0x5188b0 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.006 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.006 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445471: FLUSH() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.004 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.004 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445468: CLOSE() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] fuse/inode: passivating inode(2013354539) lru=5/0 active=4 purge=20 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445472: CLOSE 0x5188b0 2008-09-13 07:15:53 D [fuse-bridge.c:1572:fuse_flush] glusterfs-fuse: 445473: FLUSH 0x519040 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.007 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:2919:afr_flush_cbk] gfs-afr: (path=/Bonnie.12457.007 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445473: FLUSH() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.005 child=gfs-client1) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [afr.c:3012:afr_close_cbk] gfs-afr: (path=/Bonnie.12457.005 child=gfs-client2) op_ret=-1 op_errno=77(File descriptor in bad state) 2008-09-13 07:15:53 E [fuse-bridge.c:873:fuse_err_cbk] glusterfs-fuse: 445470: CLOSE() ERR => -1 (File descriptor in bad state) 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] fuse/inode: passivating inode(2013354540) lru=6/0 active=3 purge=20 2008-09-13 07:15:53 D [fuse-bridge.c:1599:fuse_release] glusterfs-fuse: 445474: CLOSE 0x519040 2008-09-13 07:15:53 D [inode.c:268:__inode_activate] fuse/inode: activating inode(2013354535), ... (continues...) ===== Server ====== 2008-09-13 07:02:05 D [socket.c:636:socket_proto_state_machine] gfs-server2: partial header read on NB socket. continue later 2008-09-13 07:02:26 D [socket.c:636:socket_proto_state_machine] gfs-server2: partial header read on NB socket. continue later 2008-09-13 07:02:26 D [socket.c:636:socket_proto_state_machine] gfs-server2: partial header read on NB socket. continue later 2008-09-13 07:02:33 D [socket.c:636:socket_proto_state_machine] gfs-server2: partial header read on NB socket. continue later 2008-09-13 07:02:57 W [socket.c:93:__socket_rwv] gfs-server2: EOF from peer 62.212.91.118:1022 2008-09-13 07:02:57 D [socket.c:568:socket_proto_state_machine] gfs-server2: socket read failed (Transport endpoint is not connected) in state 1 ( 62.212.91.118:1022) 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077150) lru=3/1024 active=8 purge=20 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077151) lru=4/1024 active=7 purge=20 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077152) lru=5/1024 active=6 purge=20 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077153) lru=6/1024 active=5 purge=20 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077154) lru=7/1024 active=4 purge=20 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077155) lru=8/1024 active=3 purge=20 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077156) lru=9/1024 active=2 purge=20 2008-09-13 07:02:57 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077157) lru=10/1024 active=1 purge=20 2008-09-13 07:02:57 D [server-protocol.c:6182:server_protocol_cleanup] gfs-server2: cleaned up transport state for client 62.212.91.118:1022 2008-09-13 07:02:57 D [socket.c:1287:fini] gfs-server2: transport 0x50d980 destroyed 2008-09-13 07:02:57 D [addr.c:166:gf_auth] gfs-storage2: allowed = "*", received addr = "62.212.91.118" 2008-09-13 07:02:57 D [server-protocol.c:5544:mop_setvolume] gfs-server2: accepted client from 62.212.91.118:1022 2008-09-13 07:15:53 D [inode.c:268:__inode_activate] gfs-storage2/inode: activating inode(1879077150), lru=9/1024 active=2 purge=20 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077150) lru=10/1024 active=1 purge=20 2008-09-13 07:15:53 D [inode.c:268:__inode_activate] gfs-storage2/inode: activating inode(1879077150), lru=9/1024 active=2 purge=20 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077150) lru=10/1024 active=1 purge=20 2008-09-13 07:15:53 D [inode.c:268:__inode_activate] gfs-storage2/inode: activating inode(1879077150), lru=9/1024 active=2 purge=20 2008-09-13 07:15:53 D [inode.c:311:__inode_retire] gfs-storage2/inode: retiring inode(1879077150) lru=9/1024 active=1 purge=21 2008-09-13 07:15:53 D [inode.c:251:__inode_destroy] gfs-storage2/inode: destroy inode(1879077150) [@0x50f7d0] 2008-09-13 07:15:53 D [inode.c:268:__inode_activate] gfs-storage2/inode: activating inode(1879077151), lru=8/1024 active=2 purge=21 2008-09-13 07:15:53 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077151) lru=9/1024 active=1 purge=21 2008-09-13 07:15:54 D [inode.c:268:__inode_activate] gfs-storage2/inode: activating inode(1879077151), lru=8/1024 active=2 purge=21 2008-09-13 07:15:54 D [inode.c:287:__inode_passivate] gfs-storage2/inode: passivating inode(1879077151) lru=9/1024 active=1 purge=21 2008-09-13 07:15:54 D [inode.c:268:__inode_activate] gfs-storage2/inode: activating inode(1879077151), lru=8/1024 active=2 purge=21 2008-09-13 07:15:54 D [inode.c:311:__inode_retire] gfs-storage2/inode: retiring inode(1879077151) lru=8/1024 active=1 purge=22 2008-09-13 07:15:54 D [inode.c:251:__inode_destroy] gfs-storage2/inode: destroy inode(1879077151) [@0x50ee30] ...(continues...) Any clues? KwangErn
