Bug #63411: qa: flush journal may cause timeouts of `scrub status` - CephFS - Ceph

Actions

Copy link

Bug #63411

open

qa: flush journal may cause timeouts of `scrub status`

Added by Patrick Donnelly 6 months ago. Updated 3 months ago.

Status:

Pending Backport

Priority:

High

Assignee:

Milind Changire

Category:

Testing

Target version:

Ceph - v19.0.0

% Done:

Source:

Q/A

Tags:

backport_processed

Backport:

reef,quincy

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Component(FS):

MDS, qa-suite

Labels (FS):

qa-failure

Pull request ID:

54446

Crash signature (v1):

Crash signature (v2):

Description

2023-10-26T06:14:11.570 DEBUG:teuthology.orchestra.run.smithi019:> sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 120 ceph --cluster ceph tell mds.1:0 scrub status
...
2023-10-26T06:14:11.959 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.956+0000 7f40f11e3700  1 -- 172.21.15.19:0/1745975620 learned_addr learned my addr 172.21.15.19:0/1745975620 (peer_addr_for_me v2:172.21.15.19:0/0)
...
2023-10-26T06:14:11.966 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.964+0000 7f40ffe31b80 10 client.15900 fetch_fsmap finished waiting for FSMap version 20
2023-10-26T06:14:11.966 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.964+0000 7f40ffe31b80 10 client.15900 resolve_mds: resolved 1:0 to role '1:0' aka daemon mds.b
2023-10-26T06:14:11.966 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.964+0000 7f40ffe31b80 20 client.15900 populate_metadata read hostname 'smithi019'
2023-10-26T06:14:11.966 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.964+0000 7f40ffe31b80  1 --2- 172.21.15.19:0/1745975620 >> [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] conn(0x562ec0f37fa0 0x562ec0f3a420 unknown :-1 s=NONE pgs=0 cs=0 l=0 rev1=0 crypto rx=0 tx=0 comp rx=0 tx=0).connect
2023-10-26T06:14:11.966 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.964+0000 7f40ffe31b80  4 client.15900 mds_command: new command op to 24626 tid=0 multi_id=0 [{"prefix": "get_command_descriptions"}]
2023-10-26T06:14:11.967 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.964+0000 7f40ffe31b80  1 -- 172.21.15.19:0/1745975620 --> [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] -- command(tid 0: {"prefix": "get_command_descriptions"}) v1 -- 0x562ec0e6de50 con 0x562ec0f37fa0
2023-10-26T06:14:11.967 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.964+0000 7f40f19e4700  1 --2- 172.21.15.19:0/1745975620 >> [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] conn(0x562ec0f37fa0 0x562ec0f3a420 unknown :-1 s=BANNER_CONNECTING pgs=0 cs=0 l=0 rev1=0 crypto rx=0 tx=0 comp rx=0 tx=0)._handle_peer_banner_payload supported=3 required=0
2023-10-26T06:14:11.981 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.980+0000 7f40f19e4700  1 --2- 172.21.15.19:0/1745975620 >> [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] conn(0x562ec0f37fa0 0x562ec0f3a420 crc :-1 s=READY pgs=60 cs=0 l=0 rev1=1 crypto rx=0 tx=0 comp rx=0 tx=0).ready entity=mds.0 client_cookie=c732cd3213b34345 server_cookie=644179e87c50e5ca in_seq=0 out_seq=0
2023-10-26T06:14:11.984 INFO:teuthology.orchestra.run.smithi019.stderr:2023-10-26T06:14:11.981+0000 7f40d57fa700 10 client.15900 ms_handle_connect on v2:172.21.15.92:6838/2624337409
...
2023-10-26T06:16:12.049 DEBUG:teuthology.orchestra.run:got remote process result: 124

From: /teuthology/pdonnell-2023-10-26_05:21:22-fs-wip-batrick-testing-20231024.144545-distro-default-smithi/7438457/teuthology.log

mds log shows:

2023-10-26T06:14:10.252+0000 7fda63c95700  1 -- [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] <== client.15891 172.21.15.19:0/3377571012 1 ==== command(tid 0: {"prefix": "flush journal"}) v1 ==== 51+0+0 (crc 0 0 0) 0x558b53f638c0 con 0x558b55764400
2023-10-26T06:14:10.252+0000 7fda65c99700  1 mds.b asok_command: flush journal {prefix=flush journal} (starting...)
2023-10-26T06:14:10.252+0000 7fda65c99700 10 mds.0.14 handle_asok_command: flush journal
...
2023-10-26T06:14:11.980+0000 7fda63c95700  1 -- [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] <== client.15900 172.21.15.19:0/1745975620 1 ==== command(tid 0: {"prefix": "get_command_descriptions"}) v1 ==== 62+0+0 (crc 0 0 0) 0x558b56194000 con 0x558b55764800
...
2023-10-26T06:16:40.973+0000 7fda5dc89700 10 MDSContext::complete: 15C_Flush_Journal
2023-10-26T06:16:40.973+0000 7fda5dc89700 20 mds.0.14 finish: r=0
2023-10-26T06:16:40.973+0000 7fda65c99700  1 -- [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] --> 172.21.15.19:0/3377571012 -- command_reply(tid 0: 0 ) v1 -- 0x558b54ebe2c0 con 0x558b55764400
2023-10-26T06:16:40.973+0000 7fda65c99700  1 -- [v2:172.21.15.92:6838/2624337409,v1:172.21.15.92:6839/2624337409] --> 172.21.15.19:0/1745975620 -- command_reply(tid 0: 0 ) v1 -- 0x558b53f638c0 con 0x558b55764800

From: /teuthology/pdonnell-2023-10-26_05:21:22-fs-wip-batrick-testing-20231024.144545-distro-default-smithi/7438457/remote/smithi092/log/3afadc4c-73c5-11ee-8db9-212e2dc638e7/ceph-mds.b.log.gz

Related issues 2 (2 open — 0 closed)