Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ztest: hash lock, keystore lock inversion #7112

Closed
behlendorf opened this issue Feb 1, 2018 · 0 comments
Closed

ztest: hash lock, keystore lock inversion #7112

behlendorf opened this issue Feb 1, 2018 · 0 comments
Labels
Component: Test Suite Indicates an issue with the test framework or a test case

Comments

@behlendorf
Copy link
Contributor

System information

Type Version/Name
Distribution Name any
Distribution Version any
Linux Kernel any
Architecture any
ZFS Version zfs-0.7.0-270-ga73c949
SPL Version spl-0.7.0-24-g23602fd

Describe the problem you're observing

Lock inversion introduced by 0873bb6 and encryption.

Thread 428 (Thread 0x7f4029e4a700 (LWP 25837)):
#0  0x00007f4032ef5837 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0
#1  0x00007f4033c84e95 in rw_enter (rwlp=0x29d45f8, rw=<optimized out>) at kernel.c:260
#2  0x00007f4033cd2e7e in spa_keystore_dsl_key_rele (spa=spa@entry=0x29d3460, dck=0x2bc6dc0, tag=tag@entry=0x7f4033dd06a0 <__func__.17161>) at ../../module/zfs/dsl_crypt.c:681
#3  0x00007f4033cd5d64 in spa_do_crypt_mac_abd (generate=generate@entry=B_FALSE, spa=spa@entry=0x29d3460, dsobj=<optimized out>, abd=abd@entry=0x7f4018000fd0, datalen=datalen@entry=2048, mac=mac@entry=0x7f40181457ac ":i8\377*\355G\361\305\324Du0\206\304r") at ../../module/zfs/dsl_crypt.c:2532
#4  0x00007f4033c926ef in arc_hdr_authenticate (dsobj=<optimized out>, spa=0x29d3460, hdr=0x7f4018145650) at ../../module/zfs/arc.c:1896
#5  arc_fill_hdr_crypt (noauth=<optimized out>, dsobj=<optimized out>, spa=0x29d3460, hash_lock=<optimized out>, hdr=0x7f4018145650) at ../../module/zfs/arc.c:2031
#6  arc_buf_fill (buf=0x7f400c0d6f50, spa=spa@entry=0x29d3460, dsobj=dsobj@entry=107, flags=ARC_FILL_LOCKED) at ../../module/zfs/arc.c:2132
#7  0x00007f4033c92ccd in arc_buf_alloc_impl (hdr=hdr@entry=0x7f4018145650, spa=0x29d3460, dsobj=107, encrypted=<optimized out>, compressed=B_FALSE, noauth=B_FALSE, fill=B_TRUE, ret=0x7f40180051f0, tag=<optimized out>) at ../../module/zfs/arc.c:2892
#8  0x00007f4033c9652f in arc_read_done (zio=0x7f401809b810) at ../../module/zfs/arc.c:5813
#9  0x00007f4033d8fb30 in zio_done (zio=0x7f401809b810) at ../../module/zfs/zio.c:4398
#10 0x00007f4033d8d02b in __zio_execute (zio=0x7f401809b810) at ../../module/zfs/zio.c:1936
#11 zio_execute (zio=0x7f401809b810) at ../../module/zfs/zio.c:1854
#12 0x00007f4033c86ae6 in taskq_thread (arg=0x29fd380) at taskq.c:233
#13 0x00007f4032ef036d in start_thread () from /lib64/libpthread.so.0
#14 0x00007f4032c28b9f in clone () from /lib64/libc.so.6

Thread 292 (Thread 0x7f3fe52f7700 (LWP 26880)):
#0  0x00007f4032efa09d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f4032ef2e23 in pthread_mutex_lock () from /lib64/libpthread.so.0
#2  0x00007f4033c84c89 in mutex_enter (mp=mp@entry=0x7f40340a0070 <buf_hash_table+116368>) at kernel.c:207
#3  0x00007f4033c975f6 in arc_buf_access (buf=0x7f4020038c90) at ../../module/zfs/arc.c:5641
#4  0x00007f4033ca042a in __dbuf_hold_impl (dh=<optimized out>) at ../../module/zfs/dbuf.c:2981
#5  0x00007f4033ca09ec in dbuf_hold_impl (dn=<optimized out>, level=<optimized out>, blkid=<optimized out>, fail_sparse=<optimized out>, fail_uncached=<optimized out>, tag=<optimized out>, dbp=0x7f3fe52f3590) at ../../module/zfs/dbuf.c:3046
#6  0x00007f4033ca0a3b in dbuf_hold_level (dn=<optimized out>, level=<optimized out>, blkid=<optimized out>, tag=<optimized out>) at ../../module/zfs/dbuf.c:3089
#7  0x00007f4033ca0a7d in dbuf_hold (dn=<optimized out>, blkid=<optimized out>, tag=<optimized out>) at ../../module/zfs/dbuf.c:3082
#8  0x00007f4033ca6878 in dmu_buf_hold_noread_by_dnode (dn=0x7f4020029c70, offset=<optimized out>, tag=0x0, dbp=0x7f3fe52f3630) at ../../module/zfs/dmu.c:155
#9  0x00007f4033ca69f2 in dmu_buf_hold_by_dnode (dn=<optimized out>, offset=offset@entry=16384, tag=tag@entry=0x0, dbp=dbp@entry=0x7f3fe52f3630, flags=flags@entry=1) at ../../module/zfs/dmu.c:205
#10 0x00007f4033d7a270 in zap_get_leaf_byblk (blkid=1, tx=tx@entry=0x0, lt=lt@entry=0, lp=lp@entry=0x7f3fe52f36d8, zap=<optimized out>, zap=<optimized out>) at ../../module/zfs/zap.c:530
#11 0x00007f4033d7a49d in zap_deref_leaf (zap=0x7f40200503d0, h=<optimized out>, tx=0x0, lt=0, lp=0x7f3fe52f36d8) at ../../module/zfs/zap.c:612
#12 0x00007f4033d7af4c in fzap_lookup (zn=zn@entry=0x2e617e0, integer_size=integer_size@entry=8, num_integers=num_integers@entry=1, buf=buf@entry=0x7f3fe52f3868, realname=realname@entry=0x0, rn_len=rn_len@entry=0, ncp=0x0) at ../../module/zfs/zap.c:799
#13 0x00007f4033d7f25b in zap_lookup_impl (zap=0x7f40200503d0, name=name@entry=0x7f4033dcf823 "DSL_CRYPTO_ROOT_DDOBJ", integer_size=integer_size@entry=8, num_integers=num_integers@entry=1, buf=buf@entry=0x7f3fe52f3868, mt=mt@entry=(unknown: 0), realname=0x0, rn_len=0, ncp=0x0) at ../../module/zfs/zap_micro.c:920
#14 0x00007f4033d7fd5c in zap_lookup_norm (os=<optimized out>, zapobj=<optimized out>, name=0x7f4033dcf823 "DSL_CRYPTO_ROOT_DDOBJ", integer_size=8, num_integers=1, buf=0x7f3fe52f3868, mt=(unknown: 0), realname=0x0, rn_len=0, ncp=0x0) at ../../module/zfs/zap_micro.c:959
#15 0x00007f4033d7fdb1 in zap_lookup (os=<optimized out>, zapobj=<optimized out>, name=<optimized out>, integer_size=<optimized out>, num_integers=<optimized out>, buf=<optimized out>) at ../../module/zfs/zap_micro.c:901
#16 0x00007f4033cd1cf6 in spa_keystore_wkey_hold_dd (spa=spa@entry=0x29d3460, dd=dd@entry=0x2a1c000, wkey_out=wkey_out@entry=0x7f3fe52f3920, tag=<optimized out>) at ../../module/zfs/dsl_crypt.c:406
#17 0x00007f4033cd1e64 in spa_keystore_dsl_key_hold_dd (spa=spa@entry=0x29d3460, dd=dd@entry=0x2a1c000, dck_out=dck_out@entry=0x2bf1978, tag=0x2bf1950) at ../../module/zfs/dsl_crypt.c:642
#18 0x00007f4033cd3c31 in spa_keystore_create_mapping_impl (spa=0x29d3460, dsobj=146, dd=0x2a1c000, tag=tag@entry=0x2ed6810) at ../../module/zfs/dsl_crypt.c:917
#19 0x00007f4033cd3d19 in spa_keystore_create_mapping (spa=<optimized out>, ds=ds@entry=0x2ed6810, tag=tag@entry=0x2ed6810) at ../../module/zfs/dsl_crypt.c:965
#20 0x00007f4033cc1d38 in dsl_dataset_hold_obj_flags (dp=dp@entry=0x2a294c0, dsobj=146, flags=flags@entry=DS_HOLD_FLAG_DECRYPT, tag=tag@entry=0x41b140 <__func__.22325>, dsp=dsp@entry=0x7f3fe52f3ab8) at ../../module/zfs/dsl_dataset.c:552
#21 0x00007f4033cc259b in dsl_dataset_hold_flags (dp=0x2a294c0, name=name@entry=0x7f3fe52f3bf0 "ztest/temp_10", flags=flags@entry=DS_HOLD_FLAG_DECRYPT, tag=tag@entry=0x41b140 <__func__.22325>, dsp=dsp@entry=0x7f3fe52f3b60) at ../../module/zfs/dsl_dataset.c:586
#22 0x00007f4033cc3cd8 in dsl_dataset_own (dp=<optimized out>, name=name@entry=0x7f3fe52f3bf0 "ztest/temp_10", flags=flags@entry=DS_HOLD_FLAG_DECRYPT, tag=tag@entry=0x41b140 <__func__.22325>, dsp=dsp@entry=0x7f3fe52f3b60) at ../../module/zfs/dsl_dataset.c:649
#23 0x00007f4033caedf7 in dmu_objset_own (name=name@entry=0x7f3fe52f3bf0 "ztest/temp_10", type=type@entry=DMU_OST_OTHER, readonly=readonly@entry=B_FALSE, decrypt=decrypt@entry=B_TRUE, tag=tag@entry=0x41b140 <__func__.22325>, osp=osp@entry=0x7f3fe52f3be0) at ../../module/zfs/dmu_objset.c:698
#24 0x000000000040a826 in ztest_dmu_objset_own (name=name@entry=0x7f3fe52f3bf0 "ztest/temp_10", type=type@entry=DMU_OST_OTHER, readonly=readonly@entry=B_FALSE, tag=tag@entry=0x41b140 <__func__.22325>, osp=osp@entry=0x7f3fe52f3be0, decrypt=B_TRUE) at ztest.c:1213
#25 0x0000000000414011 in ztest_dmu_objset_create_destroy (zd=<optimized out>, id=10) at ztest.c:3800
#26 0x000000000040d1a1 in ztest_execute (id=10, zi=<optimized out>, test=10) at ztest.c:6299
#27 ztest_thread (arg=0xa) at ztest.c:6346
#28 0x00007f4032ef036d in start_thread () from /lib64/libpthread.so.0
#29 0x00007f4032c28b9f in clone () from /lib64/libc.so.6

Thread 40 (Thread 0x7f4028b80700 (LWP 25853)):
#0  0x00007f4032ef5837 in pthread_rwlock_wrlock () from /lib64/libpthread.so.0
#1  0x00007f4033c84e95 in rw_enter (rwlp=0x29d45f8, rw=<optimized out>) at kernel.c:260
#2  0x00007f4033cd2e7e in spa_keystore_dsl_key_rele (spa=spa@entry=0x29d3460, dck=0x2d41cb0, tag=tag@entry=0x7f4033dd0680 <__func__.17182>) at ../../module/zfs/dsl_crypt.c:681
#3  0x00007f4033cd5fee in spa_do_crypt_abd (encrypt=encrypt@entry=B_TRUE, spa=spa@entry=0x29d3460, dsobj=<optimized out>, bp=bp@entry=0x7f4014005b90, txgid=<optimized out>, datalen=datalen@entry=4096, pabd=0x7f401c06c050, cabd=0x7f401c070150, iv=0x7f4028b7cca4 "\277^}\352vY^\"\322\\\313y\225\067\251/F\r\331r<\206\205\251\033\260\266\375P\300\006\034@\177", mac=0x7f4028b7ccb0 "\225\067\251/F\r\331r<\206\205\251\033\260\266\375P\300\006\034@\177", salt=0x7f4028b7cc9c "\r\211w\371,,溿^}\352vY^\"\322\\\313y\225\067\251/F\r\331r<\206\205\251\033\260\266\375P\300\006\034@\177", no_crypt=0x7f4028b7cc98) at ../../module/zfs/dsl_crypt.c:2643
#4  0x00007f4033d8a7af in zio_encrypt (zio=0x7f402400c250) at ../../module/zfs/zio.c:3826
#5  0x00007f4033d8d02b in __zio_execute (zio=0x7f402400c250) at ../../module/zfs/zio.c:1936
#6  zio_execute (zio=0x7f402400c250) at ../../module/zfs/zio.c:1854
#7  0x00007f4033c86ae6 in taskq_thread (arg=0x29fda20) at taskq.c:233
#8  0x00007f4032ef036d in start_thread () from /lib64/libpthread.so.0
#9  0x00007f4032c28b9f in clone () from /lib64/libc.so.6

Describe how to reproduce the problem

Occasionally observed when running ztest, thus far never during normal usage.

@behlendorf behlendorf added the Component: Test Suite Indicates an issue with the test framework or a test case label Feb 1, 2018
behlendorf added a commit to behlendorf/zfs that referenced this issue Feb 1, 2018
A deadlock is possible between the hash_lock and keystore lock
since they may not be taken in the same order.  For this to occur
two blocks need to hash to the same bucket.  Full backtraces
showing the deadlock are available in issue openzfs#7112.

Resolve the issue by using mutex_tryenter() in arc_buf_access()
which was introduced in 0873bb6.  The reasoning being that a
hash collision here is unlikely and updating the access info
is not required for correctness.  Since a collision is also
unlikely it's not expected to have any performance impact.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
TEST_ZTEST_TIMEOUT=3600
Issue openzfs#7112
behlendorf added a commit to behlendorf/zfs that referenced this issue Feb 1, 2018
A deadlock is possible between the hash_lock and keystore lock
since they may not be taken in the same order.  For this to occur
two blocks need to hash to the same bucket.  Full backtraces
showing the deadlock are available in issue openzfs#7112.

Resolve the issue by using mutex_tryenter() in arc_buf_access()
which was introduced in 0873bb6.  The reasoning being that a
hash collision here is unlikely and updating the access info
is not required for correctness.  Since a collision is also
unlikely it's not expected to have any performance impact.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
TEST_ZTEST_TIMEOUT=3600
Issue openzfs#7112
behlendorf added a commit to behlendorf/zfs that referenced this issue Feb 2, 2018
The keystore.sk_dk_lock should not be held while performing I/O.
Drop the lock when reading from disk and update the code so
they the first successful caller adds the lock.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
TEST_ZTEST_TIMEOUT=3600
Issue openzfs#7112
behlendorf added a commit to behlendorf/zfs that referenced this issue Feb 2, 2018
The keystore.sk_dk_lock should not be held while performing I/O.
Drop the lock when reading from disk and update the code so
they the first successful caller adds the lock.

Improve error handling in spa_keystore_create_mapping_impl().

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
TEST_ZTEST_TIMEOUT=3600
Issue openzfs#7112
Nasf-Fan pushed a commit to Nasf-Fan/zfs that referenced this issue Feb 13, 2018
The keystore.sk_dk_lock should not be held while performing I/O.
Drop the lock when reading from disk and update the code so
they the first successful caller adds the key.

Improve error handling in spa_keystore_create_mapping_impl().

Reviewed by: Thomas Caputi <tcaputi@datto.com>
Reviewed-by: RageLtMan <rageltman@sempervictus>
Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Closes openzfs#7112
Closes openzfs#7115
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Component: Test Suite Indicates an issue with the test framework or a test case
Projects
None yet
Development

No branches or pull requests

1 participant