Ah, good point.

mdcache_clean_dirent_chunks maybe needs to remove the chunks from the directory so that subsequent calls won’t unref the chunk again. It does a glist_for_each_safe assuming the chunks will be removed but you’re right, if other threads hold references to chunks, those chunks won’t actually be removed.

If we simply removed the chunk from the list, mdcache_clean_dirent_chunks would not try and unref it again, and the final unref from whichever thread was last in accessing the chunk would clean the chunk but the chunk would have already been removed from the directory list of chunks.

Frank

From: Rungta, Vandana [mailto:vrungta@amazon.com]
Sent: Wednesday, July 10, 2019 2:34 PM
To: devel@lists.nfs-ganesha.org; dang@redhat.com
Subject: [NFS-Ganesha-Devel] Extra mdcache_lru_unref_chunk path

Thread 1 is holding a ref on the chunk and releases the content lock

Thread 2 gets the write lock and calls dirents_invalidate_all and unrefs the chunk, will not clean the chunk so it is still hooked to the directory

Thread 3 gets the write lock and calls dirents_invalidate_all and unrefs the chunk – this is removing the ref held by Thread 1 and will clean the chunk

Thread 1 gets the write lock and tries to unref the chunk à but chunk is already deleted by Thread 3

Thanks,

Vandana

2.7.4 with patches.

Patches applied:

https://github.com/nfs-ganesha/nfs-ganesha/commit/c7e7d24877085dbb0424542d9d8339c722771716

https://github.com/nfs-ganesha/nfs-ganesha/commit/136df4f262c3f9bc29df456eac50921321826da3

https://github.com/nfs-ganesha/nfs-ganesha/commit/c98ad1e238f5db9db5ab8db8cea1c5cf1f123d76

https://github.com/nfs-ganesha/nfs-ganesha/commit/f0d5b8d4f6dcce4597459c3ebaf36d1e96e4645b

https://github.com/nfs-ganesha/nfs-ganesha/commit/e11cd5b9f8d6ffbb46061e7cd2b5a3e247bf09af

https://github.com/nfs-ganesha/nfs-ganesha/commit/5439f63b8a1e00f6ff56a4def58f960f03676c7b

https://github.com/nfs-ganesha/nfs-ganesha/commit/e306c01685b74970ada2259f2bf393cdc1233af6

Relevant debug log messages:

svc_48 is the thread that cored

directory = 0xd873770

dirent = 0x3a6ff9c0

--> chunk with too many unrefs -> chunk = 0xd690fb0

Starting a readdir

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:2860 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Starting chunked READDIR for 0xd873770, MDCACHE_TRUST_CONTENT true, MDCACHE_TRUST_DIR_CHUNKS true

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:2895 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Readdir chunked next_ck=0x0 look_ck=2298289

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3061 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: found dirent in cached chunk 0xd690fb0 dirent 0x9294be0 random.0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3069 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: About to read directory=0xd873770 cookie=0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:980 :mdcache_find_keyed_reason :INODE :F_DBG :Looking for hk=a5e560b83f87bdf1 fsal=0x7f24e080b080 key=0x86822902000000000100

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1018 :mdcache_find_keyed_reason :INODE :F_DBG :Found entry 0xd5651a0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3235 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Setting next_ck=2298289

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:931 :mdcache_getattrs :INODE :F_DBG :attrs obj attributes Valid Mask=0015dfce Supported Mask=0015dfee REGULAR_FILE numlinks=0x1 size=0xa19c08 mode=0755 owner=0xfffffffe group=0xfffffffe atime=Tue Aug 06 07:06:40 49523574 UTC mtime=Wed Jul 10 04:44:09 2019 UTC

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3275 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: dirent = 0x9294be0 random.0, cb_result = DIR_CONTINUE, eod = false

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:980 :mdcache_find_keyed_reason :INODE :F_DBG :Looking for hk=7e081c83c9ef0267 fsal=0x7f24e080b080 key=0x89822902000000000100

->mdcache_find_keyed_reason repeated pattern ......

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:980 :mdcache_find_keyed_reason :INODE :F_DBG :Looking for hk=73c0008e99ecba6 fsal=0x7f24e080b080 key=0xd3822902000000000100

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1018 :mdcache_find_keyed_reason :INODE :F_DBG :Found entry 0xdb00050

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:931 :mdcache_getattrs :INODE :F_DBG :attrs obj attributes Valid Mask=0015dfce Supported Mask=0015dfee REGULAR_FILE numlinks=0x1 size=0xa19c08 mode=0755 owner=0xfffffffe group=0xfffffffe atime=Sun Dec 15 00:03:20 49523574 UTC mtime=Sun Dec 15 00:03:20 49523574 UTC

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3275 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: dirent = 0x3acbce10 random.79, cb_result = DIR_CONTINUE, eod = false

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:980 :mdcache_find_keyed_reason :INODE :F_DBG :Looking for hk=c2b7f772bdd8c5c4 fsal=0x7f24e080b080 key=0xd4822902000000000100

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_48] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:3108 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Lookup by key for random.8 failed, lookup by name now

-> releasing the content lock here, and waiting for a write lock.

svc_61 --> open2 path and gets the write lock

It goes through a invalidate directory here.

Invalidate directory -> unref's all the chunks in the directory

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:471 :foo_handle_to_key :FSAL :DEBUG :Providing digest to ganesha for hashing. id=36274900, export_id=1

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:980 :mdcache_find_keyed_reason :INODE :F_DBG :Looking for hk=c2b7f772bdd8c5c4 fsal=0x7f24e080b080 key=0xd4822902000000000100

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_lru.c:559 :mdcache_lru_clean :INODE :F_DBG :Trusting op_ctx export id 1

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:44 :foo_close2 :FSAL :DEBUG :Handle: 2442805 state: (nil)

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:107 :foo_release :FSAL :DEBUG :fileId=2442805

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:44 :foo_close2 :FSAL :DEBUG :Handle: 2442805 state: (nil)

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:114 :foo_release :FSAL :DEBUG :Could not close hdl 0x0x4064e880, error Success(0)

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:750 :mdcache_new_entry :INODE :DEBUG :Adding a REGULAR_FILE, entry=0xd86a830

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:845 :mdcache_new_entry :INODE :F_DBG :New entry 0xd86a830 added with fh_hk.key hk=c2b7f772bdd8c5c4 fsal=0x7f24e080b080 key=0xd4822902000000000100

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:112 :mdcache_alloc_and_check_handle :INODE :F_DBG :open2 Created entry 0xd86a830 FSAL FOO for random.8

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1522 :mdcache_dirent_add :INODE :F_DBG :Add dir entry random.8

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:322 :mdcache_avl_insert :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Insert dir entry 0x364afd80 random.8

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:380 :mdcache_avl_insert :NFS READDIR :DEBUG :NFS READDIR: DEBUG: Already existent when inserting new dirent on entry=0xd873770 name=random.8

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:490 :mdcache_avl_insert :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Duplicate insert of random.8 v->chunk=(nil) v2->chunk=0xd690fb0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:150 :mdcache_alloc_and_check_handle :INODE :F_DBG :open2 obj attributes Request Mask=0001dfce Valid Mask=0015dfce Supported Mask=0015dfee REGULAR_FILE numlinks=0x1 size=0x0 mode=0755 owner=0xfffffffe group=0xfffffffe atime=Thu Jan 01 00:00:00 1970 UTC mtime=Wed Jul 10 09:28:30 2019 UTC

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/fsal_helper.c:418 :open2_by_name :FSAL :F_DBG :Created entry 0xd86a868 FSAL MDCACHE for random.8

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:441 :foo_handle_to_wire :FSAL :DEBUG :Providing digest to ganesha for nfs file handle. fileId=36274900, export_id=1

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/export.c:306 :foo_fs_supported_attrs :FSAL :DEBUG :supported attr mask=15DFEE

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:776 :foo_getattrs :FSAL :DEBUG :fileId=36274821

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /opt/src/src/handle.c:315 :foo_populate_attrs :FSAL :DEBUG :fileId=36274821, type=1, size=0, mode=755, owner=4294967294, group=4294967294, ctime=1205435200, atime=1205435200, mtime=1205435200

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:857 :mdcache_refresh_attrs :INODE :F_DBG :attrs obj attributes Request Mask=0015dfce Valid Mask=0015dfce Supported Mask=0015dfee DIRECTORY numlinks=0x1 size=0x0 mode=0755 owner=0xfffffffe group=0xfffffffe atime=Wed Dec 11 09:23:20 49523574 UTC mtime=Wed Dec 11 09:23:20 49523574 UTC

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:598 :mdcache_dirent_invalidate_all :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Invalidating directory for 0xd873770, clearing MDCACHE_DIR_POPULATED setting MDCACHE_TRUST_CONTENT and MDCACHE_TRUST_DIR_CHUNKS

Invalidating the dirents in the directory

Unrefs the chunk (does not clean_chunk because svc_48 has the ref )

avl_clean_trees cleans the dirents

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:612 :mdcache_avl_clean_trees :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Invalidate 0x399be410 random.23

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:171 :unchunk_dirent :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Unchunking 0x399be410 random.23

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_61] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:244 :mdcache_avl_remove :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Just freed dirent 0x399be410 from chunk 0xd690fb0 parent 0xd873770

-- Repeated pattern

svc_61 will release the lock here

svc_38 starts a READDIR on this directory and gets the write content lock and

calls dirent_invalidate_all

Wed Jul 10 09:28:30 2019 UTC 23198[none] [svc_38] /src/src/MainNFSD/nfs_rpc_dispatcher_thread.c:1332 :nfs_rpc_decode_request :DISP :DEBUG :0x35232ed0 fd 31 context 0x6bbf5b80

Wed Jul 10 09:28:30 2019 UTC 23198[none] [svc_38] /src/src/MainNFSD/nfs_worker_thread.c:713 :nfs_rpc_process_request :DISP :F_DBG :About to authenticate Prog=100003, vers=3, proc=16, xid=154636653, SVCXPRT=0x35232ed0, fd=31

Wed Jul 10 09:28:30 2019 UTC 23198[none] [svc_38] /src/src/MainNFSD/nfs_worker_thread.c:751 :nfs_rpc_process_request :DISP :F_DBG :Before SVCAUTH_CHECKSUM on SVCXPRT 0x35232ed0 fd 31

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/MainNFSD/nfs_worker_thread.c:839 :nfs_rpc_process_request :DISP :DEBUG :Request from ::ffff:10.0.138.85 for Program 100003, Version 3, Function 16 has xid=154636653

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/MainNFSD/nfs_worker_thread.c:856 :nfs_rpc_process_request :DISP :F_DBG :Current request is not duplicate or not cacheable.

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/MainNFSD/nfs_worker_thread.c:985 :nfs_rpc_process_request :DISP :M_DBG :DISP: MID DEBUG: Found export entry for path=/integtest-fileshare-bucket-vrungta-bf88s as exportid=1

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/MainNFSD/nfs_worker_thread.c:1097 :nfs_rpc_process_request :DISP :M_DBG :DISP: MID DEBUG: nfs_rpc_process_request about to call nfs_export_check_access for client ::ffff:10.0.138.85

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/support/nfs_creds.c:504 :nfs_req_creds :DISP :M_DBG :DISP: MID DEBUG: AUTH_SYS creds mapped to uid=4294967294, gid=4294967294, glen=0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/Protocols/NFS/nfs3_readdir.c:144 :nfs3_readdir :NFS READDIR :DEBUG :NFS READDIR: DEBUG: REQUEST PROCESSING: Calling nfs_Readdir handle: File Handle V3: Len=16 430000010a8582290200000000010000

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /opt/src/src/export.c:83 :foo_wire_to_host :FSAL :DEBUG :Setting length of digest for ganesha file handle. fh_desc length=10

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:980 :mdcache_find_keyed_reason :INODE :F_DBG :Looking for hk=1a3aad454037de63 fsal=0x7f24e080b080 key=0x85822902000000000100

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1018 :mdcache_find_keyed_reason :INODE :F_DBG :Found entry 0xd873770

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/Protocols/NFS/nfs3_readdir.c:183 :nfs3_readdir :NFS READDIR :DEBUG :---> NFS3_READDIR: count=16384 cookie=0 estimated_num_entries=120

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1228 :mdc_lookup :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Lookup ..

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1236 :mdc_lookup :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Lookup parent (..) of 0xd873770

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:980 :mdcache_find_keyed_reason :INODE :F_DBG :Looking for hk=aa5216ef507b1089 fsal=0x7f24e080b080 key=0x84822902000000000100

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:1018 :mdcache_find_keyed_reason :INODE :F_DBG :Found entry 0xd85c8e0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /opt/src/src/export.c:306 :foo_fs_supported_attrs :FSAL :DEBUG :supported attr mask=15DFEE

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:931 :mdcache_getattrs :INODE :F_DBG :attrs obj attributes Request Mask=000006a0 Valid Mask=0015dfce Supported Mask=0015dfee DIRECTORY numlinks=0x1 size=0x0 mode=0755 owner=0xfffffffe group=0xfffffffe atime=Wed Dec 11 09:23:20 49523574 UTC mtime=Wed Dec 11 09:23:20 49523574 UTC

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_handle.c:557 :mdcache_readdir :NFS READDIR :DEBUG :NFS READDIR: DEBUG: Calling mdcache_readdir_chunked whence=0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:2860 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Starting chunked READDIR for 0xd873770, MDCACHE_TRUST_CONTENT true, MDCACHE_TRUST_DIR_CHUNKS false

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:2867 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Flushing invalid dirent cache

------->>>> Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:598 :mdcache_dirent_invalidate_all :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Invalidating directory for 0xd873770, clearing MDCACHE_DIR_POPULATED setting MDCACHE_TRUST_CONTENT and MDCACHE_TRUST_DIR_CHUNKS

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_lru.c:2020 :lru_clean_chunk :INODE :F_DBG :Removing chunk 0xd690fb0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_lru.c:2065 :_mdcache_lru_unref_chunk :INODE :F_DBG :Freeing chunk 0xd690fb0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:612 :mdcache_avl_clean_trees :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Invalidate 0x35d0a950 random.77

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_avl.c:244 :mdcache_avl_remove :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Just freed dirent 0x35d0a950 from chunk (nil) parent (nil)

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:2895 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Readdir chunked next_ck=0x0 look_ck=0

It does the unref on the chunk again. this time it is releasing the refCount

held by svc48

svc_38 continues the readdir and when it releases the content lock -> svc48

cores.

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /opt/src/src/export.c:149 :foo_fs_supports :FSAL :DEBUG :option=21

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /opt/src/src/export.c:40 :fsal_option_to_name :FSAL :DEBUG :Option=21, to name=fso_whence_is_name

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /opt/src/src/export.c:155 :foo_fs_supports :FSAL :DEBUG :option=21 (fso_whence_is_name), supported=0

Wed Jul 10 09:28:30 2019 UTC 23198[::ffff:10.0.138.85] [svc_38] /src/src/FSAL/Stackable_FSALs/FSAL_MDCACHE/mdcache_helpers.c:2963 :mdcache_readdir_chunked :NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Readdir chunked about to populate chunk (nil) next_ck=0x0