<html><body><div style="color:#000; background-color:#fff; font-family:HelveticaNeue, Helvetica Neue, Helvetica, Arial, Lucida Grande, Sans-Serif;font-size:12pt"><div><span style="color: rgb(76, 118, 162);">Hi everyone,</span></div><div style="color: rgb(76, 118, 162); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);"><br></span></div><div style="color: rgb(76, 118, 162); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">Here's a strange issue. I am using glusterfs 3.4.0 alpha. We need to move to a stable version ASAP, but I am telling you this just off chance that it might be interesting for somebody from the glusterfs development team. Please excuse the sheer length of
this mail, but I am new to browsing such massive code, and not good at presenting my ideas very clearly.<br></span></div><div><span style="color: rgb(76, 118, 162);"><br></span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">Here's a set of observations:</span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);"><br></span></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">1. You have a replica 2 volume (testvol) on server1 and server2. You assume that on
either server, it is also locally mounted via mount.glusterfs at /testvol.<br>2. You have a large number of soft-linked files within the volume.<br>3. You check heal info (all its facets) to ensure not a single file is out of sync (also, verify md5sum or such, if possible).<br>4. You abrupty take down the ethernet device over which the servers are conencted (ip link set <eth-dev> down).<br>5. On one of the servers (say, server1 for definiteness), if you do an 'ls -l' readlink returns 'Transport endpoint is not connected'.<br>6. The error resolves all by itself if you get the eth-link up.</span><br><span style="color: rgb(76, 118, 162);"><br>Here's some additional detail:<br>7. The error is intermittent, and not all soft-linked files have the issue.<br>8. If you take a directory containing soft-linked files, and if you do a ls -l _on_the_directory, like so,</span><br><br><font size="2"><span style="font-family: Courier
New,courier,monaco,monospace,sans-serif;">server1$ ls -l /testvol/somedir/bin/<br></span></font></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;">ls: cannot read symbolic link /testvol/somedir/bin/reset: Transport endpoint is not connected<br>ls: cannot read symbolic link /testvol/somedir/bin/bzless: Transport endpoint is not connected<br>ls: cannot read symbolic link /testvol/somedir/bin/i386: Transport endpoint is not connected<br>ls: cannot read symbolic link /testvol/somedir/bin/kill: Transport endpoint is not connected<br>ls: cannot read symbolic link /testvol/somedir/bin/linux32: Transport endpoint is not connected<br>ls: cannot read symbolic link /testvol/somedir/bin/linux64: Transport endpoint is not connected<br>ls:
cannot read symbolic link /testvol/somedir/bin/logger: Transport endpoint is not connected<br>ls: cannot read symbolic link /testvol/somedir/bin/x86_64: Transport endpoint is not connected<br>ls: cannot read symbolic link /testvol/somedir/bin/python2: Transport endpoint is not connected<br>connected</span><br></font></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><font size="2"><br></font></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">9. If, however, you take a faulty soft-link and do an ls -l on it directly, then it rights itself immediately.</span><br><br><font size="2"><span style="font-family: Courier
New,courier,monaco,monospace,sans-serif;">server1$ ls -l /testvol/somedir/bin/x86_64<br>lrwxrwxrwx 1 root root 7 May 7 23:11 /testvol/somedir/bin/x86_64 -> setarch</span></font><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">I tried raising the client log level to 'trace'. Here's what I saw:</span><br><span><br><span style="text-decoration: underline;"><span style="font-weight: bold;">Upon READLINK failures, (ls -l /testvol/somedir/bin/)</span></span></span>:<br><br><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;">[2010-05-09
01:13:28.140265] T [fuse-bridge.c:2453:fuse_readdir_cbk] 0-glusterfs-fuse: 2783484: READDIR => 23/4096,1380<br>[2010-05-09 01:13:28.140444] T [fuse-resolve.c:51:fuse_resolve_loc_touchup] 0-fuse: return value inode_path 45<br>[2010-05-09 01:13:28.140477] T [fuse-bridge.c:708:fuse_getattr_resume] 0-glusterfs-fuse: 2783485: GETATTR 140299577689176 (/testvol/somedir/bin)<br>[2010-05-09 01:13:28.140618] T [fuse-bridge.c:641:fuse_attr_cbk] 0-glusterfs-fuse: 2783485: STAT() /testvol/somedir/bin => -5626802993936595428<br><span style="color: rgb(205, 35, 44);"><span style="color: rgb(0, 0, 0);"><span>[2010-05-09 01:13:28.140722] T [fuse-resolve.c:51:fuse_resolve_loc_touchup] 0-fuse: return value inode_path 52</span></span><span style="font-weight: bold;"><br>[2010-05-09 01:13:28.140737] T [fuse-bridge.c:506:fuse_lookup_resume] 0-glusterfs-fuse: 2783486: LOOKUP /testvol/somedir/bin/x86_64(025d1c57-865f-4f1f-bc95-96ddcef3dc03)<br>[2010-05-09
01:13:28.140851] T [fuse-bridge.c:376:fuse_entry_cbk] 0-glusterfs-fuse: 2783486: LOOKUP() /testvol/somedir/bin/x86_64 => -4857810743645185021</span></span><br>[2010-05-09 01:13:28.140954] T [fuse-resolve.c:51:fuse_resolve_loc_touchup] 0-fuse: return value inode_path 52<br>[2010-05-09 01:13:28.140975] T [fuse-bridge.c:1296:fuse_readlink_resume] 0-glusterfs-fuse: 2783487 READLINK /testvol/somedir/bin/x86_64/025d1c57-865f-4f1f-bc95-96ddcef3dc03 <br>[2010-05-09 01:13:28.141090] D [afr-common.c:760:afr_get_call_child] 0-_testvol-replicate-0: Returning -107, call_child: -1, last_index: -1<br>[2010-05-09 01:13:28.141120] W [fuse-bridge.c:1271:fuse_readlink_cbk] 0-glusterfs-fuse: 2783487: /testvol/somedir/bin/x86_64 => -1 (Transport endpoint is not connected)</span></font></div><div style="color: rgb(0, 0, 0); font-size: 16px; background-color: transparent; font-style: normal;"><font size="2"><span style="font-family: Courier
New,courier,monaco,monospace,sans-serif;"><br></span></font></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="text-decoration: underline;"><span style="font-weight: bold;">Upon successful readlink (ls -l /testvol/somedir/bin/x86_64)</span></span>:<br><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;"><br>[2010-05-09 01:13:37.717904] T [fuse-bridge.c:376:fuse_entry_cbk] 0-glusterfs-fuse: 2790073: LOOKUP() /testvol/somedir/bin => -5626802993936595428<br>[2010-05-09 01:13:37.718070] T [fuse-resolve.c:51:fuse_resolve_loc_touchup] 0-fuse: return value inode_path 52<br><span style="color: rgb(91, 136, 40);"><span style="font-weight: bold;"><span>[2010-05-09 01:13:37.718127] T [fuse-bridge.c:506:fuse_lookup_resume] 0-glusterfs-fuse: 2790074: LOOKUP
/testvol/somedir/bin/x86_64(025d1c57-865f-4f1f-bc95-96ddcef3dc03)<br>[2010-05-09 01:13:37.718306] D [afr-common.c:131:afr_lookup_xattr_req_prepare] 0-_testvol-replicate-0: /testvol/somedir/bin/x86_64: failed to get the gfid from dict</span></span></span><br>[2010-05-09 01:13:37.718355] T [rpc-clnt.c:1301:rpc_clnt_record] 0-_testvol-client-1: Auth Info: pid: 3343, uid: 0, gid: 0, owner: 0000000000000000<br>[2010-05-09 01:13:37.718383] T [rpc-clnt.c:1181:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 464, payload: 368, rpc hdr: 96<br>[2010-05-09 01:13:37.718459] T [rpc-clnt.c:1498:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x1527955x Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) to rpc-transport (_testvol-client-1)<br>[2010-05-09 01:13:37.718775] T [rpc-clnt.c:669:rpc_clnt_reply_init] 0-_testvol-client-1: received rpc message (RPC XID: 0x1527955x Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) from rpc-transport
(_testvol-client-1)<br>[2010-05-09 01:13:37.718848] D [afr-self-heal-common.c:138:afr_sh_print_pending_matrix] 0-_testvol-replicate-0: pending_matrix: [ 0 0 ]<br>[2010-05-09 01:13:37.718884] D [afr-self-heal-common.c:138:afr_sh_print_pending_matrix] 0-_testvol-replicate-0: pending_matrix: [ 1 0 ]<br><span style="color: rgb(91, 136, 40);"><span><span style="font-weight: bold;">[2010-05-09 01:13:37.718893] D [afr-self-heal-common.c:887:afr_mark_sources] 0-_testvol-replicate-0: Number of sources: 1<br>[2010-05-09 01:13:37.718903] D [afr-self-heal-data.c:814:afr_lookup_select_read_child_by_txn_type] 0-_testvol-replicate-0: returning read_child: 1</span></span></span><br>[2010-05-09 01:13:37.718916] D [afr-common.c:1397:afr_lookup_select_read_child] 0-_testvol-replicate-0: Source selected as 1 for /testvol/somedir/bin/x86_64<br>[2010-05-09 01:13:37.718927] D [afr-common.c:1134:afr_lookup_build_response_params] 0-_testvol-replicate-0: Building lookup response
from 1<br>[2010-05-09 01:13:37.718954] D [afr-common.c:1749:afr_lookup_perform_self_heal] 0-_testvol-replicate-0: Only 1 child up - do not attempt to detect self heal<br>[2010-05-09 01:13:37.718970] T [io-cache.c:224:ioc_lookup_cbk] 0-_testvol-io-cache: locked inode(0x7f9a057d3fe0)<br>[2010-05-09 01:13:37.718981] T [io-cache.c:233:ioc_lookup_cbk] 0-_testvol-io-cache: unlocked inode(0x7f9a057d3fe0)<br>[2010-05-09 01:13:37.718991] T [io-cache.c:128:ioc_inode_flush] 0-_testvol-io-cache: locked inode(0x7f9a057d3fe0)<br>[2010-05-09 01:13:37.719001] T [io-cache.c:132:ioc_inode_flush] 0-_testvol-io-cache: unlocked inode(0x7f9a057d3fe0)<br>[2010-05-09 01:13:37.719010] T [io-cache.c:242:ioc_lookup_cbk] 0-_testvol-io-cache: locked table(0x668ec0)<br>[2010-05-09 01:13:37.719020] T [io-cache.c:247:ioc_lookup_cbk] 0-_testvol-io-cache: unlocked table(0x668ec0)<br>[2010-05-09 01:13:37.719050] T [fuse-bridge.c:376:fuse_entry_cbk] 0-glusterfs-fuse: 2790074: LOOKUP()
/testvol/somedir/bin/x86_64 => -4857810743645185021<br>[2010-05-09 01:13:37.719239] T [fuse-resolve.c:51:fuse_resolve_loc_touchup] 0-fuse: return value inode_path 52<br>[2010-05-09 01:13:37.719291] T [fuse-bridge.c:1296:fuse_readlink_resume] 0-glusterfs-fuse: 2790075 READLINK /testvol/somedir/bin/x86_64/025d1c57-865f-4f1f-bc95-96ddcef3dc03<br>[2010-05-09 01:13:37.719426] D [afr-common.c:760:afr_get_call_child] 0-_testvol-replicate-0: Returning 0, call_child: 1, last_index: -1<br>[2010-05-09 01:13:37.719468] T [rpc-clnt.c:1301:rpc_clnt_record] 0-_testvol-client-1: Auth Info: pid: 3343, uid: 0, gid: 0, owner: 0000000000000000<br>[2010-05-09 01:13:37.719485] T [rpc-clnt.c:1181:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 120, payload: 24, rpc hdr: 96<br>[2010-05-09 01:13:37.719561] T [rpc-clnt.c:1498:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x1527956x Program: GlusterFS 3.3, ProgVers: 330, Proc: 2) to rpc-transport
(_testvol-client-1)<br>[2010-05-09 01:13:37.719728] T [rpc-clnt.c:669:rpc_clnt_reply_init] 0-_testvol-client-1: received rpc message (RPC XID: 0x1527956x Program: GlusterFS 3.3, ProgVers: 330, Proc: 2) from rpc-transport (_testvol-client-1)<br>[2010-05-09 01:13:37.719780] T [fuse-bridge.c:1265:fuse_readlink_cbk] 0-glusterfs-fuse: 2790075: /testvol/somedir/bin/x86_64 => setarch</span></font><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><br><span style="color: rgb(76, 118, 162);">I cannot quite figure out how the whole thing works, but looks like in the failure case we end up with the wrong set of
read_child(ren). If we first take a look at the fuse_lookup_cbk, which I reproduce here,</span><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;">static int<br>fuse_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this,<br> int32_t op_ret, int32_t op_errno,<br> inode_t *inode, struct iatt *stat, dict_t
*dict,<br> struct iatt *postparent)<br>{<br> fuse_state_t *state = NULL;<br> call_frame_t *prev = NULL;<br> inode_table_t *itable = NULL;<br><br> state = frame->root->state;<br> prev = cookie;<br><br> if (op_ret == -1 && state->is_revalidate == 1) {<br> itable =
state->itable;<br> inode_unref (state->loc.inode);<br> state->loc.inode = inode_new (itable);<br> state->is_revalidate = 2;<br> if (uuid_is_null (state->gfid))<br> uuid_generate (state->gfid);<br> fuse_gfid_set (state);<br><br> STACK_WIND (frame,
fuse_lookup_cbk,<br> prev->this, prev->this->fops->lookup,<br> &state->loc, state->xdata);<br> return 0;<br> }<br><br> fuse_entry_cbk (frame, cookie, this, op_ret, op_errno, inode, stat,<br> dict);<br> return 0;<br>}</span></font><br></div><div style="color: rgb(0,
0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><br></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">then one can see that a resolve failure causing op_ret to be -1 (note, from logs its is_revalidate == 1 for both cases) would cause the mount program to refresh the inode context. In fact, this is where the flow diverges between the success and the failure scenarios. I am inclined to think that at this point a soft-link on which readlink fails (on the mount on server1) has its read-child set as the afr-client on server2. Thus, in theory, a refresh of context would be necessary.</span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida
Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);"><br></span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">Now, if we take a look at the actual failure log:</span></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;">[2010-05-09
01:13:28.141090] D [afr-common.c:760:afr_get_call_child]
0-_testvol-replicate-0: Returning -107, call_child: -1, last_index: -1<br>[2010-05-09
01:13:28.141120] W [fuse-bridge.c:1271:fuse_readlink_cbk]
0-glusterfs-fuse: 2783487: /testvol/somedir/bin/x86_64 => -1
(Transport endpoint is not connected)</span></font></div><div style="color: rgb(0, 0, 0); font-size: 13px; font-family: Courier New,courier,monaco,monospace,sans-serif; background-color: transparent; font-style: normal;"><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;"><br></span></font></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">Here, if we see the below code snippet from afr_get_call_child(), then looks like there might be a problem (or maybe, I am just not reading it right)?</span></div><div style="color: rgb(0, 0, 0); font-size: 16px; background-color: transparent; font-style: normal;"><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;"><br></span></font></div><div style="color: rgb(0, 0, 0); font-size:
13px; font-family: Courier New,courier,monaco,monospace,sans-serif; background-color: transparent; font-style: normal;"><font size="2"><span style="font-family: Courier New,courier,monaco,monospace,sans-serif;"> if (child_up[read_child]) {<br> *call_child = read_child;<br> } else {<br> for (i = 0; i < priv->child_count; i++) {<br> if (fresh_children[i] == -1)<br>
break;<br> if (child_up[fresh_children[i]]) {<br> *call_child = fresh_children[i];<br> ret = 0;<br> break;<br>
}<br> }<br><br> if (*call_child == -1) {<br> ret = -ENOTCONN;<br> goto out;<br> }<br><br> *last_index = i;<br> }<br>out:<br> gf_log (this->name, GF_LOG_DEBUG, "Returning %d, call_child: %d,
"<br> "last_index: %d", ret, *call_child, *last_index);<br> return ret;</span></font><br><br></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">I would suppose 'child_up [read_child]' should equal 0, in which case we would loop over all children. This is where I am confused. If we read a link on server1, and server1 allows me to read so many other files correctly, then surely all subvolumes on server1 MUST be active? But then, we return -ENOTCONN only when it is discovered that not one of the subvolumes is active!<br></span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color:
transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);"><br></span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">It would be great if somebody could confirm my ideas for me. Also, should I need to open a bug for this? <br></span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);"><br></span></div><div style="font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">Thanks a lot for your answers!</span></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family:
HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">Anirban</span></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><br></div><div style="color: rgb(0, 0, 0); font-size: 16px; font-family: HelveticaNeue,Helvetica Neue,Helvetica,Arial,Lucida Grande,Sans-Serif; background-color: transparent; font-style: normal;"><span style="color: rgb(76, 118, 162);">P.s. And yes, umount/mount does resolve the problem as well.</span><br></div></div></body></html>