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