[Gluster-users] ls gives Input/Output error
James Whitwell
jams at jj.id.au
Thu Apr 30 05:35:55 UTC 2015
Hi,
I've been getting an "Input/Output error" from 'ls' on a new install of
glusterfs 3.4.2 on 32-bit Ubuntu 14.04 on our production servers. On our
test servers (provisioned with Vagrant using the same version of Ubuntu,
but 64-bit) I don't get the error. I can't seem to see anything in the
logs that points to the error, but hopefully someone can point me in the
right direction.
jams at node01:~$ sudo gluster
gluster> volume create s5 node01:/gfs/data2/s5 force
volume create: s5: success: please start the volume to access data
gluster> volume start s5
volume start: s5: success
gluster> exit
jams at node01:~$ sudo mkdir /gfs/mnt/s5
jams at node01:~$ sudo mount -t glusterfs node01:/s5 /gfs/mnt/s5
jams at node01:~$ mount | grep s5
node01:/s5 on /gfs/mnt/s5 type fuse.glusterfs
(rw,default_permissions,allow_other,max_read=131072)
jams at node01:~$ cd /gfs/mnt/s5
jams at node01:/gfs/mnt/s5$ ls
jams at node01:/gfs/mnt/s5$ sudo touch a b c d e f g h i j k l m n o p q r s t
u v w x y z
jams at node01:/gfs/mnt/s5$ ls -l
ls: reading directory .: Input/output error
total 0
jams at node01:/gfs/mnt/s5$
Running an strace on 'ls -l' shows the error coming from this:
openat(AT_FDCWD, ".",
O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 3
getdents64(3, 0x9b04ee4, 32768) = -1 EIO (Input/output error)
If I remove a couple of files it starts working again:
jams at node01:/gfs/mnt/s5$ sudo rm z
jams at node01:/gfs/mnt/s5$ ls
ls: reading directory .: Input/output error
jams at node01:/gfs/mnt/s5$ sudo rm y
jams at node01:/gfs/mnt/s5$ ls
ls: reading directory .: Input/output error
jams at node01:/gfs/mnt/s5$ sudo rm x
jams at node01:/gfs/mnt/s5$ ls
a b c d e f g h i j k l m n o p q r s t u v w
jams at node01:/gfs/mnt/s5$
My /var/log/glusterfs/gfs-mnt-s5.log looks like this:
[2015-04-30 05:14:58.414575] I [glusterfsd.c:1910:main]
0-/usr/sbin/glusterfs: Started running /usr/sbin/glusterfs version 3.4.2
(/usr/sbin/glusterfs --volfile-id=/s5 --volfile-server=node01 /gfs/mnt/s5)
[2015-04-30 05:14:58.417227] I [socket.c:3480:socket_init] 0-glusterfs: SSL
support is NOT enabled
[2015-04-30 05:14:58.417287] I [socket.c:3495:socket_init] 0-glusterfs:
using system polling thread
[2015-04-30 05:14:58.421834] I [socket.c:3480:socket_init] 0-s5-client-0:
SSL support is NOT enabled
[2015-04-30 05:14:58.421873] I [socket.c:3495:socket_init] 0-s5-client-0:
using system polling thread
[2015-04-30 05:14:58.421903] I [client.c:2154:notify] 0-s5-client-0: parent
translators are ready, attempting connect on transport
Given volfile:
+------------------------------------------------------------------------------+
1: volume s5-client-0
2: type protocol/client
3: option password 76ac8223-0c60-40e5-958e-22a186477e95
4: option username fa437814-33f8-4711-a672-8da1c914a39d
5: option transport-type tcp
6: option remote-subvolume /gfs/data2/s5
7: option remote-host node01
8: end-volume
9:
10: volume s5-dht
11: type cluster/distribute
12: subvolumes s5-client-0
13: end-volume
14:
15: volume s5-write-behind
16: type performance/write-behind
17: subvolumes s5-dht
18: end-volume
19:
20: volume s5-read-ahead
21: type performance/read-ahead
22: subvolumes s5-write-behind
23: end-volume
24:
25: volume s5-io-cache
26: type performance/io-cache
27: subvolumes s5-read-ahead
28: end-volume
29:
30: volume s5-quick-read
31: type performance/quick-read
32: subvolumes s5-io-cache
33: end-volume
34:
35: volume s5-open-behind
36: type performance/open-behind
37: subvolumes s5-quick-read
38: end-volume
39:
40: volume s5-md-cache
41: type performance/md-cache
42: subvolumes s5-open-behind
43: end-volume
44:
45: volume s5
46: type debug/io-stats
47: option count-fop-hits off
48: option latency-measurement off
49: subvolumes s5-md-cache
50: end-volume
+------------------------------------------------------------------------------+
[2015-04-30 05:14:58.422818] I [rpc-clnt.c:1676:rpc_clnt_reconfig]
0-s5-client-0: changing port to 49154 (from 0)
[2015-04-30 05:14:58.422887] W [socket.c:514:__socket_rwv] 0-s5-client-0:
readv failed (No data available)
[2015-04-30 05:14:58.423616] I
[client-handshake.c:1659:select_server_supported_programs] 0-s5-client-0:
Using Program GlusterFS 3.3, Num (1298437), Version (330)
[2015-04-30 05:14:58.423836] I
[client-handshake.c:1456:client_setvolume_cbk] 0-s5-client-0: Connected to
172.16.100.1:49154, attached to remote volume '/gfs/data2/s5'.
[2015-04-30 05:14:58.423851] I
[client-handshake.c:1468:client_setvolume_cbk] 0-s5-client-0: Server and
Client lk-version numbers are not same, reopening the fds
[2015-04-30 05:14:58.427357] I [fuse-bridge.c:4769:fuse_graph_setup]
0-fuse: switched to graph 0
[2015-04-30 05:14:58.427561] I
[client-handshake.c:450:client_set_lk_version_cbk] 0-s5-client-0: Server lk
version = 1
[2015-04-30 05:14:58.427600] I [fuse-bridge.c:3724:fuse_init]
0-glusterfs-fuse: FUSE inited with protocol versions: glusterfs 7.13 kernel
7.22
[2015-04-30 05:15:13.117149] W
[client-rpc-fops.c:1232:client3_3_removexattr_cbk] 0-s5-client-0: remote
operation failed: No data available
[2015-04-30 05:15:13.117184] W [fuse-bridge.c:1172:fuse_err_cbk]
0-glusterfs-fuse: 15: REMOVEXATTR() /a => -1 (No data available)
[2015-04-30 05:15:13.119338] W
[client-rpc-fops.c:1232:client3_3_removexattr_cbk] 0-s5-client-0: remote
operation failed: No data available
[2015-04-30 05:15:13.119364] W [fuse-bridge.c:1172:fuse_err_cbk]
0-glusterfs-fuse: 22: REMOVEXATTR() /b => -1 (No data available)
[2015-04-30 05:15:13.121348] W
[client-rpc-fops.c:1232:client3_3_removexattr_cbk] 0-s5-client-0: remote
operation failed: No data available
[2015-04-30 05:15:13.121373] W [fuse-bridge.c:1172:fuse_err_cbk]
0-glusterfs-fuse: 29: REMOVEXATTR() /c => -1 (No data available)
(this continues for the remainder of the files e.g. /d .. /z, then the log
file finishes).
/var/log/glusterfs/bricks/gfs-data2-s5.log:
[2015-04-30 05:14:24.914914] I [glusterfsd.c:1910:main]
0-/usr/sbin/glusterfsd: Started running /usr/sbin/glusterfsd version 3.4.2
(/usr/sbin/glusterfsd -s node01 --volfile-id s5.node01.gfs-data2-s5 -p
/var/lib/glusterd/vols/s5/run/node01-gfs-data2-s5.pid -S
/var/run/682aa9b5d57ea70794f18c3fa217a786.socket --brick-name /gfs/data2/s5
-l /var/log/glusterfs/bricks/gfs-data2-s5.log --xlator-option
*-posix.glusterd-uuid=ed8d9539-767a-4634-8380-e3bd7a6905f0 --brick-port
49154 --xlator-option s5-server.listen-port=49154)
[2015-04-30 05:14:24.916738] I [socket.c:3480:socket_init]
0-socket.glusterfsd: SSL support is NOT enabled
[2015-04-30 05:14:24.916786] I [socket.c:3495:socket_init]
0-socket.glusterfsd: using system polling thread
[2015-04-30 05:14:24.916938] I [socket.c:3480:socket_init] 0-glusterfs: SSL
support is NOT enabled
[2015-04-30 05:14:24.916951] I [socket.c:3495:socket_init] 0-glusterfs:
using system polling thread
[2015-04-30 05:14:24.919621] I [graph.c:239:gf_add_cmdline_options]
0-s5-server: adding option 'listen-port' for volume 's5-server' with value
'49154'
[2015-04-30 05:14:24.919641] I [graph.c:239:gf_add_cmdline_options]
0-s5-posix: adding option 'glusterd-uuid' for volume 's5-posix' with value
'ed8d9539-767a-4634-8380-e3bd7a6905f0'
[2015-04-30 05:14:24.921094] W [options.c:848:xl_opt_validate] 0-s5-server:
option 'listen-port' is deprecated, preferred is
'transport.socket.listen-port', continuing with correction
[2015-04-30 05:14:24.921167] I [socket.c:3480:socket_init] 0-tcp.s5-server:
SSL support is NOT enabled
[2015-04-30 05:14:24.921178] I [socket.c:3495:socket_init] 0-tcp.s5-server:
using system polling thread
Given volfile:
+------------------------------------------------------------------------------+
1: volume s5-posix
2: type storage/posix
3: option volume-id c774c24f-5205-4ebe-a05f-0c5fcd126d61
4: option directory /gfs/data2/s5
5: end-volume
6:
7: volume s5-access-control
8: type features/access-control
9: subvolumes s5-posix
10: end-volume
11:
12: volume s5-locks
13: type features/locks
14: subvolumes s5-access-control
15: end-volume
16:
17: volume s5-io-threads
18: type performance/io-threads
19: subvolumes s5-locks
20: end-volume
21:
22: volume s5-index
23: type features/index
24: option index-base /gfs/data2/s5/.glusterfs/indices
25: subvolumes s5-io-threads
26: end-volume
27:
28: volume s5-marker
29: type features/marker
30: option quota off
31: option xtime off
32: option timestamp-file /var/lib/glusterd/vols/s5/marker.tstamp
33: option volume-uuid c774c24f-5205-4ebe-a05f-0c5fcd126d61
34: subvolumes s5-index
35: end-volume
36:
37: volume /gfs/data2/s5
38: type debug/io-stats
39: option count-fop-hits off
40: option latency-measurement off
41: subvolumes s5-marker
42: end-volume
43:
44: volume s5-server
45: type protocol/server
46: option auth.addr./gfs/data2/s5.allow *
47: option auth.login.fa437814-33f8-4711-a672-8da1c914a39d.password
76ac8223-0c60-40e5-958e-22a186477e95
48: option auth.login./gfs/data2/s5.allow
fa437814-33f8-4711-a672-8da1c914a39d
49: option transport-type tcp
50: subvolumes /gfs/data2/s5
51: end-volume
+------------------------------------------------------------------------------+
[2015-04-30 05:14:25.817778] I [server-handshake.c:567:server_setvolume]
0-s5-server: accepted client from
a4-25244-2015/04/30-05:14:25:778408-s5-client-0-0 (version: 3.4.2)
[2015-04-30 05:14:58.423749] I [server-handshake.c:567:server_setvolume]
0-s5-server: accepted client from
a4-25318-2015/04/30-05:14:58:409990-s5-client-0-0 (version: 3.4.2)
[2015-04-30 05:15:13.117069] E [marker.c:2140:marker_removexattr_cbk]
0-s5-marker: No data available occurred while creating symlinks
[2015-04-30 05:15:13.117105] I
[server-rpc-fops.c:745:server_removexattr_cbk] 0-s5-server: 29: REMOVEXATTR
/a (5bbac41a-3961-40fd-874a-af71e9994bf7) of key security.ima ==> (No data
available)
[2015-04-30 05:15:13.119256] E [marker.c:2140:marker_removexattr_cbk]
0-s5-marker: No data available occurred while creating symlinks
[2015-04-30 05:15:13.119298] I
[server-rpc-fops.c:745:server_removexattr_cbk] 0-s5-server: 41: REMOVEXATTR
/b (f17fdb60-b4f9-490f-92b7-6877ff6d5f52) of key security.ima ==> (No data
available)
[2015-04-30 05:15:13.121289] E [marker.c:2140:marker_removexattr_cbk]
0-s5-marker: No data available occurred while creating symlinks
[2015-04-30 05:15:13.121309] I
[server-rpc-fops.c:745:server_removexattr_cbk] 0-s5-server: 53: REMOVEXATTR
/c (3ea402b7-50f3-45f4-9e72-84463780a12f) of key security.ima ==> (No data
available)
[2015-04-30 05:15:13.123316] E [marker.c:2140:marker_removexattr_cbk]
0-s5-marker: No data available occurred while creating symlinks
(and so on up until /z, where it finishes)
And /var/log/glusterfs/etc-glusterfs-glusterd.vol.log (apologies, this
contains some logging from previous attempts):
[2015-04-30 04:42:06.630714] I [glusterfsd.c:1910:main]
0-/usr/sbin/glusterd: Started running /usr/sbin/glusterd version 3.4.2
(/usr/sbin/glusterd -p /var/run/glusterd.pid)
[2015-04-30 04:42:06.634434] I [glusterd.c:961:init] 0-management: Using
/var/lib/glusterd as working directory
[2015-04-30 04:42:06.635508] I [socket.c:3480:socket_init]
0-socket.management: SSL support is NOT enabled
[2015-04-30 04:42:06.635532] I [socket.c:3495:socket_init]
0-socket.management: using system polling thread
[2015-04-30 04:42:06.636084] W [rdma.c:4197:__gf_rdma_ctx_create]
0-rpc-transport/rdma: rdma_cm event channel creation failed (No such device)
[2015-04-30 04:42:06.636100] E [rdma.c:4485:init] 0-rdma.management: Failed
to initialize IB Device
[2015-04-30 04:42:06.636110] E [rpc-transport.c:320:rpc_transport_load]
0-rpc-transport: 'rdma' initialization failed
[2015-04-30 04:42:06.636160] W [rpcsvc.c:1389:rpcsvc_transport_create]
0-rpc-service: cannot create listener, initing the transport failed
[2015-04-30 04:42:08.182024] E [store.c:394:gf_store_handle_retrieve] 0-:
Unable to retrieve store handle /var/lib/glusterd/glusterd.info, error: No
such file or directory
[2015-04-30 04:42:08.182069] E
[glusterd-store.c:1288:glusterd_retrieve_op_version] 0-: Unable to get
store handle!
[2015-04-30 04:42:08.182086] E [store.c:394:gf_store_handle_retrieve] 0-:
Unable to retrieve store handle /var/lib/glusterd/glusterd.info, error: No
such file or directory
[2015-04-30 04:42:08.182097] E
[glusterd-store.c:1389:glusterd_retrieve_uuid] 0-: Unable to get store
handle!
[2015-04-30 04:42:08.182107] I
[glusterd-store.c:1359:glusterd_restore_op_version] 0-management: Detected
new install. Setting op-version to maximum : 2
[2015-04-30 04:42:08.182216] E [store.c:394:gf_store_handle_retrieve] 0-:
Unable to retrieve store handle /var/lib/glusterd/options, error: No such
file or directory
Given volfile:
+------------------------------------------------------------------------------+
1: volume management
2: type mgmt/glusterd
3: option working-directory /var/lib/glusterd
4: option transport-type socket,rdma
5: option transport.socket.keepalive-time 10
6: option transport.socket.keepalive-interval 2
7: option transport.socket.read-fail-log off
8: # option base-port 49152
9: end-volume
+------------------------------------------------------------------------------+
[2015-04-30 04:42:08.252316] E [glusterd-handshake.c:272:__server_getspec]
0-glusterd: Unable to stat
/var/lib/glusterd/glustershd/glustershd-server.vol (No such file or
directory)
[2015-04-30 04:42:08.586342] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /gfs/data2/sites on port 49152
[2015-04-30 04:42:09.224250] I
[glusterd-handshake.c:557:__glusterd_mgmt_hndsk_versions_ack] 0-management:
using the op-version 2
[2015-04-30 04:42:09.224298] E [store.c:394:gf_store_handle_retrieve] 0-:
Unable to retrieve store handle /var/lib/glusterd/glusterd.info, error: No
such file or directory
[2015-04-30 04:42:09.224312] E
[glusterd-store.c:1389:glusterd_retrieve_uuid] 0-: Unable to get store
handle!
[2015-04-30 04:42:09.224346] I [glusterd.c:155:glusterd_uuid_generate_save]
0-management: generated UUID: ed8d9539-767a-4634-8380-e3bd7a6905f0
[2015-04-30 04:42:09.463337] I
[glusterd-handler.c:1956:__glusterd_handle_incoming_friend_req] 0-glusterd:
Received probe from uuid: 37367989-bd2e-4ba6-865e-98a31a6538ea
[2015-04-30 04:42:09.463750] I
[glusterd-handler.c:2987:glusterd_xfer_friend_add_resp] 0-glusterd:
Responded to 172.16.100.2 (24007), ret: 0
[2015-04-30 04:48:55.636233] E [glusterd-syncop.c:767:gd_stage_op_phase]
0-management: Staging of operation 'Volume Create' failed on localhost :
The brick node01:/gfs/data2/s4 is is being created in the root partition.
It is recommended that you don't use the system's root partition for
storage backend. Or use 'force' at the end of the command if you want to
override this behavior.
[2015-04-30 04:48:58.413158] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 04:48:58.413667] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 04:48:58.414256] E [glusterd-handshake.c:272:__server_getspec]
0-glusterd: Unable to stat
/var/lib/glusterd/glustershd/glustershd-server.vol (No such file or
directory)
[2015-04-30 04:49:01.771030] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /gfs/data2/s4 on port 49153
[2015-04-30 04:49:01.771521] I [rpc-clnt.c:962:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2015-04-30 04:49:01.771593] I [socket.c:3480:socket_init] 0-management:
SSL support is NOT enabled
[2015-04-30 04:49:01.771606] I [socket.c:3495:socket_init] 0-management:
using system polling thread
[2015-04-30 04:49:02.581709] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 04:49:02.591445] I [rpc-clnt.c:962:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2015-04-30 04:49:02.591546] I [socket.c:3480:socket_init] 0-management:
SSL support is NOT enabled
[2015-04-30 04:49:02.591560] I [socket.c:3495:socket_init] 0-management:
using system polling thread
[2015-04-30 04:49:02.592218] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 04:49:02.592271] I [socket.c:2236:socket_event_handler]
0-transport: disconnecting now
[2015-04-30 05:07:54.869244] W
[glusterd-op-sm.c:3237:glusterd_op_modify_op_ctx] 0-management: op_ctx
modification failed
[2015-04-30 05:07:54.869527] I
[glusterd-handler.c:3260:__glusterd_handle_status_volume] 0-management:
Received status volume req for volume s4
[2015-04-30 05:08:00.001050] E
[glusterd-utils.c:1618:glusterd_brick_unlink_socket_file] 0-management:
Failed to remove /var/run/b9bb9e1da9af26f9226f6fa4e3697622.socket error:
Resource temporarily unavailable
[2015-04-30 05:08:00.001209] W [socket.c:514:__socket_rwv] 0-management:
readv failed (No data available)
[2015-04-30 05:08:01.895838] E
[glusterd-utils.c:3801:glusterd_nodesvc_unlink_socket_file] 0-management:
Failed to remove /var/run/3fd66a6bdf31f9be8cfe54b19da7a53e.socket error:
Resource temporarily unavailable
[2015-04-30 05:08:01.896220] I
[glusterd-utils.c:3835:glusterd_nfs_pmap_deregister] 0-: De-registered
MOUNTV3 successfully
[2015-04-30 05:08:01.896416] I
[glusterd-utils.c:3840:glusterd_nfs_pmap_deregister] 0-: De-registered
MOUNTV1 successfully
[2015-04-30 05:08:01.896555] I
[glusterd-utils.c:3845:glusterd_nfs_pmap_deregister] 0-: De-registered
NFSV3 successfully
[2015-04-30 05:08:01.896692] I
[glusterd-utils.c:3850:glusterd_nfs_pmap_deregister] 0-: De-registered NLM
v4 successfully
[2015-04-30 05:08:01.896827] I
[glusterd-utils.c:3855:glusterd_nfs_pmap_deregister] 0-: De-registered NLM
v1 successfully
[2015-04-30 05:08:01.897263] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 05:08:01.897288] I [mem-pool.c:541:mem_pool_destroy]
0-management: size=2148 max=1 total=1
[2015-04-30 05:08:01.897302] I [mem-pool.c:541:mem_pool_destroy]
0-management: size=64 max=1 total=1
[2015-04-30 05:08:01.897347] I [glusterd-pmap.c:271:pmap_registry_remove]
0-pmap: removing brick /gfs/data2/s4 on port 49153
[2015-04-30 05:08:01.897522] W [socket.c:514:__socket_rwv] 0-management:
readv failed (No data available)
[2015-04-30 05:08:01.897550] I [mem-pool.c:541:mem_pool_destroy]
0-management: size=2148 max=0 total=0
[2015-04-30 05:08:01.897564] I [mem-pool.c:541:mem_pool_destroy]
0-management: size=64 max=0 total=0
[2015-04-30 05:14:19.908865] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 05:14:19.909368] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 05:14:19.910021] E [glusterd-handshake.c:272:__server_getspec]
0-glusterd: Unable to stat
/var/lib/glusterd/glustershd/glustershd-server.vol (No such file or
directory)
[2015-04-30 05:14:24.923048] I [glusterd-pmap.c:227:pmap_registry_bind]
0-pmap: adding brick /gfs/data2/s5 on port 49154
[2015-04-30 05:14:24.923813] I [rpc-clnt.c:962:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2015-04-30 05:14:24.923904] I [socket.c:3480:socket_init] 0-management:
SSL support is NOT enabled
[2015-04-30 05:14:24.923917] I [socket.c:3495:socket_init] 0-management:
using system polling thread
[2015-04-30 05:14:25.767790] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 05:14:25.777664] I [rpc-clnt.c:962:rpc_clnt_connection_init]
0-management: setting frame-timeout to 600
[2015-04-30 05:14:25.777763] I [socket.c:3480:socket_init] 0-management:
SSL support is NOT enabled
[2015-04-30 05:14:25.777777] I [socket.c:3495:socket_init] 0-management:
using system polling thread
[2015-04-30 05:14:25.778326] I
[glusterd-utils.c:1079:glusterd_volume_brickinfo_get] 0-management: Found
brick
[2015-04-30 05:14:25.778356] I [socket.c:2236:socket_event_handler]
0-transport: disconnecting now
Thanks,
James.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.gluster.org/pipermail/gluster-users/attachments/20150430/e62fc199/attachment.html>
More information about the Gluster-users
mailing list