Actions
Bug #62229
openlog_channel(cluster) log [WRN] : client.7719 does not advance its oldest_client_tid (1), 1004 completed requests recorded in session
% Done:
0%
Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
Labels (FS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
Test failure: test_client_release_bug (tasks.cephfs.test_client_limits.TestClientLimits)
2023-07-25T15:26:25.043 INFO:teuthology.orchestra.run.smithi038.stderr:2023-07-25T15:26:25.031+0000 7ff4275ff700 1 -- 172.21.15.38:0/2708588022 shutdown_connections 2023-07-25T15:26:25.043 INFO:teuthology.orchestra.run.smithi038.stderr:2023-07-25T15:26:25.032+0000 7ff4275ff700 1 -- 172.21.15.38:0/2708588022 wait complete. 2023-07-25T15:26:25.063 INFO:tasks.cephfs_test_runner:test_client_release_bug (tasks.cephfs.test_client_limits.TestClientLimits) ... ERROR 2023-07-25T15:26:25.063 INFO:tasks.cephfs_test_runner: 2023-07-25T15:26:25.064 INFO:tasks.cephfs_test_runner:====================================================================== 2023-07-25T15:26:25.064 INFO:tasks.cephfs_test_runner:ERROR: test_client_release_bug (tasks.cephfs.test_client_limits.TestClientLimits) 2023-07-25T15:26:25.064 INFO:tasks.cephfs_test_runner:---------------------------------------------------------------------- 2023-07-25T15:26:25.064 INFO:tasks.cephfs_test_runner:Traceback (most recent call last): 2023-07-25T15:26:25.065 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_a5d48e8c688c2543997a98b8acbae2ce9635578c/qa/tasks/cephfs/test_client_limits.py", line 208, in test_client_release_bug 2023-07-25T15:26:25.065 INFO:tasks.cephfs_test_runner: self.wait_for_health("MDS_CLIENT_LATE_RELEASE", session_timeout + 10) 2023-07-25T15:26:25.065 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_a5d48e8c688c2543997a98b8acbae2ce9635578c/qa/tasks/ceph_test_case.py", line 184, in wait_for_health 2023-07-25T15:26:25.065 INFO:tasks.cephfs_test_runner: self.wait_until_true(seen_health_warning, timeout) 2023-07-25T15:26:25.065 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_a5d48e8c688c2543997a98b8acbae2ce9635578c/qa/tasks/ceph_test_case.py", line 231, in wait_until_true 2023-07-25T15:26:25.065 INFO:tasks.cephfs_test_runner: raise TestTimeoutError("Timed out after {0}s and {1} retries".format(elapsed, retry_count)) 2023-07-25T15:26:25.066 INFO:tasks.cephfs_test_runner:tasks.ceph_test_case.TestTimeoutError: Timed out after 70s and 0 retries 2023-07-25T15:26:25.066 INFO:tasks.cephfs_test_runner: 2023-07-25T15:26:25.066 INFO:tasks.cephfs_test_runner:---------------------------------------------------------------------- 2023-07-25T15:26:25.066 INFO:tasks.cephfs_test_runner:Ran 9 tests in 748.706s 2023-07-25T15:26:25.066 INFO:tasks.cephfs_test_runner: 2023-07-25T15:26:25.067 INFO:tasks.cephfs_test_runner:FAILED (errors=1) 2023-07-25T15:26:25.067 INFO:tasks.cephfs_test_runner: 2023-07-25T15:26:25.067 INFO:tasks.cephfs_test_runner:====================================================================== 2023-07-25T15:26:25.067 INFO:tasks.cephfs_test_runner:ERROR: test_client_release_bug (tasks.cephfs.test_client_limits.TestClientLimits) 2023-07-25T15:26:25.067 INFO:tasks.cephfs_test_runner:---------------------------------------------------------------------- 2023-07-25T15:26:25.068 INFO:tasks.cephfs_test_runner:Traceback (most recent call last): 2023-07-25T15:26:25.068 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_a5d48e8c688c2543997a98b8acbae2ce9635578c/qa/tasks/cephfs/test_client_limits.py", line 208, in test_client_release_bug 2023-07-25T15:26:25.068 INFO:tasks.cephfs_test_runner: self.wait_for_health("MDS_CLIENT_LATE_RELEASE", session_timeout + 10) 2023-07-25T15:26:25.068 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_a5d48e8c688c2543997a98b8acbae2ce9635578c/qa/tasks/ceph_test_case.py", line 184, in wait_for_health 2023-07-25T15:26:25.068 INFO:tasks.cephfs_test_runner: self.wait_until_true(seen_health_warning, timeout) 2023-07-25T15:26:25.069 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_a5d48e8c688c2543997a98b8acbae2ce9635578c/qa/tasks/ceph_test_case.py", line 231, in wait_until_true 2023-07-25T15:26:25.069 INFO:tasks.cephfs_test_runner: raise TestTimeoutError("Timed out after {0}s and {1} retries".format(elapsed, retry_count)) 2023-07-25T15:26:25.069 INFO:tasks.cephfs_test_runner:tasks.ceph_test_case.TestTimeoutError: Timed out after 70s and 0 retries 2023-07-25T15:26:25.069 INFO:tasks.cephfs_test_runner:
Updated by Xiubo Li 9 months ago
- Status changed from New to Fix Under Review
- Pull request ID set to 52692
The test_client_oldest_tid test case was triggered first:
2023-07-25T15:20:29.281 INFO:tasks.cephfs_test_runner:Starting test: test_client_oldest_tid (tasks.cephfs.test_client_limits.TestClientLimits) 2023-07-25T15:20:29.281 DEBUG:teuthology.orchestra.run.smithi038:> sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 120 ceph --cluster ceph log 'Starting test tasks.cephfs.test_client_limits.TestClientLimits.test_client_oldest_tid' ... 2023-07-25T15:20:29.787 INFO:teuthology.orchestra.run.smithi038.stderr:2023-07-25T15:20:29.772+0000 7f205cfff700 1 -- 172.21.15.38:0/278982153 --> [v2:172.21.15.38:3300/0,v1:172.21.15.38:6789/0] -- mon_command({"prefix": "log", "logtext": ["Starting test tasks.cephfs.test_client_limits.TestClientLimits.test_client_oldest_tid"]} v 0) v1 -- 0x7f20580cf890 con 0x7f205813d950 2023-07-25T15:20:30.263 INFO:teuthology.orchestra.run.smithi038.stderr:2023-07-25T15:20:30.247+0000 7f2046ffd700 1 -- 172.21.15.38:0/278982153 <== mon.0 v2:172.21.15.38:3300/0 7 ==== mon_command_ack([{"prefix": "log", "logtext": ["Starting test tasks.cephfs.test_client_limits.TestClientLimits.test_client_oldest_tid"]}]=0 v375) v1 ==== 153+0+0 (secure 0 0 0) 0x7f2050057b70 con 0x7f205813d950 ... 2023-07-25T15:21:33.423 DEBUG:teuthology.orchestra.run.smithi038:> sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 120 ceph --cluster ceph log 'Ended test tasks.cephfs.test_client_limits.TestClientLimits.test_client_oldest_tid' ... 2023-07-25T15:21:33.933 INFO:teuthology.orchestra.run.smithi038.stderr:2023-07-25T15:21:33.917+0000 7f79ee39d700 1 -- 172.21.15.38:0/1069934743 --> [v2:172.21.15.38:3300/0,v1:172.21.15.38:6789/0] -- mon_command({"prefix": "log", "logtext": ["Ended test tasks.cephfs.test_client_limits.TestClientLimits.test_client_oldest_tid"]} v 0) v1 -- 0x7f79e815f5f0 con 0x7f79e80b1fc0 2023-07-25T15:21:34.773 INFO:teuthology.orchestra.run.smithi038.stderr:2023-07-25T15:21:34.757+0000 7f79ddffb700 1 -- 172.21.15.38:0/1069934743 <== mon.0 v2:172.21.15.38:3300/0 7 ==== mon_command_ack([{"prefix": "log", "logtext": ["Ended test tasks.cephfs.test_client_limits.TestClientLimits.test_client_oldest_tid"]}]=0 v430) v1 ==== 150+0+0 (secure 0 0 0) 0x7f79e815f5f0 con 0x7f79e80b1fc0 ... 2023-07-25T15:21:34.797 INFO:tasks.cephfs_test_runner:test_client_oldest_tid (tasks.cephfs.test_client_limits.TestClientLimits) ... ok
The test case test_client_release_bug was triggered later after test_client_oldest_tid:
2023-07-25T15:24:15.925 INFO:tasks.cephfs_test_runner:Starting test: test_client_release_bug (tasks.cephfs.test_client_limits.TestClientLimits) 2023-07-25T15:24:15.925 DEBUG:teuthology.orchestra.run.smithi038:> sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 120 ceph --cluster ceph log 'Starting test tasks.cephfs.test_client_limits.TestClientLimits.test_client_release_bug' ...
But the test_client_oldest_tid didn't clean the client inject fixed oldest tid option.
Actions