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@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@node01:~$ sudo mkdir /gfs/mnt/s5
jams@node01:~$ sudo mount -t glusterfs node01:/s5 /gfs/mnt/s5
jams@node01:~$ mount | grep s5
node01:/s5 on /gfs/mnt/s5 type fuse.glusterfs (rw,default_permissions,allow_other,max_read=131072)
jams@node01:~$ cd /gfs/mnt/s5
jams@node01:/gfs/mnt/s5$ ls
jams@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@node01:/gfs/mnt/s5$ ls -l
ls: reading directory .: Input/output error
total 0
jams@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@node01:/gfs/mnt/s5$ sudo rm z
jams@node01:/gfs/mnt/s5$ ls
ls: reading directory .: Input/output error
jams@node01:/gfs/mnt/s5$ sudo rm y
jams@node01:/gfs/mnt/s5$ ls
ls: reading directory .: Input/output error
jams@node01:/gfs/mnt/s5$ sudo rm x
jams@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@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.
_______________________________________________ Gluster-users mailing list Gluster-users@xxxxxxxxxxx http://www.gluster.org/mailman/listinfo/gluster-users
