Bug #21964: ceph_test_cls_log failures related to cls_cxx_subop_version() - Ceph - Ceph

Actions

Copy link

Bug #21964

closed

ceph_test_cls_log failures related to cls_cxx_subop_version()

Added by Casey Bodley over 6 years ago. Updated about 6 years ago.

Status:

Resolved

Priority:

Normal

Assignee:

Category:

Target version:

% Done:

Source:

Tags:

Backport:

luminous

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

[ RUN      ] cls_rgw.test_log_add_same_time
/home/cbodley/ceph/src/test/cls_log/test_cls_log.cc:144: Failure
      Expected: 10
To be equal to: (int)entries.size()
      Which is: 1
[  FAILED  ] cls_rgw.test_log_add_same_time (1180 ms)

cls_log_add() relies on cls_cxx_subop_version() to generate unique keys for log entries with the same timestamp. A change was introduced by https://github.com/ceph/ceph/pull/16617 that resets ctx->current_osd_subop_num = 0; in PrimaryLogPG::do_osd_ops() that causes all log entries in test_log_add_same_time() to use the same key:

2017-10-28 16:52:35.932 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.933 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.933 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.933 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.933 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.934 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.934 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.934 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.934 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1
2017-10-28 16:52:35.934 7f67a0deb700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509223955.932005_1.1

With that single line in PrimaryLogPG::do_osd_ops() reverted, the test passes:

2017-10-28 16:58:30.796 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.1
2017-10-28 16:58:30.796 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.5
2017-10-28 16:58:30.796 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.9
2017-10-28 16:58:30.796 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.13
2017-10-28 16:58:30.797 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.17
2017-10-28 16:58:30.797 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.21
2017-10-28 16:58:30.797 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.25
2017-10-28 16:58:30.797 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.29
2017-10-28 16:58:30.798 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.33
2017-10-28 16:58:30.798 7ff97366c700 20 <cls> /home/cbodley/ceph/src/cls/log/cls_log.cc:123: storing entry at 1_1509224310.795312_1.37

Related issues 2 (0 open — 2 closed)