2:33 p.m.
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/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...
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_helpers.c:3235 :mdcache_readdir_chunked
:NFS READDIR :F_DBG :NFS READDIR: FULLDEBUG: Setting next_ck=22982d6
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
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 0x39f54ba0 random.28
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 0x39f54ba0 random.28
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 0x39f54ba0 from chunk 0xd690fb0
parent 0xd873770
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 0x12fda5c0 random.2
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 0x12fda5c0 random.2
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 0x12fda5c0 from chunk 0xd690fb0
parent 0xd873770
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