I think I've found the culprit. It was due to having mounted with noacl.
cp -a attempts ACL operations, which fail wiht noacl mounts, but GlusterFS
was apparently remembering that error and passing it as the return for
fchmod. With the filesystems mounted with acl support, the error is gone.
Here is the glusterfs log from "cp -a /bin/ls /beast" when the filesystems
were mounted with noacl:
2008-07-23 15:59:19 D [fuse-bridge.c:363:fuse_entry_cbk] glusterfs-fuse: 34: (op_num=34) / => 1
2008-07-23 15:59:19 D [fuse-bridge.c:505:fuse_lookup] glusterfs-fuse: 35: LOOKUP /ls
2008-07-23 15:59:19 D [fuse-bridge.c:443:fuse_entry_cbk] glusterfs-fuse: 35: (op_num=34) /ls => -1 (No such file or directory)
2008-07-23 15:59:19 D [inode.c:397:__passive_inode] fuse/inode: purging inode(0) lru=5/0
2008-07-23 15:59:19 D [fuse-bridge.c:505:fuse_lookup] glusterfs-fuse: 36: LOOKUP /ls
2008-07-23 15:59:19 D [fuse-bridge.c:443:fuse_entry_cbk] glusterfs-fuse: 36: (op_num=34) /ls => -1 (No such file or directory)
2008-07-23 15:59:19 D [inode.c:397:__passive_inode] fuse/inode: purging inode(0) lru=5/0
2008-07-23 15:59:19 D [fuse-bridge.c:1511:fuse_create] glusterfs-fuse: 37: CREATE /ls
2008-07-23 15:59:19 D [fuse-bridge.c:1383:fuse_create_cbk] glusterfs-fuse: 37: (op_num=27) /ls => 0xb4b01170
2008-07-23 15:59:19 D [inode.c:569:__create_inode] fuse/inode: create inode(30044)
2008-07-23 15:59:19 D [inode.c:362:__active_inode] fuse/inode: activating inode(30044), lru=5/0
2008-07-23 15:59:19 D [inode.c:397:__passive_inode] fuse/inode: purging inode(0) lru=5/0
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 38: WRITE (0xb4b01170, size=8192, offset=0)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 38: WRITE => 8192/8192,0/8192
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 39: WRITE (0xb4b01170, size=8192, offset=8192)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 39: WRITE => 8192/8192,8192/16384
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 40: WRITE (0xb4b01170, size=8192, offset=16384)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 40: WRITE => 8192/8192,16384/24576
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 41: WRITE (0xb4b01170, size=8192, offset=24576)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 41: WRITE => 8192/8192,24576/32768
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 42: WRITE (0xb4b01170, size=8192, offset=32768)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 42: WRITE => 8192/8192,32768/40960
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 43: WRITE (0xb4b01170, size=8192, offset=40960)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 43: WRITE => 8192/8192,40960/49152
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 44: WRITE (0xb4b01170, size=8192, offset=49152)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 44: WRITE => 8192/8192,49152/57344
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 45: WRITE (0xb4b01170, size=8192, offset=57344)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 45: WRITE => 8192/8192,57344/65536
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 46: WRITE (0xb4b01170, size=8192, offset=65536)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 46: WRITE => 8192/8192,65536/73728
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 47: WRITE (0xb4b01170, size=8192, offset=73728)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 47: WRITE => 8192/8192,73728/81920
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 48: WRITE (0xb4b01170, size=8192, offset=81920)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 48: WRITE => 8192/8192,81920/90112
2008-07-23 15:59:19 D [fuse-bridge.c:1682:fuse_write] glusterfs-fuse: 49: WRITE (0xb4b01170, size=2264, offset=90112)
2008-07-23 15:59:19 D [fuse-bridge.c:1644:fuse_writev_cbk] glusterfs-fuse: 49: WRITE => 2264/2264,90112/92376
2008-07-23 15:59:19 D [fuse-bridge.c:878:do_utimes] glusterfs-fuse: 50: UTIMENS /ls
2008-07-23 15:59:19 D [fuse-bridge.c:564:fuse_attr_cbk] glusterfs-fuse: 50: (op_num=31) /ls => 30044
2008-07-23 15:59:19 D [fuse-bridge.c:2140:fuse_setxattr] glusterfs-fuse: 51: SETXATTR /ls/30044 (system.posix_acl_access)
2008-07-23 15:59:19 E [afr.c:1145:afr_setxattr_cbk] mirror0: (path=/ls child=share0-0) op_ret=-1 op_errno=95(Operation not supported)
2008-07-23 15:59:19 E [afr.c:1145:afr_setxattr_cbk] mirror0: (path=/ls child=share0-1) op_ret=-1 op_errno=95(Operation not supported)
2008-07-23 15:59:19 D [unify.c:2980:unify_setxattr_cbk] mirrors: child(mirror0): path(): Operation not supported
2008-07-23 15:59:19 D [fuse-bridge.c:721:do_chmod] glusterfs-fuse: 52: FCHMOD 0xb4b01170
2008-07-23 15:59:19 D [fuse-bridge.c:564:fuse_attr_cbk] glusterfs-fuse: 52: (op_num=32) ERR => 0
2008-07-23 15:59:19 D [fuse-bridge.c:1733:fuse_release] glusterfs-fuse: 53: CLOSE 0xb4b01170
2008-07-23 15:59:19 D [fuse-bridge.c:924:fuse_err_cbk] glusterfs-fuse: 53: (op_num=17) ERR => 0
2008-07-23 15:59:19 D [inode.c:393:__passive_inode] fuse/inode: passivating inode(30044) lru=6/0
Thanks,
Brent
