Daniel,
I saw the following core again with V2.7.4 and the following patches applied including the
last MDCACHE one.
Took about 5 days of hard testing to hit the core. There still seems an edge case that
does an extra chunk unref.
You mentioned last time that the chunk cannot be freed by another thread (in between the
content lock release and re-acquire) because we have a ref count. But could the code path
that removes the “sentinel” ref result in this chunk being re-used by the LRU since it
still has the ref count from this path. ( Code that removes the sentinel reference:
mdcache_populate_dir_chunk() the section with the comment “Put sentinal ref”. ) Or maybe
there is a completely different edge case that does an extra unref.
Minor: The commit heading for 2.7.5 says 2.7.4
https://github.com/nfs-ganesha/nfs-ganesha/commit/6407d3d133c9346ae586cec...
Thanks,
Vandana
Patches applied:
https://github.com/nfs-ganesha/nfs-ganesha/commit/c7e7d24877085dbb0424542...
https://github.com/nfs-ganesha/nfs-ganesha/commit/136df4f262c3f9bc29df456...
https://github.com/nfs-ganesha/nfs-ganesha/commit/c98ad1e238f5db9db5ab8db...
https://github.com/nfs-ganesha/nfs-ganesha/commit/f0d5b8d4f6dcce4597459c3...
https://github.com/nfs-ganesha/nfs-ganesha/commit/e11cd5b9f8d6ffbb46061e7...
https://github.com/nfs-ganesha/nfs-ganesha/commit/5439f63b8a1e00f6ff56a4d...
https://github.com/nfs-ganesha/nfs-ganesha/commit/e306c01685b74970ada2259...
Here are the code snippets around the lines of code in the core, after
mdcache_find_keyed_reason gets an error.
if (!has_write) {
/* We will have to re-find this dirent after we
* re-acquire the lock.
*/
look_ck = dirent->ck;
PTHREAD_RWLOCK_unlock(&directory->content_lock);
PTHREAD_RWLOCK_wrlock(&directory->content_lock);
has_write = true;
/* Dropping the content_lock may have
* invalidated some or all of the dirents and/or
* chunks in this directory. We need to start
* over from this point. look_ck is now correct
* if the dirent is still cached, and we haven't
* changed next_ck, so it's still correct for
* reloading the chunk.
*/
first_pass = true;
>>>>>>>>> Line 3133
mdcache_lru_unref_chunk(chunk);
chunk = NULL;
/* Now we need to look for this dirent again.
* We haven't updated next_ck for this dirent
* yet, so it is the right whence to use for a
* repopulation readdir if the chunk is
* discarded.
*/
goto again;
(gdb) print lru_state
$1 = {entries_hiwat = 500000, entries_used = 518407, chunks_hiwat = 100000, chunks_used =
99952,
fds_system_imposed = 400000, fds_hard_limit = 396000, fds_hiwat = 360000, fds_lowat =
200000,
futility = 0, per_lane_work = 50, biggest_window = 160000, prev_fd_count = 244632,
prev_time = 1562643400, fd_state = 2}
(gdb) bt
#0 0x00007fdf573e5c40 in pthread_mutex_lock () from /lib64/libpthread.so.0
#1 0x000000000052af4a in _mdcache_lru_unref_chunk (chunk=0x56035bc0,
func=0x598a00 <__func__.23678> "mdcache_readdir_chunked", line=3133)
at /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_lru.c:2058
#2 0x0000000000542d84 in mdcache_readdir_chunked (directory=0x1a244a20,
whence=35907657,
dir_state=0x7fdf4ba7baf0, cb=0x4323ed <populate_dirent>, attrmask=0,
eod_met=0x7fdf4ba7bfeb)
at /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3133
#3 0x000000000053054c in mdcache_readdir (dir_hdl=0x1a244a58, whence=0x7fdf4ba7bad0,
dir_state=0x7fdf4ba7baf0, cb=0x4323ed <populate_dirent>, attrmask=0,
eod_met=0x7fdf4ba7bfeb)
at /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:559
#4 0x0000000000432d14 in fsal_readdir (directory=0x1a244a58, cookie=35907657,
nbfound=0x7fdf4ba7bfec, eod_met=0x7fdf4ba7bfeb, attrmask=0, cb=0x491d35
<nfs3_readdir_callback>,
opaque=0x7fdf4ba7bfa0) at /src/src/FSAL/fsal_helper.c:1164
#5 0x0000000000491b1d in nfs3_readdir (arg=0x3a08e098, req=0x3a08d990, res=0x20466d70)
at /src/src/Protocols/NFS/nfs3_readdir.c:289
#6 0x0000000000457c16 in nfs_rpc_process_request (reqdata=0x3a08d990)
at /src/src/MainNFSD/nfs_worker_thread.c:1328
#7 0x00000000004583d5 in nfs_rpc_valid_NFS (req=0x3a08d990)
at /src/src/MainNFSD/nfs_worker_thread.c:1548
#8 0x00007fdf583c0034 in svc_vc_decode (req=0x3a08d990) at
/src/src/libntirpc/src/svc_vc.c:829
#9 0x000000000044adc5 in nfs_rpc_decode_request (xprt=0x3dd4adf0, xdrs=0x3cfd0940)
at /src/src/MainNFSD/nfs_rpc_dispatcher_thread.c:1345
#10 0x00007fdf583bff45 in svc_vc_recv (xprt=0x3dd4adf0) at
/src/src/libntirpc/src/svc_vc.c:802
---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) select-frame 2
(gdb) info locals
status = {major = ERR_FSAL_NOENT, minor = 0}
cb_result = DIR_CONTINUE
entry = 0x0
attrs = {request_mask = 0, valid_mask = 1433550, supported = 1433582, type =
REGULAR_FILE,
filesize = 1059147, fsid = {major = 0, minor = 0}, acl = 0x0, fileid = 35907648, mode =
493,
numlinks = 1, owner = 4294967294, group = 4294967294, rawdev = {major = 0, minor = 0},
atime = {
tv_sec = 1562643413407000, tv_nsec = 0}, creation = {tv_sec = 0, tv_nsec = 0}, ctime =
{
tv_sec = 1562643413407000, tv_nsec = 0}, mtime = {tv_sec = 1562624796, tv_nsec =
478000000},
chgtime = {tv_sec = 1562643413407000, tv_nsec = 0}, spaceused = 1059147,
change = 1562643413407000000, generation = 0, expire_time_attr = 60, fs_locations =
0x0,
sec_label = {slai_lfs = {lfs_lfs = 0, lfs_pi = 0}, slai_data = {slai_data_len = 0,
slai_data_val = 0x0}}}
dirent = 0x3a584590
has_write = true
set_first_ck = false
next_ck = 35907651
look_ck = 35907664
chunk = 0x56035bc0
first_pass = true
eod = false
reload_chunk = false
__func__ = "mdcache_readdir_chunked"
__PRETTY_FUNCTION__ = "mdcache_readdir_chunked"
(gdb)
status = {major = ERR_FSAL_NOENT, minor = 0}
cb_result = DIR_CONTINUE
entry = 0x0
attrs = {request_mask = 0, valid_mask = 1433550, supported = 1433582, type =
REGULAR_FILE,
filesize = 1059147, fsid = {major = 0, minor = 0}, acl = 0x0, fileid = 35907648, mode =
493,
numlinks = 1, owner = 4294967294, group = 4294967294, rawdev = {major = 0, minor = 0},
atime = {
tv_sec = 1562643413407000, tv_nsec = 0}, creation = {tv_sec = 0, tv_nsec = 0}, ctime =
{
tv_sec = 1562643413407000, tv_nsec = 0}, mtime = {tv_sec = 1562624796, tv_nsec =
478000000},
chgtime = {tv_sec = 1562643413407000, tv_nsec = 0}, spaceused = 1059147,
change = 1562643413407000000, generation = 0, expire_time_attr = 60, fs_locations =
0x0,
sec_label = {slai_lfs = {lfs_lfs = 0, lfs_pi = 0}, slai_data = {slai_data_len = 0,
slai_data_val = 0x0}}}
dirent = 0x3a584590
has_write = true
set_first_ck = false
next_ck = 35907651
look_ck = 35907664
chunk = 0x56035bc0
first_pass = true
eod = false
reload_chunk = false
__func__ = "mdcache_readdir_chunked"
__PRETTY_FUNCTION__ = "mdcache_readdir_chunked"
(gdb) print *dirent
$2 = {chunk_list = {next = 0x7fdf585dd380 <xdr_ioq_ops>, prev = 0x34247680}, chunk =
0x0,
node_name = {left = 0x0, right = 0x0, parent = 457566472}, node_ck = {left =
0x3b255758,
right = 0x1b45e8a0, parent = 457566368}, node_sorted = {left = 0x1b45e908, right =
0x1b45e908,
parent = 25769803776}, ck = 1, eod = false, namehash = 0, ckey = {hk = 0, fsal = 0x0,
kv = {
addr = 0x0, len = 0}}, flags = 0, entry = 0x3dd4b088,
name = 0x10000000000 <Address 0x10000000000 out of bounds>, name_buffer =
0x3a584640 ""}
(gdb) print *chunk
$3 = {chunks = {next = 0x24b1c303, prev = 0xa386010002000000}, dirents = {next =
0x300000003000000,
prev = 0x1c00000001000000}, parent = 0x7000000aaaaaaaa, chunk_lru = {q = {
next = 0x6e776f6e6b6e75, prev = 0xfefffffffeffffff}, qid = LRU_ENTRY_NONE, refcnt =
0,
flags = 0, lane = 268435456, cf = 16777283}, reload_ck = 1099511627778,
next_ck = 7236828793636126720, num_entries = 858680687}