Erik Jacobson
2020-Mar-31 06:50 UTC
[Gluster-users] gnfs split brain when 1 server in 3x1 down (high load) - help request
I note that this part of afr_read_txn() gets triggered a lot.
if (afr_is_inode_refresh_reqd(inode, this, local->event_generation,
event_generation)) {
Maybe that's normal when one of the three servers are down (but why
isn't it using its local copy by default?)
The comment in that if block is:
/* servers have disconnected / reconnected, and possibly
rebooted, very likely changing the state of freshness
of copies */
But we have one server conssitently down, not a changing situation.
digging digging digging seemed to show this related to cache
invalidation.... Because the paths seemed to suggest the inode needed
refreshing and that seems handled by a case statement named
GF_UPCALL_CACHE_INVALIDATION
However, that must have been a wrong turn since turning off
cache invalidation didn't help.
I'm struggling to wrap my head around the code base and without the
background in these concepts it's a tough hill to climb.
I am going to have to try this again some day with fresh eyes and go to
bed; the machine I have easy access to is going away in the morning.
Now I'll have to reserve time on a contended one but I will do that and
continue digging.
Any suggestions would be greatly appreciated as I think I'm starting to
tip over here on this one.
On Mon, Mar 30, 2020 at 04:04:39PM -0500, Erik Jacobson
wrote:> > Sadly I am not a developer, so I can't answer your questions.
>
> I'm not a FS o rnetwork developer either. I think there is a joke about
> playing one on TV but maybe it's netflix now.
>
> Enabling certain debug options made too much information for me to watch
> personally (but an expert could probably get through it).
>
> So I started putting targeted 'print' (gf_msg) statements in the
code to
> see how it got its way to split-brain. Maybe this will ring a bell
> for someone.
>
> I can tell the only way we enter the split-brain path is through in the
> first if statement of afr_read_txn_refresh_done().
>
> This means afr_read_txn_refresh_done() itself was passed "err"
and
> that it appears thin_arbiter_count was not set (which makes sense,
> I'm using 1x3, not a thin arbiter).
>
> So we jump to the readfn label, and read_subvol() should still be -1.
> If I read right, it must mean that this if didn't return true because
> my print statement didn't appear:
> if ((ret == 0) && spb_choice >= 0) {
>
> So we're still with the original read_subvol == 1,
> Which gets us to the split_brain message.
>
> So now I will try to learn why afr_read_txn_refresh_done() would have
> 'err' set in the first place. I will also learn about
> afr_inode_split_brain_choice_get(). Those seem to be the two methods to
> have avoided falling in to the split brain hole here.
>
>
> I put debug statements in these locations. I will mark with !!!!!! what
> I see:
>
>
>
> diff -Narup glusterfs-7.2-orig/xlators/cluster/afr/src/afr-read-txn.c
glusterfs-7.2-new/xlators/cluster/afr/src/afr-read-txn.c
> --- glusterfs-7.2-orig/xlators/cluster/afr/src/afr-read-txn.c 2020-01-15
11:43:53.887894293 -0600
> +++ glusterfs-7.2-new/xlators/cluster/afr/src/afr-read-txn.c 2020-03-30
15:45:02.917104321 -0500
> @@ -279,10 +279,14 @@ afr_read_txn_refresh_done(call_frame_t *
> priv = this->private;
>
> if (err) {
> - if (!priv->thin_arbiter_count)
> + if (!priv->thin_arbiter_count) {
> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg crapola
1st if in afr_read_txn_refresh_done() !priv->thin_arbiter_count -- goto to
readfn");
> !!!!!!!!!!!!!!!!!!!!!!
> We hit this error condition and jump to readfn below
> !!!!!!!!!!!!!!!!!!!!!!!
> goto readfn;
> - if (err != EINVAL)
> + }
> + if (err != EINVAL) {
> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj 2nd if in
afr_read_txn_refresh_done() err != EINVAL, goto readfn");
> goto readfn;
> + }
> /* We need to query the good bricks and/or thin-arbiter.*/
> afr_ta_read_txn_synctask(frame, this);
> return 0;
> @@ -291,6 +295,8 @@ afr_read_txn_refresh_done(call_frame_t *
> read_subvol = afr_read_subvol_select_by_policy(inode, this,
local->readable,
> NULL);
> if (read_subvol == -1) {
> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg whoops
read_subvol returned -1, going to readfn");
> +
> err = EIO;
> goto readfn;
> }
> @@ -304,11 +310,15 @@ afr_read_txn_refresh_done(call_frame_t *
> readfn:
> if (read_subvol == -1) {
> ret = afr_inode_split_brain_choice_get(inode, this,
&spb_choice);
> - if ((ret == 0) && spb_choice >= 0)
> + if ((ret == 0) && spb_choice >= 0) {
> !!!!!!!!!!!!!!!!!!!!!!
> We never get here, afr_inode_split_brain_choice_get() must not have
> returned what was needed to enter.
> !!!!!!!!!!!!!!!!!!!!!!
> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg
read_subvol was -1 to begin with split brain choice found: %d",
spb_choice);
> read_subvol = spb_choice;
> + }
> }
>
> if (read_subvol == -1) {
> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg verify this
shows up above split-brain error");
> !!!!!!!!!!!!!!!!!!!!!!
> We hit here. Game over player.
> !!!!!!!!!!!!!!!!!!!!!!
> +
> AFR_SET_ERROR_AND_CHECK_SPLIT_BRAIN(-1, err);
> }
> afr_read_txn_wind(frame, this, read_subvol);
Ravishankar N
2020-Mar-31 09:57 UTC
[Gluster-users] gnfs split brain when 1 server in 3x1 down (high load) - help request
From your reply in the other thread, I'm assuming that the file/gfid in question is not in genuine split-brain or needing heal. i.e. for example with that 1 brick down and 2 bricks up test case, if you tried to read the file from say a temporary fuse mount (which is also now connected to only to 2 bricks since the 3rd one is down) it works fine and there is no EIO error... ...which means that what you have observed is true, i.e. afr_read_txn_refresh_done() is called with err=EIO. You can add logs to see at what point it is EIO set. The call graph is like this: afr_inode_refresh_done()-->afr_txn_refresh_done()-->afr_read_txn_refresh_done(). Maybe https://github.com/gluster/glusterfs/blob/v7.4/xlators/cluster/afr/src/afr-common.c#L1188 in afr_txn_refresh_done() is causing it either due to ret being -EIO or event_generation being zero. If you are comfortable with gdb, you an put a conditional break point in afr_read_txn_refresh_done() at https://github.com/gluster/glusterfs/blob/v7.4/xlators/cluster/afr/src/afr-read-txn.c#L283 when err=EIO and then check the backtrace for who is setting err to EIO. Regards, Ravi On 31/03/20 12:20 pm, Erik Jacobson wrote:> I note that this part of afr_read_txn() gets triggered a lot. > > if (afr_is_inode_refresh_reqd(inode, this, local->event_generation, > event_generation)) { > > Maybe that's normal when one of the three servers are down (but why > isn't it using its local copy by default?) > > The comment in that if block is: > /* servers have disconnected / reconnected, and possibly > rebooted, very likely changing the state of freshness > of copies */ > > But we have one server conssitently down, not a changing situation. > > digging digging digging seemed to show this related to cache > invalidation.... Because the paths seemed to suggest the inode needed > refreshing and that seems handled by a case statement named > GF_UPCALL_CACHE_INVALIDATION > > However, that must have been a wrong turn since turning off > cache invalidation didn't help. > > I'm struggling to wrap my head around the code base and without the > background in these concepts it's a tough hill to climb. > > I am going to have to try this again some day with fresh eyes and go to > bed; the machine I have easy access to is going away in the morning. > Now I'll have to reserve time on a contended one but I will do that and > continue digging. > > Any suggestions would be greatly appreciated as I think I'm starting to > tip over here on this one. > > > On Mon, Mar 30, 2020 at 04:04:39PM -0500, Erik Jacobson wrote: >>> Sadly I am not a developer, so I can't answer your questions. >> I'm not a FS o rnetwork developer either. I think there is a joke about >> playing one on TV but maybe it's netflix now. >> >> Enabling certain debug options made too much information for me to watch >> personally (but an expert could probably get through it). >> >> So I started putting targeted 'print' (gf_msg) statements in the code to >> see how it got its way to split-brain. Maybe this will ring a bell >> for someone. >> >> I can tell the only way we enter the split-brain path is through in the >> first if statement of afr_read_txn_refresh_done(). >> >> This means afr_read_txn_refresh_done() itself was passed "err" and >> that it appears thin_arbiter_count was not set (which makes sense, >> I'm using 1x3, not a thin arbiter). >> >> So we jump to the readfn label, and read_subvol() should still be -1. >> If I read right, it must mean that this if didn't return true because >> my print statement didn't appear: >> if ((ret == 0) && spb_choice >= 0) { >> >> So we're still with the original read_subvol == 1, >> Which gets us to the split_brain message. >> >> So now I will try to learn why afr_read_txn_refresh_done() would have >> 'err' set in the first place. I will also learn about >> afr_inode_split_brain_choice_get(). Those seem to be the two methods to >> have avoided falling in to the split brain hole here. >> >> >> I put debug statements in these locations. I will mark with !!!!!! what >> I see: >> >> >> >> diff -Narup glusterfs-7.2-orig/xlators/cluster/afr/src/afr-read-txn.c glusterfs-7.2-new/xlators/cluster/afr/src/afr-read-txn.c >> --- glusterfs-7.2-orig/xlators/cluster/afr/src/afr-read-txn.c 2020-01-15 11:43:53.887894293 -0600 >> +++ glusterfs-7.2-new/xlators/cluster/afr/src/afr-read-txn.c 2020-03-30 15:45:02.917104321 -0500 >> @@ -279,10 +279,14 @@ afr_read_txn_refresh_done(call_frame_t * >> priv = this->private; >> >> if (err) { >> - if (!priv->thin_arbiter_count) >> + if (!priv->thin_arbiter_count) { >> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg crapola 1st if in afr_read_txn_refresh_done() !priv->thin_arbiter_count -- goto to readfn"); >> !!!!!!!!!!!!!!!!!!!!!! >> We hit this error condition and jump to readfn below >> !!!!!!!!!!!!!!!!!!!!!!! >> goto readfn; >> - if (err != EINVAL) >> + } >> + if (err != EINVAL) { >> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj 2nd if in afr_read_txn_refresh_done() err != EINVAL, goto readfn"); >> goto readfn; >> + } >> /* We need to query the good bricks and/or thin-arbiter.*/ >> afr_ta_read_txn_synctask(frame, this); >> return 0; >> @@ -291,6 +295,8 @@ afr_read_txn_refresh_done(call_frame_t * >> read_subvol = afr_read_subvol_select_by_policy(inode, this, local->readable, >> NULL); >> if (read_subvol == -1) { >> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg whoops read_subvol returned -1, going to readfn"); >> + >> err = EIO; >> goto readfn; >> } >> @@ -304,11 +310,15 @@ afr_read_txn_refresh_done(call_frame_t * >> readfn: >> if (read_subvol == -1) { >> ret = afr_inode_split_brain_choice_get(inode, this, &spb_choice); >> - if ((ret == 0) && spb_choice >= 0) >> + if ((ret == 0) && spb_choice >= 0) { >> !!!!!!!!!!!!!!!!!!!!!! >> We never get here, afr_inode_split_brain_choice_get() must not have >> returned what was needed to enter. >> !!!!!!!!!!!!!!!!!!!!!! >> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg read_subvol was -1 to begin with split brain choice found: %d", spb_choice); >> read_subvol = spb_choice; >> + } >> } >> >> if (read_subvol == -1) { >> + gf_msg(this->name, GF_LOG_ERROR,0,0,"erikj dbg verify this shows up above split-brain error"); >> !!!!!!!!!!!!!!!!!!!!!! >> We hit here. Game over player. >> !!!!!!!!!!!!!!!!!!!!!! >> + >> AFR_SET_ERROR_AND_CHECK_SPLIT_BRAIN(-1, err); >> } >> afr_read_txn_wind(frame, this, read_subvol); > > ________ > > > > Community Meeting Calendar: > > Schedule - > Every 2nd and 4th Tuesday at 14:30 IST / 09:00 UTC > Bridge: https://bluejeans.com/441850968 > > Gluster-users mailing list > Gluster-users at gluster.org > https://lists.gluster.org/mailman/listinfo/gluster-users >
Erik Jacobson
2020-Apr-01 03:27 UTC
[Gluster-users] gnfs split brain when 1 server in 3x1 down (high load) - help request
THANK YOU for the hints. Very happy to have the help. I'll reply to a couple things then dig in: On Tue, Mar 31, 2020 at 03:27:59PM +0530, Ravishankar N wrote:> From your reply in the other thread, I'm assuming that the file/gfid in > question is not in genuine split-brain or needing heal. i.e. for exampleRight, they were not tagged split-brain either, just healing needed, which is expected for those 76 files.> with that 1 brick down and 2 bricks up test case, if you tried to read the > file from say a temporary fuse mount (which is also now connected to only to > 2 bricks since the 3rd one is down) it works fine and there is no EIO > error...Looking at the heal info, all files are the files I expected to have write changes and I think* are outside the scope of this issue. To close the loop, I ran a 'strings' on the top of one the files to confirm from a fuse mount and had no trouble.> ...which means that what you have observed is true, i.e. > afr_read_txn_refresh_done() is called with err=EIO. You can add logs to see > at what point it is EIO set. The call graph is like this: afr_inode_refresh_done()-->afr_txn_refresh_done()-->afr_read_txn_refresh_done(). > > Maybe https://github.com/gluster/glusterfs/blob/v7.4/xlators/cluster/afr/src/afr-common.c#L1188 > in afr_txn_refresh_done() is causing it either due to ret being -EIO or > event_generation being zero. > > If you are comfortable with gdb, you an put a conditional break point in > afr_read_txn_refresh_done() at https://github.com/gluster/glusterfs/blob/v7.4/xlators/cluster/afr/src/afr-read-txn.c#L283 > when err=EIO and then check the backtrace for who is setting err to EIO.Ok so the main event! :) I'm not a gdb expert but I think I figured it out well enough to paste some back traces. However, I'm having trouble intepreting them exactly. It looks to me to be the "event" case. (I got permission to use this MFG system at night for a couple more nights; avoiding the 24-hour-reserved internal larger system we have). here is what I did, feel free to suggest something better. - I am using an RPM build so I changed the spec file to create debuginfo packages. I'm on rhel8.1 - I installed the updated packages and debuginfo packages - When glusterd started the nfs glusterfs, I killed it. - I ran this: gdb -d /root/rpmbuild/BUILD/glusterfs-7.2 -d /root/rpmbuild/BUILD/glusterfs-7.2/xlators/cluster/afr/src/ /usr/sbin/glusterfs - Then from GDB, I ran this: (gdb) run -s localhost --volfile-id gluster/nfs -p /var/run/gluster/nfs/nfs.pid -l /var/log/glusterfs/nfs.log -S /var/run/gluster/9ddb5561058ff543.socket -N - I hit ctrl-c, then set the break point: (gdb) break xlators/cluster/afr/src/afr-read-txn.c:280 if err == 5 - I have some debugging statements but gluster 72 line 280 is this: --> line 280 (I think gdb changed it to 281 internally) if (err) { if (!priv->thin_arbiter_count) { - continue - Then I ran the test case. Here are some back traces. They make my head hurt. Maybe you can suggest something else to try next? In the morning I'll try to unwind this myself too in the source code but I suspect it will be tough for me. (gdb) break xlators/cluster/afr/src/afr-read-txn.c:280 if err == 5 Breakpoint 1 at 0x7fff688e057b: file afr-read-txn.c, line 281. (gdb) continue Continuing. [Switching to Thread 0x7ffecffff700 (LWP 50175)] Thread 15 "glfs_epoll007" hit Breakpoint 1, afr_read_txn_refresh_done ( frame=0x7fff48325d78, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 281 if (err) { (gdb) bt #0 afr_read_txn_refresh_done (frame=0x7fff48325d78, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 #1 0x00007fff68901fdb in afr_txn_refresh_done ( frame=frame at entry=0x7fff48325d78, this=this at entry=0x7fff640137b0, err=5, err at entry=0) at afr-common.c:1223 #2 0x00007fff689022b3 in afr_inode_refresh_done ( frame=frame at entry=0x7fff48325d78, this=this at entry=0x7fff640137b0, error=0) at afr-common.c:1295 #3 0x00007fff6890f3fb in afr_inode_refresh_subvol_cbk (frame=0x7fff48325d78, cookie=<optimized out>, this=0x7fff640137b0, op_ret=<optimized out>, op_errno=<optimized out>, buf=buf at entry=0x7ffecfffdaa0, xdata=0x7ffeb806ef08, par=0x7ffecfffdb40) at afr-common.c:1333 #4 0x00007fff6890f42a in afr_inode_refresh_subvol_with_lookup_cbk ( frame=<optimized out>, cookie=<optimized out>, this=<optimized out>, op_ret=<optimized out>, op_errno=<optimized out>, inode=<optimized out>, buf=0x7ffecfffdaa0, xdata=0x7ffeb806ef08, par=0x7ffecfffdb40) at afr-common.c:1344 #5 0x00007fff68b8e96f in client4_0_lookup_cbk (req=<optimized out>, iov=<optimized out>, count=<optimized out>, myframe=0x7fff483147b8) at client-rpc-fops_v2.c:2640 #6 0x00007fffed293115 in rpc_clnt_handle_reply ( clnt=clnt at entry=0x7fff640671b0, pollin=pollin at entry=0x7ffeb81aa110) at rpc-clnt.c:764 #7 0x00007fffed2934b3 in rpc_clnt_notify (trans=0x7fff64067540, mydata=0x7fff640671e0, event=<optimized out>, data=0x7ffeb81aa110) at rpc-clnt.c:931 #8 0x00007fffed29007b in rpc_transport_notify ( this=this at entry=0x7fff64067540, event=event at entry=RPC_TRANSPORT_MSG_RECEIVED, data=data at entry=0x7ffeb81aa110) at rpc-transport.c:545 #9 0x00007fff7b6298dc in socket_event_poll_in_async (xl=<optimized out>, async=0x7ffeb81aa238) at socket.c:2592 #10 0x00007fff7b63134c in gf_async ( cbk=0x7fff7b6298b0 <socket_event_poll_in_async>, xl=<optimized out>, async=0x7ffeb81aa238) at ../../../../libglusterfs/src/glusterfs/async.h:189 #11 socket_event_poll_in (notify_handled=true, this=0x7fff64067540) at socket.c:2633 #12 socket_event_handler (fd=fd at entry=18, idx=idx at entry=9, gen=gen at entry=1, --Type <RET> for more, q to quit, c to continue without paging-- data=data at entry=0x7fff64067540, poll_in=<optimized out>, poll_out=<optimized out>, poll_err=0, event_thread_died=0 '\000') at socket.c:3031 #13 0x00007fffed54da8b in event_dispatch_epoll_handler (event=0x7ffecfffe014, event_pool=0x5555557cb750) at event-epoll.c:650 #14 event_dispatch_epoll_worker (data=0x7fff64038a80) at event-epoll.c:763 #15 0x00007fffec0702de in start_thread () from /lib64/libpthread.so.0 #16 0x00007fffeb8c8a63 in clone () from /lib64/libc.so.6 (gdb) continue Continuing. [Switching to Thread 0x7fff2ffff700 (LWP 50171)] Thread 11 "glfs_epoll003" hit Breakpoint 1, afr_read_txn_refresh_done ( frame=0x7ffc64544158, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 281 if (err) { (gdb) bt #0 afr_read_txn_refresh_done (frame=0x7ffc64544158, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 #1 0x00007fff68901fdb in afr_txn_refresh_done ( frame=frame at entry=0x7ffc64544158, this=this at entry=0x7fff640137b0, err=5, err at entry=0) at afr-common.c:1223 #2 0x00007fff689022b3 in afr_inode_refresh_done ( frame=frame at entry=0x7ffc64544158, this=this at entry=0x7fff640137b0, error=0) at afr-common.c:1295 #3 0x00007fff6890f3fb in afr_inode_refresh_subvol_cbk (frame=0x7ffc64544158, cookie=<optimized out>, this=0x7fff640137b0, op_ret=<optimized out>, op_errno=<optimized out>, buf=buf at entry=0x7fff2fffdaa0, xdata=0x7fff18523298, par=0x7fff2fffdb40) at afr-common.c:1333 #4 0x00007fff6890f42a in afr_inode_refresh_subvol_with_lookup_cbk ( frame=<optimized out>, cookie=<optimized out>, this=<optimized out>, op_ret=<optimized out>, op_errno=<optimized out>, inode=<optimized out>, buf=0x7fff2fffdaa0, xdata=0x7fff18523298, par=0x7fff2fffdb40) at afr-common.c:1344 #5 0x00007fff68b8e96f in client4_0_lookup_cbk (req=<optimized out>, iov=<optimized out>, count=<optimized out>, myframe=0x7ffc64319a08) at client-rpc-fops_v2.c:2640 #6 0x00007fffed293115 in rpc_clnt_handle_reply ( clnt=clnt at entry=0x7fff640671b0, pollin=pollin at entry=0x7fff18685b40) at rpc-clnt.c:764 #7 0x00007fffed2934b3 in rpc_clnt_notify (trans=0x7fff64067540, mydata=0x7fff640671e0, event=<optimized out>, data=0x7fff18685b40) at rpc-clnt.c:931 #8 0x00007fffed29007b in rpc_transport_notify ( this=this at entry=0x7fff64067540, event=event at entry=RPC_TRANSPORT_MSG_RECEIVED, data=data at entry=0x7fff18685b40) at rpc-transport.c:545 #9 0x00007fff7b6298dc in socket_event_poll_in_async (xl=<optimized out>, async=0x7fff18685c68) at socket.c:2592 #10 0x00007fff7b63134c in gf_async ( cbk=0x7fff7b6298b0 <socket_event_poll_in_async>, xl=<optimized out>, async=0x7fff18685c68) at ../../../../libglusterfs/src/glusterfs/async.h:189 #11 socket_event_poll_in (notify_handled=true, this=0x7fff64067540) at socket.c:2633 #12 socket_event_handler (fd=fd at entry=18, idx=idx at entry=9, gen=gen at entry=1, --Type <RET> for more, q to quit, c to continue without paging-- data=data at entry=0x7fff64067540, poll_in=<optimized out>, poll_out=<optimized out>, poll_err=0, event_thread_died=0 '\000') at socket.c:3031 #13 0x00007fffed54da8b in event_dispatch_epoll_handler (event=0x7fff2fffe014, event_pool=0x5555557cb750) at event-epoll.c:650 #14 event_dispatch_epoll_worker (data=0x7fff64038340) at event-epoll.c:763 #15 0x00007fffec0702de in start_thread () from /lib64/libpthread.so.0 #16 0x00007fffeb8c8a63 in clone () from /lib64/libc.so.6 Continuing. [Switching to Thread 0x7ffd53fff700 (LWP 50191)] Thread 31 "glfs_epoll016" hit Breakpoint 1, afr_read_txn_refresh_done ( frame=0x7ffc949cf7c8, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 281 if (err) { (gdb) bt #0 afr_read_txn_refresh_done (frame=0x7ffc949cf7c8, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 #1 0x00007fff68901fdb in afr_txn_refresh_done ( frame=frame at entry=0x7ffc949cf7c8, this=this at entry=0x7fff640137b0, err=5, err at entry=0) at afr-common.c:1223 #2 0x00007fff689022b3 in afr_inode_refresh_done ( frame=frame at entry=0x7ffc949cf7c8, this=this at entry=0x7fff640137b0, error=0) at afr-common.c:1295 #3 0x00007fff6890f3fb in afr_inode_refresh_subvol_cbk (frame=0x7ffc949cf7c8, cookie=<optimized out>, this=0x7fff640137b0, op_ret=<optimized out>, op_errno=<optimized out>, buf=buf at entry=0x7ffd53ffdaa0, xdata=0x7ffd3c6764f8, par=0x7ffd53ffdb40) at afr-common.c:1333 #4 0x00007fff6890f42a in afr_inode_refresh_subvol_with_lookup_cbk ( frame=<optimized out>, cookie=<optimized out>, this=<optimized out>, op_ret=<optimized out>, op_errno=<optimized out>, inode=<optimized out>, buf=0x7ffd53ffdaa0, xdata=0x7ffd3c6764f8, par=0x7ffd53ffdb40) at afr-common.c:1344 #5 0x00007fff68b8e96f in client4_0_lookup_cbk (req=<optimized out>, iov=<optimized out>, count=<optimized out>, myframe=0x7ffc9498ce38) at client-rpc-fops_v2.c:2640 #6 0x00007fffed293115 in rpc_clnt_handle_reply ( clnt=clnt at entry=0x7fff6406b4a0, pollin=pollin at entry=0x7ffd3c1685d0) at rpc-clnt.c:764 #7 0x00007fffed2934b3 in rpc_clnt_notify (trans=0x7fff6406b7b0, mydata=0x7fff6406b4d0, event=<optimized out>, data=0x7ffd3c1685d0) at rpc-clnt.c:931 #8 0x00007fffed29007b in rpc_transport_notify ( this=this at entry=0x7fff6406b7b0, event=event at entry=RPC_TRANSPORT_MSG_RECEIVED, data=data at entry=0x7ffd3c1685d0) at rpc-transport.c:545 #9 0x00007fff7b6298dc in socket_event_poll_in_async (xl=<optimized out>, async=0x7ffd3c1686f8) at socket.c:2592 #10 0x00007fff7b63134c in gf_async ( cbk=0x7fff7b6298b0 <socket_event_poll_in_async>, xl=<optimized out>, async=0x7ffd3c1686f8) at ../../../../libglusterfs/src/glusterfs/async.h:189 #11 socket_event_poll_in (notify_handled=true, this=0x7fff6406b7b0) at socket.c:2633 #12 socket_event_handler (fd=fd at entry=14, idx=idx at entry=6, gen=gen at entry=4, --Type <RET> for more, q to quit, c to continue without paging-- data=data at entry=0x7fff6406b7b0, poll_in=<optimized out>, poll_out=<optimized out>, poll_err=0, event_thread_died=0 '\000') at socket.c:3031 #13 0x00007fffed54da8b in event_dispatch_epoll_handler (event=0x7ffd53ffe014, event_pool=0x5555557cb750) at event-epoll.c:650 #14 event_dispatch_epoll_worker (data=0x7fff64065ee0) at event-epoll.c:763 #15 0x00007fffec0702de in start_thread () from /lib64/libpthread.so.0 #16 0x00007fffeb8c8a63 in clone () from /lib64/libc.so.6 (gdb) continue Continuing. [Switching to Thread 0x7fff60dc6700 (LWP 50169)] Thread 9 "glfs_epoll001" hit Breakpoint 1, afr_read_txn_refresh_done ( frame=0x7ffe589b0848, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 281 if (err) { (gdb) bt #0 afr_read_txn_refresh_done (frame=0x7ffe589b0848, this=0x7fff640137b0, err=5) at afr-read-txn.c:281 #1 0x00007fff68901fdb in afr_txn_refresh_done ( frame=frame at entry=0x7ffe589b0848, this=this at entry=0x7fff640137b0, err=5, err at entry=0) at afr-common.c:1223 #2 0x00007fff689022b3 in afr_inode_refresh_done ( frame=frame at entry=0x7ffe589b0848, this=this at entry=0x7fff640137b0, error=0) at afr-common.c:1295 #3 0x00007fff6890f3fb in afr_inode_refresh_subvol_cbk (frame=0x7ffe589b0848, cookie=<optimized out>, this=0x7fff640137b0, op_ret=<optimized out>, op_errno=<optimized out>, buf=buf at entry=0x7fff60dc4aa0, xdata=0x7fff48a70bc8, par=0x7fff60dc4b40) at afr-common.c:1333 #4 0x00007fff6890f42a in afr_inode_refresh_subvol_with_lookup_cbk ( frame=<optimized out>, cookie=<optimized out>, this=<optimized out>, op_ret=<optimized out>, op_errno=<optimized out>, inode=<optimized out>, buf=0x7fff60dc4aa0, xdata=0x7fff48a70bc8, par=0x7fff60dc4b40) at afr-common.c:1344 #5 0x00007fff68b8e96f in client4_0_lookup_cbk (req=<optimized out>, iov=<optimized out>, count=<optimized out>, myframe=0x7ffe584cfeb8) at client-rpc-fops_v2.c:2640 #6 0x00007fffed293115 in rpc_clnt_handle_reply ( clnt=clnt at entry=0x7fff640671b0, pollin=pollin at entry=0x7fff484cc110) at rpc-clnt.c:764 #7 0x00007fffed2934b3 in rpc_clnt_notify (trans=0x7fff64067540, mydata=0x7fff640671e0, event=<optimized out>, data=0x7fff484cc110) at rpc-clnt.c:931 #8 0x00007fffed29007b in rpc_transport_notify ( this=this at entry=0x7fff64067540, event=event at entry=RPC_TRANSPORT_MSG_RECEIVED, data=data at entry=0x7fff484cc110) at rpc-transport.c:545 #9 0x00007fff7b6298dc in socket_event_poll_in_async (xl=<optimized out>, async=0x7fff484cc238) at socket.c:2592 #10 0x00007fff7b63134c in gf_async ( cbk=0x7fff7b6298b0 <socket_event_poll_in_async>, xl=<optimized out>, async=0x7fff484cc238) at ../../../../libglusterfs/src/glusterfs/async.h:189 #11 socket_event_poll_in (notify_handled=true, this=0x7fff64067540) at socket.c:2633 #12 socket_event_handler (fd=fd at entry=18, idx=idx at entry=9, gen=gen at entry=1, --Type <RET> for more, q to quit, c to continue without paging-- data=data at entry=0x7fff64067540, poll_in=<optimized out>, poll_out=<optimized out>, poll_err=0, event_thread_died=0 '\000') at socket.c:3031 #13 0x00007fffed54da8b in event_dispatch_epoll_handler (event=0x7fff60dc5014, event_pool=0x5555557cb750) at event-epoll.c:650 #14 event_dispatch_epoll_worker (data=0x555555825900) at event-epoll.c:763 #15 0x00007fffec0702de in start_thread () from /lib64/libpthread.so.0 #16 0x00007fffeb8c8a63 in clone () from /lib64/libc.so.6 (gdb) continue