[Gluster-users] Mount fails first time, then works
Pranith Kumar Karampuri
pkarampu at redhat.com
Thu Feb 5 11:41:15 UTC 2015
On 02/05/2015 05:08 PM, Pranith Kumar Karampuri wrote:
>
> On 01/29/2015 11:52 PM, mark at sidell.org wrote:
>> I've just started having a problem mounting gluster volumes. The first
>> time I try to mount a volume, right after I've launched a server, it
>> fails. But if I try the very same mount command a second time, it
>> works.
>>
>> Below is the gluster log. The failure appears to have to do with
>> getting an EBADF error from /dev/fuse.
>>
>> Any ideas what's going wrong?
>>
>> =========================================================
>>
>>> [2015-01-29 18:04:43.973839] I [glusterfsd.c:2026:main]
>>> 0-/usr/sbin/glusterfs: Started running /usr/sbin/glusterfs version
>>> 3.4.0.59rhs (/usr/sbin/glusterfs --log-level=DEBUG
>>> --volfile-server=files2.forteinc.com --volfile-id=/directra
>>> /media/directra)
>>> [2015-01-29 18:04:43.974025] D
>>> [glusterfsd.c:446:set_fuse_mount_options] 0-: fuse direct io type 2
>>> [2015-01-29 18:04:43.974035] D
>>> [glusterfsd.c:472:set_fuse_mount_options] 0-: fuse direct io type 2
>>> [2015-01-29 18:04:43.974109] D
>>> [options.c:1112:xlator_option_init_double] 0-fuse: option
>>> negative-timeout using set value 0.000000
>>> [2015-01-29 18:04:43.974153] D
>>> [options.c:1109:xlator_option_init_bool] 0-fuse: option
>>> no-root-squash using set value disable
>>> [2015-01-29 18:04:43.975024] D
>>> [rpc-clnt.c:980:rpc_clnt_connection_init] 0-glusterfs: defaulting
>>> frame-timeout to 30mins
>>> [2015-01-29 18:04:43.975056] D
>>> [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to
>>> load file /usr/lib64/glusterfs/3.4.0.59rhs/rpc-transport/socket.so
>>> [2015-01-29 18:04:43.976804] I [socket.c:3505:socket_init]
>>> 0-glusterfs: SSL support is NOT enabled
>>> [2015-01-29 18:04:43.976818] I [socket.c:3520:socket_init]
>>> 0-glusterfs: using system polling thread
>>> [2015-01-29 18:04:43.976831] D
>>> [rpc-clnt.c:1388:rpcclnt_cbk_program_register] 0-glusterfs: New
>>> program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>>> [2015-01-29 18:04:43.983866] D [common-utils.c:248:gf_resolve_ip6]
>>> 0-resolver: returning ip-10.0.11.30 (port-24007) for hostname:
>>> files2.forteinc.com and port: 24007
>>> [2015-01-29 18:04:43.990392] D [io-stats.c:2627:init] 0-directra:
>>> dangling volume. check volfile
>>> [2015-01-29 18:04:43.990411] D
>>> [options.c:1109:xlator_option_init_bool] 0-directra: option
>>> count-fop-hits using set value off
>>> [2015-01-29 18:04:43.990418] D
>>> [options.c:1109:xlator_option_init_bool] 0-directra: option
>>> latency-measurement using set value off
>>> [2015-01-29 18:04:43.990512] D
>>> [quick-read.c:822:check_cache_size_ok] 0-directra-quick-read: Max
>>> cache size is 1041051648
>>> [2015-01-29 18:04:43.990553] D [io-cache.c:1564:check_cache_size_ok]
>>> 0-directra-io-cache: Max cache size is 1041051648
>>> [2015-01-29 18:04:43.991683] D [afr.c:492:init]
>>> 0-directra-replicate-0: Returning 0
>>> [2015-01-29 18:04:43.991701] D
>>> [client.c:2348:client_init_grace_timer] 0-directra-client-1: lk-heal
>>> = off
>>> [2015-01-29 18:04:43.991706] D
>>> [client.c:2359:client_init_grace_timer] 0-directra-client-1: Client
>>> grace timeout value = 10
>>> [2015-01-29 18:04:43.991716] D
>>> [options.c:1111:xlator_option_init_path] 0-directra-client-1: option
>>> remote-subvolume using set value /media/brick2
>>> [2015-01-29 18:04:43.992186] D
>>> [rpc-clnt.c:980:rpc_clnt_connection_init] 0-directra-client-1:
>>> defaulting frame-timeout to 30mins
>>> [2015-01-29 18:04:43.992202] D
>>> [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to
>>> load file /usr/lib64/glusterfs/3.4.0.59rhs/rpc-transport/socket.so
>>> [2015-01-29 18:04:43.992217] I [socket.c:3505:socket_init]
>>> 0-directra-client-1: SSL support is NOT enabled
>>> [2015-01-29 18:04:43.992222] I [socket.c:3520:socket_init]
>>> 0-directra-client-1: using system polling thread
>>> [2015-01-29 18:04:43.992228] D
>>> [rpc-clnt.c:1388:rpcclnt_cbk_program_register] 0-directra-client-1:
>>> New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>>> [2015-01-29 18:04:43.992233] D [client.c:2323:client_init_rpc]
>>> 0-directra-client-1: client init successful
>>> [2015-01-29 18:04:43.992238] D
>>> [client.c:2348:client_init_grace_timer] 0-directra-client-0: lk-heal
>>> = off
>>> [2015-01-29 18:04:43.992242] D
>>> [client.c:2359:client_init_grace_timer] 0-directra-client-0: Client
>>> grace timeout value = 10
>>> [2015-01-29 18:04:43.992291] D
>>> [options.c:1111:xlator_option_init_path] 0-directra-client-0: option
>>> remote-subvolume using set value /media/brick1
>>> [2015-01-29 18:04:43.992777] D
>>> [rpc-clnt.c:980:rpc_clnt_connection_init] 0-directra-client-0:
>>> defaulting frame-timeout to 30mins
>>> [2015-01-29 18:04:43.992791] D
>>> [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to
>>> load file /usr/lib64/glusterfs/3.4.0.59rhs/rpc-transport/socket.so
>>> [2015-01-29 18:04:43.992809] I [socket.c:3505:socket_init]
>>> 0-directra-client-0: SSL support is NOT enabled
>>> [2015-01-29 18:04:43.992822] I [socket.c:3520:socket_init]
>>> 0-directra-client-0: using system polling thread
>>> [2015-01-29 18:04:43.992828] D
>>> [rpc-clnt.c:1388:rpcclnt_cbk_program_register] 0-directra-client-0:
>>> New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>>> [2015-01-29 18:04:43.992834] D [client.c:2323:client_init_rpc]
>>> 0-directra-client-0: client init successful
>>> [2015-01-29 18:04:43.992845] D [fuse-bridge.c:5892:notify] 0-fuse:
>>> got event 12 on graph 0
>>> [2015-01-29 18:04:43.992855] I [client.c:2171:notify]
>>> 0-directra-client-0: parent translators are ready, attempting
>>> connect on transport
>>> [2015-01-29 18:04:43.992861] D
>>> [name.c:155:client_fill_address_family] 0-directra-client-0:
>>> address-family not specified, guessing it to be inet from
>>> (remote-host: files1.forteinc.com)
>>> [2015-01-29 18:04:43.998137] D [common-utils.c:248:gf_resolve_ip6]
>>> 0-resolver: returning ip-10.0.10.29 (port-24007) for hostname:
>>> files1.forteinc.com and port: 24007
>>> [2015-01-29 18:04:43.998217] I [client.c:2171:notify]
>>> 0-directra-client-1: parent translators are ready, attempting
>>> connect on transport
>>> [2015-01-29 18:04:43.998228] D
>>> [name.c:155:client_fill_address_family] 0-directra-client-1:
>>> address-family not specified, guessing it to be inet from
>>> (remote-host: files2.forteinc.com)
>>> [2015-01-29 18:04:44.001046] D [common-utils.c:248:gf_resolve_ip6]
>>> 0-resolver: returning ip-10.0.11.30 (port-24007) for hostname:
>>> files2.forteinc.com and port: 24007
>>> Final graph:
>>> +------------------------------------------------------------------------------+
>>>
>>> 1: volume directra-client-0
>>> 2: type protocol/client
>>> 3: option transport-type socket
>>> 4: option remote-subvolume /media/brick1
>>> 5: option remote-host files1.forteinc.com
>>> 6: end-volume
>>> 7:
>>> 8: volume directra-client-1
>>> 9: type protocol/client
>>> 10: option transport-type socket
>>> 11: option remote-subvolume /media/brick2
>>> 12: option remote-host files2.forteinc.com
>>> 13: end-volume
>>> 14:
>>> 15: volume directra-replicate-0
>>> 16: type cluster/replicate
>>> 17: subvolumes directra-client-0 directra-client-1
>>> 18: end-volume
>>> 19:
>>> 20: volume directra-write-behind
>>> 21: type performance/write-behind
>>> 22: subvolumes directra-replicate-0
>>> 23: end-volume
>>> 24:
>>> 25: volume directra-read-ahead
>>> 26: type performance/read-ahead
>>> 27: subvolumes directra-write-behind
>>> 28: end-volume
>>> 29:
>>> 30: volume directra-io-cache
>>> 31: type performance/io-cache
>>> 32: subvolumes directra-read-ahead
>>> 33: end-volume
>>> 34:
>>> 35: volume directra-quick-read
>>> 36: type performance/quick-read
>>> 37: subvolumes directra-io-cache
>>> 38: end-volume
>>> 39:
>>> 40: volume directra-md-cache
>>> 41: type performance/md-cache
>>> 42: subvolumes directra-quick-read
>>> 43: end-volume
>>> 44:
>>> 45: volume directra
>>> 46: type debug/io-stats
>>> 47: option count-fop-hits off
>>> 48: option latency-measurement off
>>> 49: subvolumes directra-md-cache
>>> 50: end-volume
>>> 51:
>>> +------------------------------------------------------------------------------+
>>>
>>> [2015-01-29 18:04:44.001186] D
>>> [glusterfsd-mgmt.c:2031:glusterfs_mgmt_pmap_signin] 0-fsd-mgmt:
>>> portmapper signin arguments not given
>>> [2015-01-29 18:04:44.001245] D [client.c:2050:client_rpc_notify]
>>> 0-directra-client-0: got RPC_CLNT_CONNECT
>>> [2015-01-29 18:04:44.001286] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-0:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.001940] D [client.c:2050:client_rpc_notify]
>>> 0-directra-client-1: got RPC_CLNT_CONNECT
>>> [2015-01-29 18:04:44.001976] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-1:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.003037] D
>>> [client-handshake.c:1729:server_has_portmap] 0-directra-client-0:
>>> detected portmapper on server
>>> [2015-01-29 18:04:44.003099] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-0:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.003128] D
>>> [client-handshake.c:1729:server_has_portmap] 0-directra-client-1:
>>> detected portmapper on server
>>> [2015-01-29 18:04:44.003162] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-1:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.003672] I [rpc-clnt.c:1690:rpc_clnt_reconfig]
>>> 0-directra-client-1: changing port to 24009 (from 0)
>>> [2015-01-29 18:04:44.003700] D [socket.c:492:__socket_rwv]
>>> 0-directra-client-1: EOF on socket
>>> [2015-01-29 18:04:44.003707] D [socket.c:2235:socket_event_handler]
>>> 0-transport: disconnecting now
>>> [2015-01-29 18:04:44.003775] D [client.c:2126:client_rpc_notify]
>>> 0-directra-client-1: disconnected (skipped notify)
>>> [2015-01-29 18:04:44.003783] D
>>> [name.c:155:client_fill_address_family] 0-directra-client-1:
>>> address-family not specified, guessing it to be inet from
>>> (remote-host: files2.forteinc.com)
>>> [2015-01-29 18:04:44.006690] D [common-utils.c:248:gf_resolve_ip6]
>>> 0-resolver: returning ip-10.0.11.30 (port-24007) for hostname:
>>> files2.forteinc.com and port: 24007
>>> [2015-01-29 18:04:44.006799] I [rpc-clnt.c:1690:rpc_clnt_reconfig]
>>> 0-directra-client-0: changing port to 24009 (from 0)
>>> [2015-01-29 18:04:44.006829] D [socket.c:492:__socket_rwv]
>>> 0-directra-client-0: EOF on socket
>>> [2015-01-29 18:04:44.006837] D [socket.c:2235:socket_event_handler]
>>> 0-transport: disconnecting now
>>> [2015-01-29 18:04:44.006848] D [client.c:2126:client_rpc_notify]
>>> 0-directra-client-0: disconnected (skipped notify)
>>> [2015-01-29 18:04:44.006854] D
>>> [name.c:155:client_fill_address_family] 0-directra-client-0:
>>> address-family not specified, guessing it to be inet from
>>> (remote-host: files1.forteinc.com)
>>> [2015-01-29 18:04:44.009756] D [common-utils.c:248:gf_resolve_ip6]
>>> 0-resolver: returning ip-10.0.10.29 (port-24007) for hostname:
>>> files1.forteinc.com and port: 24007
>>> [2015-01-29 18:04:44.009852] D [client.c:2050:client_rpc_notify]
>>> 0-directra-client-1: got RPC_CLNT_CONNECT
>>> [2015-01-29 18:04:44.009893] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-1:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.010364] I
>>> [client-handshake.c:1695:select_server_supported_programs]
>>> 0-directra-client-1: Using Program GlusterFS 3.3.1, Num (1298437),
>>> Version (330)
>>> [2015-01-29 18:04:44.010410] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-1:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.010784] D [client.c:2050:client_rpc_notify]
>>> 0-directra-client-0: got RPC_CLNT_CONNECT
>>> [2015-01-29 18:04:44.010814] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-0:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.010943] D
>>> [client-handshake.c:1437:client_setvolume_cbk] 0-directra-client-1:
>>> clnt-lk-version = 1, server-lk-version = 0
>>> [2015-01-29 18:04:44.010953] I
>>> [client-handshake.c:1480:client_setvolume_cbk] 0-directra-client-1:
>>> Connected to 10.0.11.30:24009, attached to remote volume
>>> '/media/brick2'.
>>> [2015-01-29 18:04:44.010958] I
>>> [client-handshake.c:1492:client_setvolume_cbk] 0-directra-client-1:
>>> Server and Client lk-version numbers are not same, reopening the fds
>>> [2015-01-29 18:04:44.010963] D
>>> [client-handshake.c:1324:client_post_handshake] 0-directra-client-1:
>>> No fds to open - notifying all parents child up
>>> [2015-01-29 18:04:44.010970] D
>>> [client-handshake.c:492:client_set_lk_version] 0-directra-client-1:
>>> Sending SET_LK_VERSION
>>> [2015-01-29 18:04:44.011019] I [afr-common.c:3988:afr_notify]
>>> 0-directra-replicate-0: Subvolume 'directra-client-1' came back up;
>>> going online.
>>> [2015-01-29 18:04:44.011409] I
>>> [client-handshake.c:450:client_set_lk_version_cbk]
>>> 0-directra-client-1: Server lk version = 1
>>> [2015-01-29 18:04:44.011762] I
>>> [client-handshake.c:1695:select_server_supported_programs]
>>> 0-directra-client-0: Using Program GlusterFS 3.3.1, Num (1298437),
>>> Version (330)
>>> [2015-01-29 18:04:44.011802] D
>>> [client-handshake.c:185:client_start_ping] 0-directra-client-0:
>>> returning as transport is already disconnected OR there are no
>>> frames (1 || 1)
>>> [2015-01-29 18:04:44.012843] D
>>> [client-handshake.c:1437:client_setvolume_cbk] 0-directra-client-0:
>>> clnt-lk-version = 1, server-lk-version = 0
>>> [2015-01-29 18:04:44.012856] I
>>> [client-handshake.c:1480:client_setvolume_cbk] 0-directra-client-0:
>>> Connected to 10.0.10.29:24009, attached to remote volume
>>> '/media/brick1'.
>>> [2015-01-29 18:04:44.012861] I
>>> [client-handshake.c:1492:client_setvolume_cbk] 0-directra-client-0:
>>> Server and Client lk-version numbers are not same, reopening the fds
>>> [2015-01-29 18:04:44.012866] D
>>> [client-handshake.c:1324:client_post_handshake] 0-directra-client-0:
>>> No fds to open - notifying all parents child up
>>> [2015-01-29 18:04:44.012871] D
>>> [client-handshake.c:492:client_set_lk_version] 0-directra-client-0:
>>> Sending SET_LK_VERSION
>>> [2015-01-29 18:04:44.012912] D [fuse-bridge.c:5892:notify] 0-fuse:
>>> got event 5 on graph 0
>>> [2015-01-29 18:04:44.016042] I [fuse-bridge.c:5874:fuse_graph_setup]
>>> 0-fuse: switched to graph 0
>>> [2015-01-29 18:04:44.016497] I
>>> [client-handshake.c:450:client_set_lk_version_cbk]
>>> 0-directra-client-0: Server lk version = 1
>>> [2015-01-29 18:04:44.016564] D
>>> [fuse-bridge.c:5500:fuse_get_mount_status] 0-fuse: mount status is 0
>>> [2015-01-29 18:04:44.016615] I [fuse-bridge.c:4811:fuse_init]
>>> 0-glusterfs-fuse: FUSE inited with protocol versions: glusterfs 7.13
>>> kernel 7.22
>>> [2015-01-29 18:04:44.017348] D
>>> [afr-common.c:2300:afr_set_root_inode_on_first_lookup]
>>> 0-directra-replicate-0: added root inode
>>> [2015-01-29 18:04:44.017789] D
>>> [afr-self-heal-common.c:160:afr_sh_print_pending_matrix]
>>> 0-directra-replicate-0: pending_matrix: [ 0 0 ]
>>> [2015-01-29 18:04:44.017799] D
>>> [afr-self-heal-common.c:160:afr_sh_print_pending_matrix]
>>> 0-directra-replicate-0: pending_matrix: [ 0 0 ]
>>> [2015-01-29 18:04:44.017806] D
>>> [afr-self-heal-common.c:1069:afr_mark_sources]
>>> 0-directra-replicate-0: Number of sources: 0
>>> [2015-01-29 18:04:44.017812] D
>>> [afr-self-heal-data.c:1127:afr_lookup_select_read_child_by_txn_type]
>>> 0-directra-replicate-0: returning read_child: 1
>>> [2015-01-29 18:04:44.017817] D
>>> [afr-common.c:1549:afr_lookup_select_read_child]
>>> 0-directra-replicate-0: Source selected as 1 for /
>>> [2015-01-29 18:04:44.017825] D
>>> [afr-common.c:1211:afr_lookup_build_response_params]
>>> 0-directra-replicate-0: Building lookup response from 1
>>> [2015-01-29 18:04:44.019685] D
>>> [afr-self-heal-common.c:160:afr_sh_print_pending_matrix]
>>> 0-directra-replicate-0: pending_matrix: [ 0 0 ]
>>> [2015-01-29 18:04:44.019699] D
>>> [afr-self-heal-common.c:160:afr_sh_print_pending_matrix]
>>> 0-directra-replicate-0: pending_matrix: [ 0 0 ]
>>> [2015-01-29 18:04:44.019705] D
>>> [afr-self-heal-common.c:1069:afr_mark_sources]
>>> 0-directra-replicate-0: Number of sources: 0
>>> [2015-01-29 18:04:44.019710] D
>>> [afr-self-heal-data.c:1127:afr_lookup_select_read_child_by_txn_type]
>>> 0-directra-replicate-0: returning read_child: 1
>>> [2015-01-29 18:04:44.019715] D
>>> [afr-common.c:1549:afr_lookup_select_read_child]
>>> 0-directra-replicate-0: Source selected as 1 for /
>>> [2015-01-29 18:04:44.019721] D
>>> [afr-common.c:1211:afr_lookup_build_response_params]
>>> 0-directra-replicate-0: Building lookup response from 1
>>> [2015-01-29 18:04:46.371314] W [glusterfsd.c:1099:cleanup_and_exit]
>>> (-->/lib64/libc.so.6(clone+0x6d) [0x7f37dbe2d1ad]
>>> (-->/lib64/libpthread.so.0(+0x7df3) [0x7f37dc4e4df3]
>>> (-->/usr/sbin/glusterfs(glusterfs_sigwaiter+0xe5)
>>> [0x7f37dd1e0255]))) 0-: received signum (15), shutting down
>>> [2015-01-29 18:04:46.371334] D
>>> [glusterfsd-mgmt.c:2093:glusterfs_mgmt_pmap_signout] 0-fsd-mgmt:
>>> portmapper signout arguments not given
>>> [2015-01-29 18:04:46.371360] I [fuse-bridge.c:6412:fini] 0-fuse:
>>> Unmounting '/media/directra'.
>>> [2015-01-29 18:04:46.371786] D [fuse-bridge.c:5611:fuse_thread_proc]
>>> 0-glusterfs-fuse: terminating upon getting EBADF when reading /dev/fuse
>>> [2015-01-29 18:04:46.371801] I [fuse-bridge.c:5715:fuse_thread_proc]
>>> 0-fuse: unmounting /media/directra
> what is happening if you do the following: glusterfs
> --volfile-server=<hostname> --volfile-id=<volname> <mount>, instead of
> 'mount -t glusterfs ..'
If it still fails, 'strace -f' output of the command above would be helpful.
Pranith
>
> Pranith
>> _______________________________________________
>> Gluster-users mailing list
>> Gluster-users at gluster.org
>> http://www.gluster.org/mailman/listinfo/gluster-users
>
> _______________________________________________
> Gluster-users mailing list
> Gluster-users at gluster.org
> http://www.gluster.org/mailman/listinfo/gluster-users
More information about the Gluster-users
mailing list