Project

General

Profile

Actions

Bug #59301

open

pacific (?): test_full_fsync: RuntimeError: Timed out waiting for MDS daemons to become healthy

Added by Patrick Donnelly about 1 year ago. Updated about 1 year ago.

Status:
Triaged
Priority:
High
Assignee:
Category:
Introspection/Control
Target version:
% Done:

0%

Source:
Q/A
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

2023-03-31T09:28:32.074 INFO:tasks.cephfs_test_runner:test_full_fsync (tasks.cephfs.test_full.TestClusterFull) ... ERROR
2023-03-31T09:28:32.075 INFO:tasks.cephfs_test_runner:
2023-03-31T09:28:32.075 INFO:tasks.cephfs_test_runner:======================================================================
2023-03-31T09:28:32.075 INFO:tasks.cephfs_test_runner:ERROR: test_full_fsync (tasks.cephfs.test_full.TestClusterFull)
2023-03-31T09:28:32.076 INFO:tasks.cephfs_test_runner:----------------------------------------------------------------------
2023-03-31T09:28:32.076 INFO:tasks.cephfs_test_runner:Traceback (most recent call last):
2023-03-31T09:28:32.076 INFO:tasks.cephfs_test_runner:  File "/home/teuthworker/src/git.ceph.com_ceph-c_caeaa2e33ca3e818edceb3fc8d7950e9ebf75f1e/qa/tasks/cephfs/test_full.py", line 391, in setUp
2023-03-31T09:28:32.077 INFO:tasks.cephfs_test_runner:    super(TestClusterFull, self).setUp()
2023-03-31T09:28:32.077 INFO:tasks.cephfs_test_runner:  File "/home/teuthworker/src/git.ceph.com_ceph-c_caeaa2e33ca3e818edceb3fc8d7950e9ebf75f1e/qa/tasks/cephfs/test_full.py", line 28, in setUp
2023-03-31T09:28:32.077 INFO:tasks.cephfs_test_runner:    CephFSTestCase.setUp(self)
2023-03-31T09:28:32.077 INFO:tasks.cephfs_test_runner:  File "/home/teuthworker/src/git.ceph.com_ceph-c_caeaa2e33ca3e818edceb3fc8d7950e9ebf75f1e/qa/tasks/cephfs/cephfs_test_case.py", line 180, in setUp
2023-03-31T09:28:32.077 INFO:tasks.cephfs_test_runner:    self.fs.wait_for_daemons()
2023-03-31T09:28:32.078 INFO:tasks.cephfs_test_runner:  File "/home/teuthworker/src/git.ceph.com_ceph-c_caeaa2e33ca3e818edceb3fc8d7950e9ebf75f1e/qa/tasks/cephfs/filesystem.py", line 1135, in wait_for_daemons
2023-03-31T09:28:32.078 INFO:tasks.cephfs_test_runner:    raise RuntimeError("Timed out waiting for MDS daemons to become healthy")
2023-03-31T09:28:32.078 INFO:tasks.cephfs_test_runner:RuntimeError: Timed out waiting for MDS daemons to become healthy

From: /teuthology/pdonnell-2023-03-30_20:10:47-fs-wip-pdonnell-testing-20230330.155904-pacific-distro-default-smithi/7227165/teuthology.log

MDS stuck in up:creating:

#2023-03-31T09:24:50.754+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6824/81893,v1:172.21.15.142:6825/81893] -- osd_op(unknown.0.28:1 11.14 11:292cf221:::200.00000000:head [writefull 0~90 in=90b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa51e000 con 0x561fa9779c00                 
#2023-03-31T09:24:50.754+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6808/81857,v1:172.21.15.142:6809/81857] -- osd_op(unknown.0.28:2 11.f 11:f1f69726:::400.00000000:head [writefull 0~22 in=22b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa51e800 con 0x561faa51e400                  
#2023-03-31T09:24:50.754+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6824/81893,v1:172.21.15.142:6825/81893] -- osd_op(unknown.0.28:3 11.14 11:287034c4:::1.00000000.inode:head [writefull 0~554 in=554b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa51ec00 con 0x561fa9779c00           
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6808/81857,v1:172.21.15.142:6809/81857] -- osd_op(unknown.0.28:4 11.3f 11:ff5b34d6:::1.00000000:head [create,setxattr parent (30) in=36b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa51f000 con 0x561faa51e400
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6800/81856,v1:172.21.15.142:6801/81856] -- osd_op(unknown.0.28:5 11.30 11:0d82a743:::600.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa51f800 con 0x561faa51f400
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6815/81643,v1:172.21.15.123:6816/81643] -- osd_op(unknown.0.28:6 11.10 11:09401a81:::601.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa52c000 con 0x561faa51fc00
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6815/81643,v1:172.21.15.123:6816/81643] -- osd_op(unknown.0.28:7 11.10 11:0bd6d154:::602.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa52c400 con 0x561faa51fc00
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6800/81856,v1:172.21.15.142:6801/81856] -- osd_op(unknown.0.28:8 11.30 11:0d89b25e:::603.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa52c800 con 0x561faa51f400
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6821/81653,v1:172.21.15.123:6825/81653] -- osd_op(unknown.0.28:9 11.15 11:a93a17c2:::604.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa52d000 con 0x561faa52cc00
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6808/81857,v1:172.21.15.142:6809/81857] -- osd_op(unknown.0.28:10 11.1d 11:b871830b:::605.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa52d400 con 0x561faa51e400
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6808/81652,v1:172.21.15.123:6809/81652] -- osd_op(unknown.0.28:11 11.34 11:2f55791f:::606.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa52dc00 con 0x561faa52d800
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6808/81652,v1:172.21.15.123:6809/81652] -- osd_op(unknown.0.28:12 11.3c 11:3ed09add:::607.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa534000 con 0x561faa52d800
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6800/81856,v1:172.21.15.142:6801/81856] -- osd_op(unknown.0.28:13 11.e 11:717a0223:::608.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa534400 con 0x561faa51f400
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6816/81866,v1:172.21.15.142:6817/81866] -- osd_op(unknown.0.28:14 11.7 11:e0b41d06:::609.00000000:head [create,setxattr parent (62) in=68b,setxattr layout (30) in=36b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa534c00 con 0x561faa534800
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6808/81857,v1:172.21.15.142:6809/81857] -- osd_op(unknown.0.28:15 11.3f 11:fe07bba1:::100.00000000.inode:head [writefull 0~554 in=554b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa535000 con 0x561faa51e400         
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6816/81866,v1:172.21.15.142:6817/81866] -- osd_op(unknown.0.28:16 11.13 11:c91d4a1d:::mds0_inotable:head [writefull 0~34 in=34b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa535400 con 0x561faa534800                
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6800/81642,v1:172.21.15.123:6801/81642] -- osd_op(unknown.0.28:17 11.b 11:d0630e4c:::mds0_sessionmap:head [omap-set-header in=14b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa535c00 con 0x561faa535800              
#2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6821/81653,v1:172.21.15.123:6825/81653] -- osd_op(unknown.0.28:18 11.15 11:aa448500:::500.00000000:head [writefull 0~90 in=90b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa5fe000 con 0x561faa52cc00                
2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6824/81893,v1:172.21.15.142:6825/81893] -- osd_op(unknown.0.28:19 11.2d 11:b50e409b:::mds_snaptable:head [writefull 0~70 in=70b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa5fe400 con 0x561fa9779c00                
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6808/81857,v1:172.21.15.142:6809/81857] -- osd_op(unknown.0.28:20 11.3f 11:ff5b34d6:::1.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa604000 con 0x561faa51e400                 
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6800/81856,v1:172.21.15.142:6801/81856] -- osd_op(unknown.0.28:21 11.30 11:0d82a743:::600.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa604400 con 0x561faa51f400               
2023-03-31T09:24:50.755+0000 7f761e51b700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6808/81652,v1:172.21.15.123:6809/81652] -- osd_op(unknown.0.28:22 11.34 11:2e2fa760:::200.00000001:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa604c00 con 0x561faa52d800                                
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6815/81643,v1:172.21.15.123:6816/81643] -- osd_op(unknown.0.28:23 11.10 11:09401a81:::601.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa604800 con 0x561faa51fc00               
2023-03-31T09:24:50.755+0000 7f761e51b700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6821/81653,v1:172.21.15.123:6825/81653] -- osd_op(unknown.0.28:24 11.3b 11:ddb4e4d7:::200.00000002:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa605000 con 0x561faa52cc00                                
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6815/81643,v1:172.21.15.123:6816/81643] -- osd_op(unknown.0.28:25 11.10 11:0bd6d154:::602.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa605800 con 0x561faa51fc00               
2023-03-31T09:24:50.755+0000 7f761e51b700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6800/81856,v1:172.21.15.142:6801/81856] -- osd_op(unknown.0.28:26 11.2b 11:d5c7a900:::200.00000003:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa605400 con 0x561faa51f400                                
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6800/81856,v1:172.21.15.142:6801/81856] -- osd_op(unknown.0.28:27 11.30 11:0d89b25e:::603.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa605c00 con 0x561faa51f400               
2023-03-31T09:24:50.755+0000 7f761e51b700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6821/81653,v1:172.21.15.123:6825/81653] -- osd_op(unknown.0.28:28 11.1f 11:f83d65d8:::200.00000004:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa612000 con 0x561faa52cc00                                
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6821/81653,v1:172.21.15.123:6825/81653] -- osd_op(unknown.0.28:29 11.15 11:a93a17c2:::604.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa612c00 con 0x561faa52cc00               
2023-03-31T09:24:50.755+0000 7f761e51b700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6824/81893,v1:172.21.15.142:6825/81893] -- osd_op(unknown.0.28:30 11.3a 11:5e41ab69:::200.00000005:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa612400 con 0x561fa9779c00                                
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6808/81857,v1:172.21.15.142:6809/81857] -- osd_op(unknown.0.28:31 11.1d 11:b871830b:::605.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa613000 con 0x561faa51e400               
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6808/81652,v1:172.21.15.123:6809/81652] -- osd_op(unknown.0.28:32 11.34 11:2f55791f:::606.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa613400 con 0x561faa52d800               
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6808/81652,v1:172.21.15.123:6809/81652] -- osd_op(unknown.0.28:33 11.3c 11:3ed09add:::607.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa613800 con 0x561faa52d800               
2023-03-31T09:24:50.755+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6800/81856,v1:172.21.15.142:6801/81856] -- osd_op(unknown.0.28:35 11.e 11:717a0223:::608.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa613c00 con 0x561faa51f400                
2023-03-31T09:24:50.755+0000 7f761e51b700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6808/81857,v1:172.21.15.142:6809/81857] -- osd_op(unknown.0.28:34 11.1e 11:7bf7e7b5:::200.00000006:head [delete] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa612800 con 0x561faa51e400                                
2023-03-31T09:24:50.756+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.142:6816/81866,v1:172.21.15.142:6817/81866] -- osd_op(unknown.0.28:36 11.7 11:e0b41d06:::609.00000000:head [omap-set-header in=274b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa61c000 con 0x561faa534800                
2023-03-31T09:24:50.756+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6815/81643,v1:172.21.15.123:6816/81643] -- osd_op(unknown.0.28:37 11.33 11:cd5a64a3:::100.00000000:head [omap-set-header in=274b,omap-set-vals in=5074b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa61c400 con 0x561faa51fc00
2023-03-31T09:24:50.763+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.1 v2:172.21.15.123:6808/81652 1 ==== osd_op_reply(11 606.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa52d800
2023-03-31T09:24:50.763+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.1 v2:172.21.15.123:6808/81652 2 ==== osd_op_reply(32 606.00000000 [omap-set-header] v91'2 uv2 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa52d800
2023-03-31T09:24:50.763+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.1 v2:172.21.15.123:6808/81652 3 ==== osd_op_reply(22 200.00000001 [delete] v91'3 uv2 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa52d800
2023-03-31T09:24:50.763+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.0 v2:172.21.15.123:6815/81643 1 ==== osd_op_reply(6 601.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa51fc00
2023-03-31T09:24:50.764+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.7 v2:172.21.15.142:6808/81857 1 ==== osd_op_reply(2 400.00000000 [writefull 0~22] v91'1 uv1 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa51e400
2023-03-31T09:24:50.764+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.6 v2:172.21.15.142:6824/81893 1 ==== osd_op_reply(1 200.00000000 [writefull 0~90] v91'1 uv1 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561fa9779c00
2023-03-31T09:24:50.764+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.2 v2:172.21.15.123:6821/81653 1 ==== osd_op_reply(24 200.00000002 [delete] v91'1 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa52cc00
2023-03-31T09:24:50.765+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.7 v2:172.21.15.142:6808/81857 2 ==== osd_op_reply(34 200.00000006 [delete] v91'1 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa51e400
2023-03-31T09:24:50.765+0000 7f761ed1c700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6808/81652,v1:172.21.15.123:6809/81652] -- osd_op(unknown.0.28:38 11.34 11:2e2fa760:::200.00000001:head [write 0~892 in=892b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa61c800 con 0x561faa52d800
2023-03-31T09:24:50.765+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.5 v2:172.21.15.142:6816/81866 1 ==== osd_op_reply(14 609.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa534800
2023-03-31T09:24:50.765+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.1 v2:172.21.15.123:6808/81652 4 ==== osd_op_reply(12 607.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa52d800
2023-03-31T09:24:50.765+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.0 v2:172.21.15.123:6815/81643 2 ==== osd_op_reply(7 602.00000000 [create,setxattr (62),setxattr (30)] v91'2 uv2 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa51fc00
2023-03-31T09:24:50.765+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.0 v2:172.21.15.123:6815/81643 3 ==== osd_op_reply(23 601.00000000 [omap-set-header] v91'3 uv3 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa51fc00
2023-03-31T09:24:50.766+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.1 v2:172.21.15.123:6808/81652 5 ==== osd_op_reply(33 607.00000000 [omap-set-header] v91'2 uv2 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa52d800
2023-03-31T09:24:50.766+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.7 v2:172.21.15.142:6808/81857 3 ==== osd_op_reply(10 605.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa51e400
2023-03-31T09:24:50.766+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.7 v2:172.21.15.142:6808/81857 4 ==== osd_op_reply(31 605.00000000 [omap-set-header] v91'2 uv2 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa51e400
2023-03-31T09:24:50.766+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.7 v2:172.21.15.142:6808/81857 5 ==== osd_op_reply(4 1.00000000 [create,setxattr (30),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 238+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa51e400
2023-03-31T09:24:50.766+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.7 v2:172.21.15.142:6808/81857 6 ==== osd_op_reply(20 1.00000000 [omap-set-header] v91'2 uv2 ondisk = 0) v8 ==== 154+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa51e400
2023-03-31T09:24:50.766+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.7 v2:172.21.15.142:6808/81857 7 ==== osd_op_reply(15 100.00000000.inode [writefull 0~554] v91'3 uv3 ondisk = 0) v8 ==== 162+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa51e400
2023-03-31T09:24:50.766+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.5 v2:172.21.15.142:6816/81866 2 ==== osd_op_reply(36 609.00000000 [omap-set-header] v91'2 uv2 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa534800
2023-03-31T09:24:50.766+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.5 v2:172.21.15.142:6816/81866 3 ==== osd_op_reply(16 mds0_inotable [writefull 0~34] v91'1 uv1 ondisk = 0) v8 ==== 157+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa534800
2023-03-31T09:24:50.767+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.2 v2:172.21.15.123:6821/81653 2 ==== osd_op_reply(28 200.00000004 [delete] v91'1 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa52cc00
2023-03-31T09:24:50.767+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.2 v2:172.21.15.123:6821/81653 3 ==== osd_op_reply(9 604.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa52cc00
2023-03-31T09:24:50.767+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.2 v2:172.21.15.123:6821/81653 4 ==== osd_op_reply(29 604.00000000 [omap-set-header] v91'2 uv2 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa52cc00
2023-03-31T09:24:50.767+0000 7f7627d2e700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.2 v2:172.21.15.123:6821/81653 5 ==== osd_op_reply(18 500.00000000 [writefull 0~90] v91'3 uv3 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa376fc0 con 0x561faa52cc00
2023-03-31T09:24:50.767+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.1 v2:172.21.15.123:6808/81652 6 ==== osd_op_reply(38 200.00000001 [write 0~892] v91'4 uv4 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa52d800
2023-03-31T09:24:50.767+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.6 v2:172.21.15.142:6824/81893 2 ==== osd_op_reply(19 mds_snaptable [writefull 0~70] v91'1 uv1 ondisk = 0) v8 ==== 157+0+0 (crc 0 0 0) 0x561faa648000 con 0x561fa9779c00
2023-03-31T09:24:50.769+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.6 v2:172.21.15.142:6824/81893 3 ==== osd_op_reply(30 200.00000005 [delete] v91'1 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561fa9779c00
2023-03-31T09:24:50.769+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.0 v2:172.21.15.123:6815/81643 4 ==== osd_op_reply(25 602.00000000 [omap-set-header] v91'4 uv4 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa51fc00
2023-03-31T09:24:50.769+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.4 v2:172.21.15.142:6800/81856 1 ==== osd_op_reply(26 200.00000003 [delete] v91'1 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa51f400
2023-03-31T09:24:50.769+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.4 v2:172.21.15.142:6800/81856 2 ==== osd_op_reply(13 608.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa51f400
2023-03-31T09:24:50.769+0000 7f762852f700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.0 v2:172.21.15.123:6815/81643 5 ==== osd_op_reply(37 100.00000000 [omap-set-header,omap-set-vals] v91'1 uv1 ondisk = 0) v8 ==== 198+0+0 (crc 0 0 0) 0x561faa6486c0 con 0x561faa51fc00
2023-03-31T09:24:50.769+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.4 v2:172.21.15.142:6800/81856 3 ==== osd_op_reply(35 608.00000000 [omap-set-header] v91'2 uv2 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa51f400
2023-03-31T09:24:50.770+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.4 v2:172.21.15.142:6800/81856 4 ==== osd_op_reply(5 600.00000000 [create,setxattr (62),setxattr (30)] v91'1 uv1 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa51f400
2023-03-31T09:24:50.770+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.6 v2:172.21.15.142:6824/81893 4 ==== osd_op_reply(3 1.00000000.inode [writefull 0~554] v91'2 uv2 ondisk = 0) v8 ==== 160+0+0 (crc 0 0 0) 0x561faa648000 con 0x561fa9779c00
2023-03-31T09:24:50.770+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.4 v2:172.21.15.142:6800/81856 5 ==== osd_op_reply(8 603.00000000 [create,setxattr (62),setxattr (30)] v91'2 uv2 ondisk = 0) v8 ==== 240+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa51f400
2023-03-31T09:24:50.770+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.4 v2:172.21.15.142:6800/81856 6 ==== osd_op_reply(21 600.00000000 [omap-set-header] v91'3 uv3 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa51f400
2023-03-31T09:24:50.770+0000 7f762752d700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] <== osd.4 v2:172.21.15.142:6800/81856 7 ==== osd_op_reply(27 603.00000000 [omap-set-header] v91'4 uv4 ondisk = 0) v8 ==== 156+0+0 (crc 0 0 0) 0x561faa648000 con 0x561faa51f400

(Filtered osd ops.) This op never got a reply:

2023-03-31T09:24:50.755+0000 7f7624d28700  1 -- [v2:172.21.15.142:6832/2158931055,v1:172.21.15.142:6834/2158931055] --> [v2:172.21.15.123:6800/81642,v1:172.21.15.123:6801/81642] -- osd_op(unknown.0.28:17 11.b 11:d0630e4c:::mds0_sessionmap:head [omap-set-header in=14b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8 -- 0x561faa535c00 con 0x561faa535800              

OSD says:

2023-03-31T09:24:50.763+0000 7f674b7cc700 10 osd.3 pg_epoch: 91 pg[11.b( empty local-lis/les=89/90 n=0 ec=89/89 lis/c=89/89 les/c/f=90/90/0 sis=89) [3,1] r=0 lpr=89 crt=0'0 mlcod 0'0 active+clean] _handle_message: 0x560c2f480580                                                                                                                                                          
2023-03-31T09:24:50.763+0000 7f674b7cc700 20 osd.3 pg_epoch: 91 pg[11.b( empty local-lis/les=89/90 n=0 ec=89/89 lis/c=89/89 les/c/f=90/90/0 sis=89) [3,1] r=0 lpr=89 crt=0'0 mlcod 0'0 active+clean] do_op: op osd_op(mds.0.28:17 11.b 11:d0630e4c:::mds0_sessionmap:head [omap-set-header in=14b] snapc 0=[] ondisk+write+known_if_redirected+full_force e91) v8                             
2023-03-31T09:24:50.763+0000 7f674b7cc700 20 osd.3 pg_epoch: 91 pg[11.b( empty local-lis/les=89/90 n=0 ec=89/89 lis/c=89/89 les/c/f=90/90/0 sis=89) [3,1] r=0 lpr=89 crt=0'0 mlcod 0'0 active+clean] op_has_sufficient_caps session=0x560c1cd69e00 pool=11 (cephfs_metadata ) pool_app_metadata={cephfs={metadata=cephfs}} need_read_cap=0 need_write_cap=1 classes=[] -> yes                 
2023-03-31T09:24:50.763+0000 7f674b7cc700 10 osd.3 pg_epoch: 91 pg[11.b( empty local-lis/les=89/90 n=0 ec=89/89 lis/c=89/89 les/c/f=90/90/0 sis=89) [3,1] r=0 lpr=89 crt=0'0 mlcod 0'0 active+clean] _check_full current usage is 9.22337e+10 physical 9.22337e+10                                                                                                                            
2023-03-31T09:24:50.763+0000 7f674b7cc700 10 osd.3 pg_epoch: 91 pg[11.b( empty local-lis/les=89/90 n=0 ec=89/89 lis/c=89/89 les/c/f=90/90/0 sis=89) [3,1] r=0 lpr=89 crt=0'0 mlcod 0'0 active+clean] do_op fail-safe full check failed, dropping request.                                                                                                                                     
2023-03-31T09:24:50.763+0000 7f674b7cc700 10 osd.3 91 dequeue_op 0x560c2f480580 finish

From: /teuthology/pdonnell-2023-03-30_20:10:47-fs-wip-pdonnell-testing-20230330.155904-pacific-distro-default-smithi/7227165/remote/smithi123/log/ceph-osd.3.log.gz

So the OSD dropped the op because the full check failed. Some things to note: (a) this is the only op the MDS sent that OSD; (b) all other ops got a response; (c) full_force flag had no effect.

This is a test_full suite so something related to the OSD becoming full on the previous test probably influenced this behavior.

Actions #1

Updated by Patrick Donnelly about 1 year ago

  • Subject changed from pacific (?): to pacific (?): test_full_fsync: RuntimeError: Timed out waiting for MDS daemons to become healthy
Actions #2

Updated by Venky Shankar about 1 year ago

  • Category set to Introspection/Control
  • Assignee set to Venky Shankar
  • Target version set to v19.0.0
  • Source set to Q/A

No backport target set since this is being currently debugged to assess the scope of the issue.

Actions #3

Updated by Venky Shankar about 1 year ago

  • Status changed from New to Triaged
Actions

Also available in: Atom PDF