Ceph » CephFS

From: https://pulpito.ceph.com/leonidus-2024-05-26_10:48:16-fs-wip-lusov-quiesce-distro-default-smithi/7726344/

[leonidus@vossi04 leonidus-2024-05-26_10:48:16-fs-wip-lusov-quiesce-distro-default-smithi]$ grep "ERROR:tasks.quiescer" */teuthology.log
7726344/teuthology.log:2024-05-26T12:51:16.035 ERROR:tasks.quiescer.fs.[cephfs]:Couldn't quiesce root with rc: 110 (ETIMEDOUT), stdout:
7726344/teuthology.log:2024-05-26T12:51:16.035 ERROR:tasks.quiescer.fs.[cephfs]:exception:

[leonidus@vossi04 leonidus-2024-05-26_10:48:16-fs-wip-lusov-quiesce-distro-default-smithi]$ grep Outstanding 7726344/teuthology.log | head -2
2024-05-26T12:50:48.644 DEBUG:tasks.quiescer.fs.[cephfs]:Outstanding op at rank 2 (g) for 420c46f1-1: 'internal op quiesce_inode:mds.2:111 fp=#0x20000000210'
2024-05-26T12:50:48.648 DEBUG:tasks.quiescer.fs.[cephfs]:Outstanding op at rank 2 (g) for 420c46f1-1: 'internal op quiesce_inode:mds.2:115 fp=#0x2000000026d'

» cat ops-420c46f1-1-mds.g.json | jq '.ops | map(select(.type_data.op_name == "quiesce_inode" and (.type_data.flag_point | test("quiesce complete|quiescing children")|not)) | [.type_data.flag_point, .description, (.type_data.locks | map(.lock.type))] )
[
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:111 fp=#0x20000000210", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:115 fp=#0x2000000026d", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:116 fp=#0x20000000205", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:120 fp=#0x20000000209", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:122 fp=#0x20000000266", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:123 fp=#0x2000000021e", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:126 fp=#0x2000000020a", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:128 fp=#0x20000000201", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:102 fp=#0x2000000021b", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:134 fp=#0x2000000023f", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:135 fp=#0x20000000227", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:104 fp=#0x20000000207", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:136 fp=#0x20000000211", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:105 fp=#0x2000000022b", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:137 fp=#0x20000000260", ["iquiesce","ipolicy"]],
  ["failed to xlock, waiting", "internal op quiesce_inode:mds.2:109 fp=#0x20000000269", ["iquiesce","ipolicy"]]
]

There are two observations to be made:
1. It doesn't look like a deadlock, as there are no pending operations other than the quiesce ops
2. The quiesce ops are failing to xlock the file lock - the only other xlock quiesce takes is the quiesce, which all of the operations already hold along with the policy

This suggests that we must be waiting for a cap revoke. This is to be corroborated with the mds.g.log