Actions
Bug #17257
closedceph_test_rados_api_lock fails LibRadosLockPP.LockExclusiveDurPP
Added by Kefu Chai over 7 years ago. Updated almost 3 years ago.
Status:
Can't reproduce
Priority:
High
Assignee:
-
Category:
-
Target version:
-
% Done:
0%
Source:
Development
Tags:
Backport:
mimic,luminous
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2016-09-10T16:37:03.892 INFO:tasks.workunit.client.0.mira082.stdout: api_lock: [ RUN ] LibRadosLockEC.LockExclusiveDur 2016-09-10T16:37:03.892 INFO:tasks.workunit.client.0.mira082.stdout: api_lock: /srv/autobuild-ceph/gitbuilder.git/build/out~/ceph-11.0.0-2224-g12cba55/src/test/librados/lock.cc:224: Failure 2016-09-10T16:37:03.892 INFO:tasks.workunit.client.0.mira082.stdout: api_lock: Expected: 0 2016-09-10T16:37:03.892 INFO:tasks.workunit.client.0.mira082.stdout: api_lock: To be equal to: rados_lock_exclusive(ioctx, "foo", "TestLock", "Cookie", "", __null, 0) 2016-09-10T16:37:03.892 INFO:tasks.workunit.client.0.mira082.stdout: api_lock: Which is: -17 2016-09-10T16:37:03.892 INFO:tasks.workunit.client.0.mira082.stdout: api_lock: [ FAILED ] LibRadosLockEC.LockExclusiveDur (984 ms)
see /a/kchai-2016-09-10_15:46:37-rados-wip-kefu-testing---basic-mira/408471/teuthology.log
http://pulpito.ceph.com/kchai-2016-09-10_15:46:37-rados-wip-kefu-testing---basic-mira/408471/
and
2016-09-19T08:15:51.021 INFO:tasks.workunit.client.0.mira034.stdout: api_lock: [ RUN ] LibRadosLockPP.LockExclusiveDurPP
2016-09-19T08:15:51.021 INFO:tasks.workunit.client.0.mira034.stdout: api_lock: /srv/autobuild-ceph/gitbuilder.git/build/rpmbuild/BUILD/ceph-11.0.0/src/test/librados
/lock.cc:54: Failure
2016-09-19T08:15:51.021 INFO:tasks.workunit.client.0.mira034.stdout: api_lock: Expected: 0
2016-09-19T08:15:51.021 INFO:tasks.workunit.client.0.mira034.stdout: api_lock: To be equal to: ioctx.lock_exclusive("foo", "TestLock", "Cookie", "", __null, 0)
2016-09-19T08:15:51.021 INFO:tasks.workunit.client.0.mira034.stdout: api_lock: Which is: -17
2016-09-19T08:15:51.022 INFO:tasks.workunit.client.0.mira034.stdout: api_lock: [ FAILED ] LibRadosLockPP.LockExclusiveDurPP (1031 ms)
in http://pulpito.ceph.com/kchai-2016-09-19_07:07:02-rados-wip-kefu-testing---basic-mira/423445/
Updated by Kefu Chai over 7 years ago
rerunning at http://pulpito.ceph.com/kchai-2016-09-11_03:15:51-rados-master---basic-mira/, and it failed also with a different reason. it seems..
2016-09-11T11:35:44.131 INFO:tasks.workunit.client.0.mira037.stdout: api_list: [ RUN ] LibRadosList.EnumerateObjects 2016-09-11T11:35:44.131 INFO:tasks.workunit.client.0.mira037.stdout: api_list: /srv/autobuild-ceph/gitbuilder.git/build/rpmbuild/BUILD/ceph-11.0.0/src/test/librados/list.cc:689: Failure 2016-09-11T11:35:44.131 INFO:tasks.workunit.client.0.mira037.stdout: api_list: Value of: err_str.empty() 2016-09-11T11:35:44.131 INFO:tasks.workunit.client.0.mira037.stdout: api_list: Actual: false 2016-09-11T11:35:44.131 INFO:tasks.workunit.client.0.mira037.stdout: api_list: Expected: true
Updated by Kefu Chai over 7 years ago
test again at http://pulpito.ceph.com/kchai-2016-09-12_04:34:59-rados-master---basic-mira/ passed.
Updated by Samuel Just over 7 years ago
- Status changed from New to Can't reproduce
Updated by Sage Weil about 6 years ago
- Subject changed from ceph_test_rados_api_lock fails in qa run to ceph_test_rados_api_lock fails LibRadosLockPP.LockExclusiveDurPP (luminous)
- Status changed from Can't reproduce to 12
- Backport set to luminous
2018-04-04T04:15:11.032 INFO:tasks.workunit.client.0.smithi190.stdout: api_lock: [ RUN ] LibRadosLockPP.LockExclusiveDurPP
2018-04-04T04:15:11.032 INFO:tasks.workunit.client.0.smithi190.stdout: api_lock: /build/ceph-12.2.4-264-g6f2ebf5/src/test/librados/lock.cc:54: Failure
2018-04-04T04:15:11.032 INFO:tasks.workunit.client.0.smithi190.stdout: api_lock: Expected: 0
2018-04-04T04:15:11.032 INFO:tasks.workunit.client.0.smithi190.stdout: api_lock: To be equal to: ioctx.lock_exclusive("foo", "TestLock", "Cookie", "", __null, 0)
2018-04-04T04:15:11.032 INFO:tasks.workunit.client.0.smithi190.stdout: api_lock: Which is: -17
2018-04-04T04:15:11.032 INFO:tasks.workunit.client.0.smithi190.stdout: api_lock: [ FAILED ] LibRadosLockPP.LockExclusiveDurPP (1007 ms)
/a/yuriw-2018-04-03_19:42:03-rados-wip-yuri2-testing-2018-04-03-1604-luminous-distro-basic-smithi/2349124
client log remote/smithi190/log/ceph-client.admin.14769.log.gz
2018-04-04 04:15:10.996633 7fcc74a18980 10 librados: call oid=foo nspace=test-rados-api-smithi190-14769-24 2018-04-04 04:15:10.996643 7fcc74a18980 10 client.4388.objecter _op_submit op 0x555fe1ff8f20 2018-04-04 04:15:10.996648 7fcc74a18980 20 client.4388.objecter _calc_target epoch 32 base foo @43;test-rados-api-smithi190-14769-24 precalc_pgid 0 pgid 0.0 is_write 2018-04-04 04:15:10.996654 7fcc74a18980 20 client.4388.objecter _calc_target target foo @43;test-rados-api-smithi190-14769-24 -> pgid 43.a1893c02 2018-04-04 04:15:10.996674 7fcc74a18980 10 client.4388.objecter _calc_target raw pgid 43.a1893c02 -> actual 43.2s0 acting [4,7,5] primary 4 2018-04-04 04:15:10.996679 7fcc74a18980 20 client.4388.objecter _get_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:10.996690 7fcc74a18980 10 client.4388.objecter _op_submit oid foo '@43;test-rados-api-smithi190-14769-24' '@43;test-rados-api-smithi190-14769-24' [call lock.lock] tid 9 osd.4 2018-04-04 04:15:10.996697 7fcc74a18980 20 client.4388.objecter get_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:10.996701 7fcc74a18980 15 client.4388.objecter _session_op_assign 4 9 2018-04-04 04:15:10.996704 7fcc74a18980 15 client.4388.objecter _send_op 9 to 43.2s0 on osd.4 2018-04-04 04:15:10.996708 7fcc74a18980 1 -- 172.21.15.190:0/4133745564 --> 172.21.15.39:6804/13236 -- osd_op(unknown.0.0:9 43.2s0 43:403c9185:test-rados-api-smithi190-14769-24::foo:head [call lock.lock] snapc 0=[] ondisk+write+known_if_redirected e32) v8 -- 0x555fe1ff9fb0 con 0 2018-04-04 04:15:10.996739 7fcc74a18980 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 4 2018-04-04 04:15:10.996742 7fcc74a18980 5 client.4388.objecter 1 in flight 2018-04-04 04:15:11.000251 7fcc622a0700 1 -- 172.21.15.190:0/4133745564 <== osd.4 172.21.15.39:6804/13236 4 ==== osd_op_reply(9 foo [call] v32'1 uv1 ondisk = 0) v8 ==== 147+0+0 (2155262854 0 0) 0x7fcc54005220 con 0x555fe1ff15f0 2018-04-04 04:15:11.000279 7fcc622a0700 10 client.4388.objecter ms_dispatch 0x555fe1e20830 osd_op_reply(9 foo [call] v32'1 uv1 ondisk = 0) v8 2018-04-04 04:15:11.000286 7fcc622a0700 10 client.4388.objecter in handle_osd_op_reply 2018-04-04 04:15:11.000291 7fcc622a0700 7 client.4388.objecter handle_osd_op_reply 9 ondisk uv 1 in 43.2 attempt 0 2018-04-04 04:15:11.000294 7fcc622a0700 10 client.4388.objecter op 0 rval 0 len 0 2018-04-04 04:15:11.000296 7fcc622a0700 15 client.4388.objecter handle_osd_op_reply completed tid 9 2018-04-04 04:15:11.000298 7fcc622a0700 15 client.4388.objecter finish_op 9 2018-04-04 04:15:11.000301 7fcc622a0700 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 4 2018-04-04 04:15:11.000303 7fcc622a0700 15 client.4388.objecter _session_op_remove 4 9 2018-04-04 04:15:11.000308 7fcc622a0700 5 client.4388.objecter 0 in flight 2018-04-04 04:15:11.000317 7fcc622a0700 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:11.000322 7fcc74a18980 10 librados: Objecter returned from call r=0 2018-04-04 04:15:11.000345 7fcc74a18980 10 librados: call oid=foo nspace=test-rados-api-smithi190-14769-24 2018-04-04 04:15:11.000353 7fcc74a18980 10 client.4388.objecter _op_submit op 0x555fe1ff9fb0 2018-04-04 04:15:11.000356 7fcc74a18980 20 client.4388.objecter _calc_target epoch 32 base foo @43;test-rados-api-smithi190-14769-24 precalc_pgid 0 pgid 0.0 is_write 2018-04-04 04:15:11.000361 7fcc74a18980 20 client.4388.objecter _calc_target target foo @43;test-rados-api-smithi190-14769-24 -> pgid 43.a1893c02 2018-04-04 04:15:11.000375 7fcc74a18980 10 client.4388.objecter _calc_target raw pgid 43.a1893c02 -> actual 43.2s0 acting [4,7,5] primary 4 2018-04-04 04:15:11.000379 7fcc74a18980 20 client.4388.objecter _get_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:11.000386 7fcc74a18980 10 client.4388.objecter _op_submit oid foo '@43;test-rados-api-smithi190-14769-24' '@43;test-rados-api-smithi190-14769-24' [call lock.lock] tid 10 osd.4 2018-04-04 04:15:11.000392 7fcc74a18980 20 client.4388.objecter get_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:11.000395 7fcc74a18980 15 client.4388.objecter _session_op_assign 4 10 2018-04-04 04:15:11.000396 7fcc74a18980 15 client.4388.objecter _send_op 10 to 43.2s0 on osd.4 2018-04-04 04:15:11.000399 7fcc74a18980 1 -- 172.21.15.190:0/4133745564 --> 172.21.15.39:6804/13236 -- osd_op(unknown.0.0:10 43.2s0 43:403c9185:test-rados-api-smithi190-14769-24::foo:head [call lock.lock] snapc 0=[] ondisk+write+known_if_redirected e32) v8 -- 0x555fe1ffb040 con 0 2018-04-04 04:15:11.000423 7fcc74a18980 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 4 2018-04-04 04:15:11.000426 7fcc74a18980 5 client.4388.objecter 1 in flight 2018-04-04 04:15:11.003425 7fcc622a0700 1 -- 172.21.15.190:0/4133745564 <== osd.4 172.21.15.39:6804/13236 5 ==== osd_op_reply(10 foo [call] v32'2 uv1 ondisk = -17 ((17) File exists)) v8 ==== 147+0+0 (919667873 0 0) 0x7fcc54005e20 con 0x555fe1ff15f0 2018-04-04 04:15:11.003456 7fcc622a0700 10 client.4388.objecter ms_dispatch 0x555fe1e20830 osd_op_reply(10 foo [call] v32'2 uv1 ondisk = -17 ((17) File exists)) v8 2018-04-04 04:15:11.003462 7fcc622a0700 10 client.4388.objecter in handle_osd_op_reply 2018-04-04 04:15:11.003466 7fcc622a0700 7 client.4388.objecter handle_osd_op_reply 10 ondisk uv 1 in 43.2 attempt 0 2018-04-04 04:15:11.003470 7fcc622a0700 10 client.4388.objecter op 0 rval -17 len 0 2018-04-04 04:15:11.003472 7fcc622a0700 15 client.4388.objecter handle_osd_op_reply completed tid 10 2018-04-04 04:15:11.003473 7fcc622a0700 15 client.4388.objecter finish_op 10 2018-04-04 04:15:11.003476 7fcc622a0700 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 4 2018-04-04 04:15:11.003478 7fcc622a0700 15 client.4388.objecter _session_op_remove 4 10 2018-04-04 04:15:11.003482 7fcc622a0700 5 client.4388.objecter 0 in flight 2018-04-04 04:15:11.003489 7fcc622a0700 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:11.003496 7fcc74a18980 10 librados: Objecter returned from call r=-17 2018-04-04 04:15:11.003518 7fcc74a18980 10 librados: call oid=foo nspace=test-rados-api-smithi190-14769-24 2018-04-04 04:15:11.003524 7fcc74a18980 10 client.4388.objecter _op_submit op 0x555fe1ffb040 2018-04-04 04:15:11.003527 7fcc74a18980 20 client.4388.objecter _calc_target epoch 32 base foo @43;test-rados-api-smithi190-14769-24 precalc_pgid 0 pgid 0.0 is_write 2018-04-04 04:15:11.003531 7fcc74a18980 20 client.4388.objecter _calc_target target foo @43;test-rados-api-smithi190-14769-24 -> pgid 43.a1893c02 2018-04-04 04:15:11.003545 7fcc74a18980 10 client.4388.objecter _calc_target raw pgid 43.a1893c02 -> actual 43.2s0 acting [4,7,5] primary 4 2018-04-04 04:15:11.003549 7fcc74a18980 20 client.4388.objecter _get_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:11.003556 7fcc74a18980 10 client.4388.objecter _op_submit oid foo '@43;test-rados-api-smithi190-14769-24' '@43;test-rados-api-smithi190-14769-24' [call lock.lock] tid 11 osd.4 2018-04-04 04:15:11.003561 7fcc74a18980 20 client.4388.objecter get_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:11.003564 7fcc74a18980 15 client.4388.objecter _session_op_assign 4 11 2018-04-04 04:15:11.003565 7fcc74a18980 15 client.4388.objecter _send_op 11 to 43.2s0 on osd.4 2018-04-04 04:15:11.003568 7fcc74a18980 1 -- 172.21.15.190:0/4133745564 --> 172.21.15.39:6804/13236 -- osd_op(unknown.0.0:11 43.2s0 43:403c9185:test-rados-api-smithi190-14769-24::foo:head [call lock.lock] snapc 0=[] ondisk+write+known_if_redirected e32) v8 -- 0x555fe1ffc0d0 con 0 2018-04-04 04:15:11.003595 7fcc74a18980 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 4 2018-04-04 04:15:11.003599 7fcc74a18980 5 client.4388.objecter 1 in flight 2018-04-04 04:15:11.009841 7fcc622a0700 1 -- 172.21.15.190:0/4133745564 <== osd.4 172.21.15.39:6804/13236 6 ==== osd_op_reply(11 foo [call] v32'3 uv3 ondisk = 0) v8 ==== 147+0+0 (1769456686 0 0) 0x7fcc54006930 con 0x555fe1ff15f0 2018-04-04 04:15:11.009870 7fcc622a0700 10 client.4388.objecter ms_dispatch 0x555fe1e20830 osd_op_reply(11 foo [call] v32'3 uv3 ondisk = 0) v8 2018-04-04 04:15:11.009877 7fcc622a0700 10 client.4388.objecter in handle_osd_op_reply 2018-04-04 04:15:11.009882 7fcc622a0700 7 client.4388.objecter handle_osd_op_reply 11 ondisk uv 3 in 43.2 attempt 0 2018-04-04 04:15:11.009886 7fcc622a0700 10 client.4388.objecter op 0 rval 0 len 0 2018-04-04 04:15:11.009889 7fcc622a0700 15 client.4388.objecter handle_osd_op_reply completed tid 11 2018-04-04 04:15:11.009891 7fcc622a0700 15 client.4388.objecter finish_op 11 2018-04-04 04:15:11.009895 7fcc622a0700 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 4 2018-04-04 04:15:11.009898 7fcc622a0700 15 client.4388.objecter _session_op_remove 4 11 2018-04-04 04:15:11.009906 7fcc622a0700 5 client.4388.objecter 0 in flight 2018-04-04 04:15:11.009917 7fcc622a0700 20 client.4388.objecter put_session s=0x555fe1ff0e70 osd=4 3 2018-04-04 04:15:11.009939 7fcc74a18980 10 librados: Objecter returned from call r=0
Updated by Sage Weil almost 6 years ago
- Subject changed from ceph_test_rados_api_lock fails LibRadosLockPP.LockExclusiveDurPP (luminous) to luminous: ceph_test_rados_api_lock fails LibRadosLockPP.LockExclusiveDurPP
Updated by Sage Weil almost 6 years ago
- Subject changed from luminous: ceph_test_rados_api_lock fails LibRadosLockPP.LockExclusiveDurPP to ceph_test_rados_api_lock fails LibRadosLockPP.LockExclusiveDurPP
- Backport changed from luminous to mimic,luminous
2018-05-24T10:01:03.004 INFO:tasks.workunit.client.0.smithi124.stdout: api_lock: [ RUN ] LibRadosLockEC.LockExclusiveDur 2018-05-24T10:01:03.005 INFO:tasks.workunit.client.0.smithi124.stdout: api_lock: /build/ceph-13.1.1-65-ge8d43bc/src/test/librados/lock.cc:264: Failure 2018-05-24T10:01:03.005 INFO:tasks.workunit.client.0.smithi124.stdout: api_lock: Expected: expected 2018-05-24T10:01:03.005 INFO:tasks.workunit.client.0.smithi124.stdout: api_lock: Which is: 0 2018-05-24T10:01:03.005 INFO:tasks.workunit.client.0.smithi124.stdout: api_lock: To be equal to: wait_until(1.0s, 0.1s, expected, lock_exclusive, nullptr) 2018-05-24T10:01:03.008 INFO:tasks.workunit.client.0.smithi124.stdout: api_lock: Which is: -17 2018-05-24T10:01:03.009 INFO:tasks.workunit.client.0.smithi124.stdout: api_lock: [ FAILED ] LibRadosLockEC.LockExclusiveDur (836 ms)
/a/sage-2018-05-23_14:55:44-rados-wip-sage3-testing-2018-05-22-2126-distro-basic-smithi/2577171
Updated by Neha Ojha almost 6 years ago
2018-06-28T00:17:59.962 INFO:tasks.workunit.client.0.smithi023.stdout: api_lock: [ RUN ] LibRadosLockEC.LockExclusiveDur 2018-06-28T00:17:59.962 INFO:tasks.workunit.client.0.smithi023.stdout: api_lock: /build/ceph-14.0.0-732-gb68920d/src/test/librados/lock.cc:264: Failure 2018-06-28T00:17:59.962 INFO:tasks.workunit.client.0.smithi023.stdout: api_lock: Expected: expected 2018-06-28T00:17:59.962 INFO:tasks.workunit.client.0.smithi023.stdout: api_lock: Which is: 0 2018-06-28T00:17:59.962 INFO:tasks.workunit.client.0.smithi023.stdout: api_lock: To be equal to: wait_until(1.0s, 0.1s, expected, lock_exclusive, nullptr) 2018-06-28T00:17:59.963 INFO:tasks.workunit.client.0.smithi023.stdout: api_lock: Which is: -17 2018-06-28T00:17:59.963 INFO:tasks.workunit.client.0.smithi023.stdout: api_lock: [ FAILED ] LibRadosLockEC.LockExclusiveDur (988 ms)
/a/nojha-2018-06-27_22:32:36-rados-wip-23979-distro-basic-smithi/2715634/
Updated by Kefu Chai over 5 years ago
2018-12-06T18:10:37.797 INFO:tasks.workunit.client.0.smithi167.stdout: api_lock: /build/ceph-14.0.1-1461-g7b2d092/src/test/librados/lock.cc:38 : Failure 2018-12-06T18:10:37.797 INFO:tasks.workunit.client.0.smithi167.stdout: api_lock: Expected: expected 2018-12-06T18:10:37.797 INFO:tasks.workunit.client.0.smithi167.stdout: api_lock: Which is: 0 2018-12-06T18:10:37.797 INFO:tasks.workunit.client.0.smithi167.stdout: api_lock: To be equal to: wait_until(1.0s, 0.1s, expected, lock_exclusi ve, nullptr) 2018-12-06T18:10:37.797 INFO:tasks.workunit.client.0.smithi167.stdout: api_lock: Which is: -17 2018-12-06T18:10:37.797 INFO:tasks.workunit.client.0.smithi167.stdout: api_lock: [ FAILED ] LibRadosLock.LockExclusiveDur (1120 ms)
Updated by Sage Weil about 5 years ago
/a/sage-2019-02-03_18:58:17-rados-wip-sage2-testing-2019-02-03-1047-distro-basic-smithi/3545716
Updated by Sage Weil almost 3 years ago
- Status changed from New to Can't reproduce
Actions