Commit 8ea412e1 authored by Patrick Donnelly's avatar Patrick Donnelly Committed by Ilya Dryomov
Browse files

ceph: improve caps debugging output 

This improves uniformity and exposes important sequence numbers.

Now looks like:

    <7>[   73.749563] ceph:           caps.c:4465 : [c9653bca-110b-4f70-9f84-5a195b205e9a 15290]  caps mds2 op export ino 20000000000.fffffffffffffffe inode 0000000008d2e5ea seq 0 iseq 0 mseq 0
    ...
    <7>[   73.749574] ceph:           caps.c:4102 : [c9653bca-110b-4f70-9f84-5a195b205e9a 15290]  cap 20000000000.fffffffffffffffe export to peer 1 piseq 1 pmseq 1
    ...
    <7>[   73.749645] ceph:           caps.c:4465 : [c9653bca-110b-4f70-9f84-5a195b205e9a 15290]  caps mds1 op import ino 20000000000.fffffffffffffffe inode 0000000008d2e5ea seq 1 iseq 1 mseq 1
    ...
    <7>[   73.749681] ceph:           caps.c:4244 : [c9653bca-110b-4f70-9f84-5a195b205e9a 15290]  cap 20000000000.fffffffffffffffe import from peer 2 piseq 686 pmseq 0
    ...
    <7>[  248.645596] ceph:           caps.c:4465 : [c9653bca-110b-4f70-9f84-5a195b205e9a 15290]  caps mds1 op revoke ino 20000000000.fffffffffffffffe inode 0000000008d2e5ea seq 2538 iseq 1 mseq 1

See also ceph.git commit cb4ff28af09f ("mds: add issue_seq to all cap
messages").

Link: https://tracker.ceph.com/issues/66704


Signed-off-by: default avatarPatrick Donnelly <pdonnell@redhat.com>
Reviewed-by: default avatarIlya Dryomov <idryomov@gmail.com>
Signed-off-by: default avatarIlya Dryomov <idryomov@gmail.com>
parent 8b41ac43

fs/ceph/caps.c

+17 −18
Original line number Diff line number Diff line
@@ -4071,8 +4071,7 @@ static void handle_cap_export(struct inode *inode, struct ceph_mds_caps *ex, 
	struct ceph_cap *cap, *tcap, *new_cap = NULL;

	struct ceph_inode_info *ci = ceph_inode(inode);

	u64 t_cap_id;

	unsigned mseq = le32_to_cpu(ex->migrate_seq);

	unsigned t_issue_seq, t_mseq;

	u32 t_issue_seq, t_mseq;

	int target, issued;

	int mds = session->s_mds;
@@ -4086,8 +4085,8 @@ static void handle_cap_export(struct inode *inode, struct ceph_mds_caps *ex, 
		target = -1;

	}



	doutc(cl, "%p %llx.%llx ci %p mds%d mseq %d target %d\n",

	      inode, ceph_vinop(inode), ci, mds, mseq, target);

	doutc(cl, " cap %llx.%llx export to peer %d piseq %u pmseq %u\n",

	      ceph_vinop(inode), target, t_issue_seq, t_mseq);

retry:

	down_read(&mdsc->snap_rwsem);

	spin_lock(&ci->i_ceph_lock);
@@ -4214,18 +4213,22 @@ static void handle_cap_import(struct ceph_mds_client *mdsc, 
	u64 realmino = le64_to_cpu(im->realm);

	u64 cap_id = le64_to_cpu(im->cap_id);

	u64 p_cap_id;

	u32 piseq = 0;

	u32 pmseq = 0;

	int peer;



	if (ph) {

		p_cap_id = le64_to_cpu(ph->cap_id);

		peer = le32_to_cpu(ph->mds);

		piseq = le32_to_cpu(ph->issue_seq);

		pmseq = le32_to_cpu(ph->mseq);

	} else {

		p_cap_id = 0;

		peer = -1;

	}



	doutc(cl, "%p %llx.%llx ci %p mds%d mseq %d peer %d\n",

	      inode, ceph_vinop(inode), ci, mds, mseq, peer);

	doutc(cl, " cap %llx.%llx import from peer %d piseq %u pmseq %u\n",

	      ceph_vinop(inode), peer, piseq, pmseq);

retry:

	cap = __get_cap_for_mds(ci, mds);

	if (!cap) {
@@ -4254,15 +4257,13 @@ static void handle_cap_import(struct ceph_mds_client *mdsc, 
		doutc(cl, " remove export cap %p mds%d flags %d\n",

		      ocap, peer, ph->flags);

		if ((ph->flags & CEPH_CAP_FLAG_AUTH) &&

		    (ocap->seq != le32_to_cpu(ph->issue_seq) ||

		     ocap->mseq != le32_to_cpu(ph->mseq))) {

		    (ocap->seq != piseq ||

		     ocap->mseq != pmseq)) {

			pr_err_ratelimited_client(cl, "mismatched seq/mseq: "

					"%p %llx.%llx mds%d seq %d mseq %d"

					" importer mds%d has peer seq %d mseq %d\n",

					inode, ceph_vinop(inode), peer,

					ocap->seq, ocap->mseq, mds,

					le32_to_cpu(ph->issue_seq),

					le32_to_cpu(ph->mseq));

					ocap->seq, ocap->mseq, mds, piseq, pmseq);

		}

		ceph_remove_cap(mdsc, ocap, (ph->flags & CEPH_CAP_FLAG_RELEASE));

	}
@@ -4336,7 +4337,7 @@ void ceph_handle_caps(struct ceph_mds_session *session, 
	struct ceph_snap_realm *realm = NULL;

	int op;

	int msg_version = le16_to_cpu(msg->hdr.version);

	u32 seq, mseq;

	u32 seq, mseq, issue_seq;

	struct ceph_vino vino;

	void *snaptrace;

	size_t snaptrace_len;
@@ -4346,8 +4347,6 @@ void ceph_handle_caps(struct ceph_mds_session *session, 
	bool close_sessions = false;

	bool do_cap_release = false;



	doutc(cl, "from mds%d\n", session->s_mds);



	if (!ceph_inc_mds_stopping_blocker(mdsc, session))

		return;
@@ -4361,6 +4360,7 @@ void ceph_handle_caps(struct ceph_mds_session *session, 
	vino.snap = CEPH_NOSNAP;

	seq = le32_to_cpu(h->seq);

	mseq = le32_to_cpu(h->migrate_seq);

	issue_seq = le32_to_cpu(h->issue_seq);



	snaptrace = h + 1;

	snaptrace_len = le32_to_cpu(h->snap_trace_len);
@@ -4448,12 +4448,11 @@ void ceph_handle_caps(struct ceph_mds_session *session, 


	/* lookup ino */

	inode = ceph_find_inode(mdsc->fsc->sb, vino);

	doutc(cl, " op %s ino %llx.%llx inode %p\n", ceph_cap_op_name(op),

	      vino.ino, vino.snap, inode);

	doutc(cl, " caps mds%d op %s ino %llx.%llx inode %p seq %u iseq %u mseq %u\n",

	      session->s_mds, ceph_cap_op_name(op), vino.ino, vino.snap, inode,

	      seq, issue_seq, mseq);



	mutex_lock(&session->s_mutex);

	doutc(cl, " mds%d seq %lld cap seq %u\n", session->s_mds,

	      session->s_seq, (unsigned)seq);



	if (!inode) {

		doutc(cl, " i don't have ino %llx\n", vino.ino);