[Bugs] [Bug 1618347] New: [Ganesha] Ganesha crashed in mdcache_alloc_and_check_handle while running bonnie and untars with parallel lookups

bugzilla at redhat.com bugzilla at redhat.com
Thu Aug 16 13:12:33 UTC 2018


https://bugzilla.redhat.com/show_bug.cgi?id=1618347

            Bug ID: 1618347
           Summary: [Ganesha] Ganesha crashed in
                    mdcache_alloc_and_check_handle while running bonnie
                    and untars with parallel lookups
           Product: GlusterFS
           Version: 4.1
         Component: libgfapi
          Severity: high
          Assignee: jthottan at redhat.com
          Reporter: jthottan at redhat.com
        QA Contact: bugs at gluster.org
                CC: bugs at gluster.org
        Depends On: 1610236
            Blocks: 1601245



+++ This bug was initially created as a clone of Bug #1610236 +++

+++ This bug was initially created as a clone of Bug #1601245 +++

Description of problem:

6 Node ganesha cluster. 3 clients mapping same volume (2 x (4 + 2)
Distributed-disperse Volume ) with v3/v4 protocol. Different VIP's.


While running bonnie,linux untars with parallel lookups from 3 different
clients,Ganesha crashed on one of the node (whose VIP is mapped to client
running lookups)


====================

Switching to Thread 0x7f40e7fa7700 (LWP 22611)]
0x00007f4148abc207 in raise () from /lib64/libc.so.6
(gdb) bt
#0  0x00007f4148abc207 in raise () from /lib64/libc.so.6
#1  0x00007f4148abd8f8 in abort () from /lib64/libc.so.6
#2  0x00005594dda3f8f3 in mdcache_alloc_and_check_handle
(export=export at entry=0x5594de1294d0, sub_handle=<optimized out>, 
    new_obj=new_obj at entry=0x7f40e7fa5938,
new_directory=new_directory at entry=false,
attrs_in=attrs_in at entry=0x7f40e7fa5940, 
    attrs_out=attrs_out at entry=0x0, tag=tag at entry=0x5594dda8d9a1 "lookup ",
parent=parent at entry=0x7f4080101220, name=name at entry=0x7f3f6c2d41b4 "", 
    invalidate=invalidate at entry=0x7f40e7fa592f, state=state at entry=0x0)
    at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:138
#3  0x00005594dda4b0a1 in mdc_lookup_uncached
(mdc_parent=mdc_parent at entry=0x7f4080101220, name=0x7f3f6c2d41b4 "", 
    new_entry=new_entry at entry=0x7f40e7fa5b18, attrs_out=attrs_out at entry=0x0)
    at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1420
#4  0x00005594dda4f772 in mdcache_readdir_chunked
(directory=directory at entry=0x7f4080101220, whence=0,
dir_state=dir_state at entry=0x7f40e7fa5e30, 
    cb=cb at entry=0x5594dd96a1f0 <populate_dirent>,
attrmask=attrmask at entry=122830, eod_met=eod_met at entry=0x7f40e7fa5f1b)
    at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3215
#5  0x00005594dda3d924 in mdcache_readdir (dir_hdl=0x7f4080101258,
whence=<optimized out>, dir_state=0x7f40e7fa5e30, 
    cb=0x5594dd96a1f0 <populate_dirent>, attrmask=122830,
eod_met=0x7f40e7fa5f1b)
    at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:640
#6  0x00005594dd96c0e4 in fsal_readdir
(directory=directory at entry=0x7f4080101258, cookie=cookie at entry=0,
nbfound=nbfound at entry=0x7f40e7fa5f1c, 
    eod_met=eod_met at entry=0x7f40e7fa5f1b, attrmask=122830,
cb=cb at entry=0x5594dd9a87f0 <nfs4_readdir_callback>,
opaque=opaque at entry=0x7f40e7fa5f20)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/fsal_helper.c:1500
---Type <return> to continue, or q <return> to quit---
#7  0x00005594dd9a97bb in nfs4_op_readdir (op=0x7f40880043c0,
data=0x7f40e7fa6150, resp=0x7f3f44362eb0)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/Protocols/NFS/nfs4_op_readdir.c:627
#8  0x00005594dd99515f in nfs4_Compound (arg=<optimized out>, req=<optimized
out>, res=0x7f3f442f91f0)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/Protocols/NFS/nfs4_Compound.c:752
#9  0x00005594dd9853cb in nfs_rpc_execute
(reqdata=reqdata at entry=0x7f4088059470)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/MainNFSD/nfs_worker_thread.c:1290
#10 0x00005594dd986a2a in worker_run (ctx=0x5594de23b5e0) at
/usr/src/debug/nfs-ganesha-2.5.5/src/MainNFSD/nfs_worker_thread.c:1562
#11 0x00005594dda171a9 in fridgethr_start_routine (arg=0x5594de23b5e0) at
/usr/src/debug/nfs-ganesha-2.5.5/src/support/fridgethr.c:550
#12 0x00007f41494b8dd5 in start_thread () from /lib64/libpthread.so.0
#13 0x00007f4148b84b3d in clone () from /lib64/libc.so.6

============== 



ganesha.log-

-----------
15/07/2018 18:17:07 : epoch 96c40000 : zod.lab.eng.blr.redhat.com :
ganesha.nfsd-22492[work-95] posix2fsal_type :FSAL :WARN :Unknown object type: 0
15/07/2018 18:17:07 : epoch 96c40000 : zod.lab.eng.blr.redhat.com :
ganesha.nfsd-22492[work-95] posix2fsal_type :FSAL :WARN :Unknown object type: 0
15/07/2018 18:17:07 : epoch 96c40000 : zod.lab.eng.blr.redhat.com :
ganesha.nfsd-22492[work-95] mdcache_alloc_and_check_handle :RW LOCK :CRIT
:Error 35, write locking 0x7f4080101658 (&new_entry->content_lock) at
/builddir/build/BUILD/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:138
-----------

Version-Release number of selected component (if applicable):

# rpm -qa | grep ganesha
nfs-ganesha-2.5.5-8.el7rhgs.x86_64
nfs-ganesha-gluster-2.5.5-8.el7rhgs.x86_64
nfs-ganesha-debuginfo-2.5.5-8.el7rhgs.x86_64
glusterfs-ganesha-3.12.2-13.el7rhgs.x86_64


How reproducible:

2/3

Steps to Reproduce:
1.Create 6 node ganesha cluster
2.Create Distributed-disperse 2 x (4 + 2) volume
3.Mount the volume to 3 different clients with 3 different VIP's
4.Run the following workload

Client 1 (v3) :Run linux untars
Client 2 (v3):Run dbench,bonnie
Client 3 (v4):Run  ls -laRt in loop

Actual results:

While running the above workload,Ganesha crashed on one of the node.


Expected results:

Ganesha should not crash 

Additional info:



--- Additional comment from Daniel Gryniewicz on 2018-07-16 14:45:59 EDT ---

So, the lock attempt returned EDEADLK, which means that this thread already has
the lock.  The content lock of the parent directory is, indeed, held during
this operation; however, you shouldn't be able to get an inode that points to a
directory when you do a readdir() on that directory.  You can't, for example,
hard-link to a directory at all.

Does the directory structure still exist?  If so, can we get the output of
ls -ialR
from it? (note, -i, not -t)  Alternatively, if the core is still there, we can
get the name of the directory that crashed from that, and the just get the "ls
-ial" output of that directory; this would be a much much smaller output.

--- Additional comment from Manisha Saini on 2018-07-18 05:15:16 EDT ---

I have shared the core generated in comment#2.
Setup is not in same state.

--- Additional comment from Manisha Saini on 2018-07-23 04:00:16 EDT ---

I could consistently hit this crash on
nfs-ganesha-gluster-2.5.5-8.el7rhgs.x86_64 build.

But every time its not able to generate core dump file.Hence I took from gdb
session.

Also,there is no dir name in the core file causing this crash so that I can
take the output of "ls -ial" of that particular directory.

Taking full output of "ls -ialR" is taking more then 2+ hours for this data
set.


bt output from gdb session
--------------------
Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fde98718700 (LWP 31200)]
0x00007fdf5a8ad207 in raise () from /lib64/libc.so.6
(gdb) bt
#0  0x00007fdf5a8ad207 in raise () from /lib64/libc.so.6
#1  0x00007fdf5a8ae8f8 in abort () from /lib64/libc.so.6
#2  0x0000562c4455e8f3 in mdcache_alloc_and_check_handle
(export=export at entry=0x562c45f5f100, sub_handle=<optimized out>, 
    new_obj=new_obj at entry=0x7fde98716938,
new_directory=new_directory at entry=false,
attrs_in=attrs_in at entry=0x7fde98716940, 
    attrs_out=attrs_out at entry=0x0, tag=tag at entry=0x562c445ac9a1 "lookup ",
parent=parent at entry=0x7fdd7c35a1c0, 
    name=name at entry=0x7fde3c30ff24 "",
invalidate=invalidate at entry=0x7fde9871692f, state=state at entry=0x0)
    at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:138
#3  0x0000562c4456a0a1 in mdc_lookup_uncached
(mdc_parent=mdc_parent at entry=0x7fdd7c35a1c0, name=0x7fde3c30ff24 "", 
    new_entry=new_entry at entry=0x7fde98716b18, attrs_out=attrs_out at entry=0x0)
    at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1420
#4  0x0000562c4456e772 in mdcache_readdir_chunked
(directory=directory at entry=0x7fdd7c35a1c0, whence=0, 
    dir_state=dir_state at entry=0x7fde98716e30, cb=cb at entry=0x562c444891f0
<populate_dirent>, attrmask=attrmask at entry=122830, 
    eod_met=eod_met at entry=0x7fde98716f1b) at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3215
#5  0x0000562c4455c924 in mdcache_readdir (dir_hdl=0x7fdd7c35a1f8,
whence=<optimized out>, dir_state=0x7fde98716e30, 
    cb=0x562c444891f0 <populate_dirent>, attrmask=122830,
eod_met=0x7fde98716f1b)
    at
/usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:640
#6  0x0000562c4448b0e4 in fsal_readdir
(directory=directory at entry=0x7fdd7c35a1f8, cookie=cookie at entry=0, 
    nbfound=nbfound at entry=0x7fde98716f1c, eod_met=eod_met at entry=0x7fde98716f1b,
attrmask=122830, 
    cb=cb at entry=0x562c444c77f0 <nfs4_readdir_callback>,
opaque=opaque at entry=0x7fde98716f20)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/FSAL/fsal_helper.c:1500
#7  0x0000562c444c87bb in nfs4_op_readdir (op=0x7fde240bf870,
data=0x7fde98717150, resp=0x7fde3843f7b0)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/Protocols/NFS/nfs4_op_readdir.c:627
#8  0x0000562c444b415f in nfs4_Compound (arg=<optimized out>, req=<optimized
out>, res=0x7fde3837b660)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/Protocols/NFS/nfs4_Compound.c:752
#9  0x0000562c444a43cb in nfs_rpc_execute
(reqdata=reqdata at entry=0x7fde2435f370)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/MainNFSD/nfs_worker_thread.c:1290


--------------------------


bt of core dump file

------------------
4 libgcrypt-1.5.3-14.el7.x86_64 libgpg-error-1.12-3.el7.x86_64
libnfsidmap-0.25-19.el7.x86_64 libselinux-2.5-12.el7.x86_64
libuuid-2.23.2-52.el7.x86_64 lz4-1.7.5-2.el7.x86_64
openssl-libs-1.0.2k-12.el7.x86_64 pcre-8.32-17.el7.x86_64
systemd-libs-219-57.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64
zlib-1.2.7-17.el7.x86_64
(gdb) bt
#0  0x00007fdf5b2adcf2 in pthread_cond_timedwait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1  0x0000562c44536404 in fridgethr_freeze (thr_ctx=0x562c45f59040,
fr=0x562c45f583a0)
    at /usr/src/debug/nfs-ganesha-2.5.5/src/support/fridgethr.c:416
#2  fridgethr_start_routine (arg=0x562c45f59040) at
/usr/src/debug/nfs-ganesha-2.5.5/src/support/fridgethr.c:554
#3  0x00007fdf5b2a9dd5 in start_thread () from /lib64/libpthread.so.0
#4  0x00007fdf5a975b3d in clone () from /lib64/libc.so.6
--------------------


--- Additional comment from Daniel Gryniewicz on 2018-07-23 15:05:51 EDT ---

Okay, the core file helps, to some extent.  There is a dirent with an empty
name:

(gdb) p dirent->name 
$2 = 0x7fde3c30ff24 ""

This is passed into FSAL_GLUSTER's lookup(), which calls glfs_h_lookupat() with
it.  This must return the handle of the parent directory, rather than an error,
and so mdcache find's it's existing entry for the parent dir, which already has
it's content_lock held.

There are 2 bugs here, I think.

1) MDCACHE lost a name on a dirent.  I'll look into this.
2) lookup(parent_dir, name="") in gluster returns parent_dir, instead of an
error.

--- Additional comment from Jiffin on 2018-07-26 05:03:02 EDT ---

(In reply to Daniel Gryniewicz from comment #9)
> Okay, the core file helps, to some extent.  There is a dirent with an empty
> name:
> 
> (gdb) p dirent->name 
> $2 = 0x7fde3c30ff24 ""
> 
> This is passed into FSAL_GLUSTER's lookup(), which calls glfs_h_lookupat()
> with it.  This must return the handle of the parent directory, rather than
> an error, and so mdcache find's it's existing entry for the parent dir,
> which already has it's content_lock held.
> 
> There are 2 bugs here, I think.
> 
> 1) MDCACHE lost a name on a dirent.  I'll look into this.
> 2) lookup(parent_dir, name="") in gluster returns parent_dir, instead of an
> error.

The pub_glfs_h_lookupat() only checks for path = NULL for returning error, in
this it was not NULL. Then it tries to resolve path component 
from glfs_resolve_at()



        for (component = strtok_r (path, "/", &saveptr);                        
             component; component = next_component) {                           

                next_component = strtok_r (NULL, "/", &saveptr);                

                if (parent)                                                     
                        inode_unref (parent);                                   
                parent = inode;                                                 
                inode = glfs_resolve_component (fs, subvol, parent,             
                                                component, &ciatt,              
                                                /* force hard lookup on the
last                         
                                                   component, as the caller     
                                                   wants proper iatt filled     
                                                */                              
                                                (reval || (!next_component &&   
                                                iatt)));   

Looks like above loop resolve parent if the value of path is "".


So how come the path become "". Was it cleared or something ? is it valid value
for path??

--- Additional comment from Daniel Gryniewicz on 2018-07-27 10:32:42 EDT ---

I don't know how path became "" yet, name is only set on creation or rename. 
Tracing through the code, it looks like only NFSv3 could use an empty name,
since NFSv4's standard utf8 string handler checks for 0-length strings, whereas
NFSv3 just uses what the client provided.


However, returning the parent for that is clearly a bug.  Parent should only be
returned for "."

--- Additional comment from Frank Filz on 2018-07-27 10:56:43 EDT ---

(In reply to Daniel Gryniewicz from comment #11)
> I don't know how path became "" yet, name is only set on creation or rename.
> Tracing through the code, it looks like only NFSv3 could use an empty name,
> since NFSv4's standard utf8 string handler checks for 0-length strings,
> whereas NFSv3 just uses what the client provided.
> 
> 
> However, returning the parent for that is clearly a bug.  Parent should only
> be returned for "."

Hmm, I thought I had done some looking at this one... 

An empty name would be valid if AT_EMPTY_PATH was set, but we don't in this
case.

Is it remotely possible we got an empty name in readdir?

If this is re-createable, it would be interesting to enable NFS_READDIR log
componment to FULL_DEBUG. We can then look for empty names.

--- Additional comment from Matt Benjamin (redhat) on 2018-07-27 11:00:57 EDT
---

(In reply to Frank Filz from comment #12)
> (In reply to Daniel Gryniewicz from comment #11)
> > I don't know how path became "" yet, name is only set on creation or rename.
> > Tracing through the code, it looks like only NFSv3 could use an empty name,
> > since NFSv4's standard utf8 string handler checks for 0-length strings,
> > whereas NFSv3 just uses what the client provided.
> > 
> > 
> > However, returning the parent for that is clearly a bug.  Parent should only
> > be returned for "."
> 
> Hmm, I thought I had done some looking at this one... 
> 
> An empty name would be valid if AT_EMPTY_PATH was set, but we don't in this
> case.
> 
> Is it remotely possible we got an empty name in readdir?
> 
> If this is re-createable, it would be interesting to enable NFS_READDIR log
> componment to FULL_DEBUG. We can then look for empty names.

I don't know but isn't Daniel's observation about returning parent (dot? 
dotdot?) still correct?

Matt

--- Additional comment from Frank Filz on 2018-07-27 11:29:42 EDT ---

(In reply to Matt Benjamin (redhat) from comment #13)
> I don't know but isn't Daniel's observation about returning parent (dot? 
> dotdot?) still correct?

Yes, the empty path resulting in returning the parent without AT_EMPTY_PATH
passed as a flag is not good, without that flag, empty path should return an
error.

But there's an issue where somehow Ganesha is getting a dirent with an empty
name...

That COULD be because we got one from readdir from the filesystem. It could be
because somehow we dropped the name.

--- Additional comment from Daniel Gryniewicz on 2018-07-27 12:04:37 EDT ---

We can't have dropped the name.  It's only freed and NULL'd.  I think it has to
have come from either readdir() or rename().

--- Additional comment from Daniel Gryniewicz on 2018-07-30 09:57:13 EDT ---

AT_EMPTY_PATH is only valid for *at() calls (fstatat, fchonwat, etc), i.e.
things that take a file descriptor and a name.  As far as I can tell, an empty
name on a dirent is not valid.  Adding a check for creation, link, and rename
is easy; dealing with readdir is much harder, as it may make an entire
directory unreadable, and therefor un-removeable.  It would be better for this
case if Gluster disallowed creation of such a dirent in the first place.

--- Additional comment from Daniel Gryniewicz on 2018-07-30 10:03:00 EDT ---

Actually, NFSv4 explicitly forbids zero-length dirents:

   If the oldname or newname is of zero length, NFS4ERR_INVAL will be
   returned.

NFSv3 does not include this requirement, but does allow NFS3ERR_INVAL for
invalid names.  I'll add some checking for names from clients.  NFSv4 already
has this, as part of it's standard UTF-8 handling, but I'll add some for other
protocols.

GFAPI needs to be fixed in addition, so no other client can create such
dirents.

--- Additional comment from Daniel Gryniewicz on 2018-07-30 10:19:54 EDT ---

 https://review.gerrithub.io/#/c/ffilz/nfs-ganesha/+/420770

--- Additional comment from Worker Ant on 2018-07-31 05:27:59 EDT ---

REVIEW: https://review.gluster.org/20594 (gfapi : Handle the path == \"\" in
pub_glfs_h_lookupat) posted (#1) for review on master by jiffin tony Thottan

--- Additional comment from Worker Ant on 2018-08-13 07:45:26 EDT ---

COMMIT: https://review.gluster.org/20594 committed in master by "Kaleb
KEITHLEY" <kkeithle at redhat.com> with a commit message- gfapi : Handle the path
== "" glfs_resolve_at

Currently there is no check for path = "" in glfs_resolve_at.
So if application sends an empty path, then the function resolves
into the parent inode which is incorrect. Plus modified possible
of "path" with "origpath" in the same function.

Change-Id: Ie5ff9ce4b771607b7dbb3fe00704fe670421792a
fixes: bz#1610236
Signed-off-by: Jiffin Tony Thottan <jthottan at redhat.com>


Referenced Bugs:

https://bugzilla.redhat.com/show_bug.cgi?id=1601245
[Bug 1601245] [Ganesha] Ganesha crashed in mdcache_alloc_and_check_handle
while running bonnie and untars with parallel lookups
https://bugzilla.redhat.com/show_bug.cgi?id=1610236
[Bug 1610236] [Ganesha] Ganesha crashed in mdcache_alloc_and_check_handle
while running bonnie and untars with parallel lookups
-- 
You are receiving this mail because:
You are the QA Contact for the bug.
You are on the CC list for the bug.


More information about the Bugs mailing list