Project

General

Profile

Actions
Copy link

Bug #51846

open

rados/test.sh: LibRadosList.ListObjectsCursor did not complete.

Added by Sridhar Seshasayee almost 3 years ago. Updated about 2 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

/a/nojha-2021-07-22_18:00:50-rados-wip-sseshasa-testing-2021-07-14-1320-distro-basic-smithi/6287310
/a/nojha-2021-07-21_18:05:51-rados-wip-sseshasa-testing-2021-07-14-1320-distro-basic-smithi/6285172

Logs from JobID: 6287310

The logs of the api_list test abruptly ends after a seek shown below. The test is presumably hung for some reason.

2021-07-22T18:58:56.346 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: [ RUN ] LibRadosList.ListObjectsCursor
2021-07-22T18:58:56.347 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: x cursor=MIN
2021-07-22T18:58:56.347 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=1 cursor=7:02547ec2:::1:head
2021-07-22T18:58:56.347 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=10 cursor=7:52ea6a34:::10:head
2021-07-22T18:58:56.348 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=13 cursor=7:566253c9:::13:head
2021-07-22T18:58:56.348 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=7 cursor=7:5c6b0b28:::7:head
2021-07-22T18:58:56.348 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=14 cursor=7:62a1935d:::14:head
2021-07-22T18:58:56.348 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=0 cursor=7:6cac518f:::0:head
2021-07-22T18:58:56.349 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=15 cursor=7:863748b0:::15:head
2021-07-22T18:58:56.349 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=11 cursor=7:89d3ae78:::11:head
2021-07-22T18:58:56.349 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=5 cursor=7:b29083e3:::5:head
2021-07-22T18:58:56.349 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=8 cursor=7:bd63b0f1:::8:head
2021-07-22T18:58:56.350 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=6 cursor=7:c4fdafeb:::6:head
2021-07-22T18:58:56.350 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=3 cursor=7:cfc208b3:::3:head
2021-07-22T18:58:56.350 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=4 cursor=7:d83876eb:::4:head
2021-07-22T18:58:56.350 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=12 cursor=7:de5d7c5f:::12:head
2021-07-22T18:58:56.350 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=9 cursor=7:e960b815:::9:head
2021-07-22T18:58:56.351 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > oid=2 cursor=7:f905c69b:::2:head
2021-07-22T18:58:56.351 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: FIRST> seek to MIN oid=1
2021-07-22T18:58:56.351 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=1 cursor=7:02547ec2:::1:head
2021-07-22T18:58:56.351 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:02547ec2:::1:head
2021-07-22T18:58:56.352 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:02547ec2:::1:head -> 1
2021-07-22T18:58:56.352 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=10 cursor=7:52ea6a34:::10:head
2021-07-22T18:58:56.352 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:52ea6a34:::10:head
2021-07-22T18:58:56.353 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:52ea6a34:::10:head -> 10
2021-07-22T18:58:56.353 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=13 cursor=7:566253c9:::13:head
2021-07-22T18:58:56.353 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:566253c9:::13:head
2021-07-22T18:58:56.353 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:566253c9:::13:head -> 13
2021-07-22T18:58:56.353 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=7 cursor=7:5c6b0b28:::7:head
2021-07-22T18:58:56.354 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:5c6b0b28:::7:head
2021-07-22T18:58:56.354 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:5c6b0b28:::7:head -> 7
2021-07-22T18:59:05.777 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=14 cursor=7:62a1935d:::14:head
2021-07-22T18:59:05.777 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:62a1935d:::14:head
2021-07-22T18:59:05.777 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:62a1935d:::14:head -> 14
2021-07-22T18:59:05.778 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=0 cursor=7:6cac518f:::0:head
2021-07-22T18:59:05.778 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:6cac518f:::0:head
2021-07-22T18:59:05.778 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:6cac518f:::0:head -> 0
2021-07-22T18:59:05.778 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=15 cursor=7:863748b0:::15:head
2021-07-22T18:59:05.778 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:863748b0:::15:head
2021-07-22T18:59:05.779 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:863748b0:::15:head -> 15
2021-07-22T18:59:05.779 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=11 cursor=7:89d3ae78:::11:head
2021-07-22T18:59:05.779 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:89d3ae78:::11:head
2021-07-22T18:59:05.779 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:89d3ae78:::11:head -> 11
2021-07-22T18:59:05.780 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=5 cursor=7:b29083e3:::5:head
2021-07-22T18:59:05.780 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:b29083e3:::5:head
2021-07-22T18:59:05.780 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:b29083e3:::5:head -> 5
2021-07-22T18:59:05.780 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=8 cursor=7:bd63b0f1:::8:head
2021-07-22T18:59:05.781 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:bd63b0f1:::8:head
2021-07-22T18:59:05.781 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:bd63b0f1:::8:head -> 8
2021-07-22T18:59:05.781 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=6 cursor=7:c4fdafeb:::6:head
2021-07-22T18:59:05.781 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:c4fdafeb:::6:head
2021-07-22T18:59:05.782 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:c4fdafeb:::6:head -> 6
2021-07-22T18:59:05.782 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=3 cursor=7:cfc208b3:::3:head
2021-07-22T18:59:05.782 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:cfc208b3:::3:head
2021-07-22T18:59:05.782 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:cfc208b3:::3:head -> 3
2021-07-22T18:59:05.782 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=4 cursor=7:d83876eb:::4:head
2021-07-22T18:59:05.783 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:d83876eb:::4:head
2021-07-22T18:59:05.783 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:d83876eb:::4:head -> 4
2021-07-22T18:59:05.783 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=12 cursor=7:de5d7c5f:::12:head
2021-07-22T18:59:05.783 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:de5d7c5f:::12:head
2021-07-22T18:59:05.783 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:de5d7c5f:::12:head -> 12
2021-07-22T18:59:05.784 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=9 cursor=7:e960b815:::9:head
2021-07-22T18:59:05.784 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:e960b815:::9:head
2021-07-22T18:59:05.784 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:e960b815:::9:head -> 9
2021-07-22T18:59:05.784 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : oid=2 cursor=7:f905c69b:::2:head
2021-07-22T18:59:05.785 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:f905c69b:::2:head
2021-07-22T18:59:05.785 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:f905c69b:::2:head -> 2
2021-07-22T18:59:05.785 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:f905c69b:::2:head
2021-07-22T18:59:05.785 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:f905c69b:::2:head expected=7:f905c69b:::2:head
2021-07-22T18:59:05.785 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:f905c69b:::2:head -> 2
2021-07-22T18:59:05.786 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=2 expected=2
2021-07-22T18:59:05.786 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:e960b815:::9:head
2021-07-22T18:59:05.786 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:e960b815:::9:head expected=7:e960b815:::9:head
2021-07-22T18:59:05.786 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:e960b815:::9:head -> 9
2021-07-22T18:59:05.787 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=9 expected=9
2021-07-22T18:59:05.787 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:566253c9:::13:head
2021-07-22T18:59:05.787 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:566253c9:::13:head expected=7:566253c9:::13:head
2021-07-22T18:59:05.788 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:566253c9:::13:head -> 13
2021-07-22T18:59:05.788 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=13 expected=13
2021-07-22T18:59:05.788 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:02547ec2:::1:head
2021-07-22T18:59:05.788 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:02547ec2:::1:head expected=7:02547ec2:::1:head
2021-07-22T18:59:05.788 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:02547ec2:::1:head -> 1
2021-07-22T18:59:05.789 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=1 expected=1
2021-07-22T18:59:05.789 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:6cac518f:::0:head
2021-07-22T18:59:05.789 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:6cac518f:::0:head expected=7:6cac518f:::0:head
2021-07-22T18:59:05.789 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:6cac518f:::0:head -> 0
2021-07-22T18:59:05.790 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=0 expected=0
2021-07-22T18:59:05.790 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:62a1935d:::14:head
2021-07-22T18:59:05.790 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:62a1935d:::14:head expected=7:62a1935d:::14:head
2021-07-22T18:59:05.790 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:62a1935d:::14:head -> 14
2021-07-22T18:59:05.790 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=14 expected=14
2021-07-22T18:59:05.791 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:de5d7c5f:::12:head
2021-07-22T18:59:05.791 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:de5d7c5f:::12:head expected=7:de5d7c5f:::12:head
2021-07-22T18:59:05.791 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:de5d7c5f:::12:head -> 12
2021-07-22T18:59:05.791 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=12 expected=12
2021-07-22T18:59:05.791 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:d83876eb:::4:head
2021-07-22T18:59:05.792 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : cursor()=7:d83876eb:::4:head expected=7:d83876eb:::4:head
2021-07-22T18:59:05.792 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: > 7:d83876eb:::4:head -> 4
2021-07-22T18:59:05.792 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : entry=4 expected=4
2021-07-22T18:59:05.792 INFO:tasks.workunit.client.0.smithi115.stdout: api_list: : seek to 7:cfc208b3:::3:head

All the other tests succeeded. Much later in the logs, the wait_for_recovery check fails:

2021-07-21T19:55:12.224 INFO:tasks.thrashosds.thrasher:Traceback (most recent call last):
File "/home/teuthworker/src/git.ceph.com_ceph-c_f81345ca72228f2b22752a42ef3d4cfb048530bb/qa/tasks/ceph_manager.py", line 188, in wrapper
return func(self)
File "/home/teuthworker/src/git.ceph.com_ceph-c_f81345ca72228f2b22752a42ef3d4cfb048530bb/qa/tasks/ceph_manager.py", line 1404, in _do_thrash
timeout=self.config.get('timeout')
File "/home/teuthworker/src/git.ceph.com_ceph-c_f81345ca72228f2b22752a42ef3d4cfb048530bb/qa/tasks/ceph_manager.py", line 2804, in wait_for_recovery
'wait_for_recovery: failed before timeout expired'
AssertionError: wait_for_recovery: failed before timeout expired

2021-07-21T19:55:12.224 ERROR:tasks.thrashosds.thrasher:exception:
Traceback (most recent call last):
File "/home/teuthworker/src/git.ceph.com_ceph-c_f81345ca72228f2b22752a42ef3d4cfb048530bb/qa/tasks/ceph_manager.py", line 1279, in do_thrash
self._do_thrash()
File "/home/teuthworker/src/git.ceph.com_ceph-c_f81345ca72228f2b22752a42ef3d4cfb048530bb/qa/tasks/ceph_manager.py", line 188, in wrapper
return func(self)
File "/home/teuthworker/src/git.ceph.com_ceph-c_f81345ca72228f2b22752a42ef3d4cfb048530bb/qa/tasks/ceph_manager.py", line 1404, in _do_thrash
timeout=self.config.get('timeout')
File "/home/teuthworker/src/git.ceph.com_ceph-c_f81345ca72228f2b22752a42ef3d4cfb048530bb/qa/tasks/ceph_manager.py", line 2804, in wait_for_recovery
'wait_for_recovery: failed before timeout expired'
AssertionError: wait_for_recovery: failed before timeout expired

The test performs a seek within a loop but it looks like the seek probably didn't complete:

TEST_F(LibRadosList, ListObjectsCursor) {
...
while (p != cursor_to_obj.rend()) {
cout << ": seek to " << p->first << std::endl;
rados_object_list_cursor cursor;
rados_object_list_cursor oid(p->first);
rados_nobjects_list_seek_cursor(ctx, oid);
...
}

Actions
Copy link

Also available in: Atom PDF