* [PATCH 1/2] ceph: add tracepoints for message submission on read/write requests
2012-05-10 14:35 [PATCH 0/2] Ceph tracepoints Jim Schutt
@ 2012-05-10 14:35 ` Jim Schutt
2012-05-10 14:35 ` [PATCH 2/2] ceph: add tracepoints for message send queueing and completion, reply handling Jim Schutt
2012-05-10 15:39 ` [PATCH 0/2] Ceph tracepoints Alex Elder
2 siblings, 0 replies; 4+ messages in thread
From: Jim Schutt @ 2012-05-10 14:35 UTC (permalink / raw)
To: elder; +Cc: ceph-devel, Jim Schutt
Trace callers of ceph_osdc_start_request, so that call locations
are identified implicitly.
Put the tracepoints after calls to ceph_osdc_start_request,
since it fills in the request transaction ID and request OSD.
Signed-off-by: Jim Schutt <jaschut@sandia.gov>
---
fs/ceph/addr.c | 8 ++++
fs/ceph/file.c | 6 +++
include/trace/events/ceph.h | 77 +++++++++++++++++++++++++++++++++++++++++++
net/ceph/osd_client.c | 7 ++++
4 files changed, 98 insertions(+), 0 deletions(-)
create mode 100644 include/trace/events/ceph.h
diff --git a/fs/ceph/addr.c b/fs/ceph/addr.c
index 173b1d2..f552579 100644
--- a/fs/ceph/addr.c
+++ b/fs/ceph/addr.c
@@ -13,6 +13,12 @@
#include "mds_client.h"
#include <linux/ceph/osd_client.h>
+
+#include <linux/tracepoint.h>
+#define CREATE_TRACE_POINTS
+#define CEPH_TRACE_FS_ADDR
+#include <trace/events/ceph.h>
+
/*
* Ceph address space ops.
*
@@ -338,6 +344,7 @@ static int start_read(struct inode *inode, struct list_head *page_list, int max)
dout("start_read %p starting %p %lld~%lld\n", inode, req, off, len);
ret = ceph_osdc_start_request(osdc, req, false);
+ trace_ceph_async_readpages_req(req);
if (ret < 0)
goto out_pages;
ceph_osdc_put_request(req);
@@ -902,6 +909,7 @@ get_more_pages:
req->r_request->hdr.data_len = cpu_to_le32(len);
rc = ceph_osdc_start_request(&fsc->client->osdc, req, true);
+ trace_ceph_async_writepages_req(req);
BUG_ON(rc);
req = NULL;
diff --git a/fs/ceph/file.c b/fs/ceph/file.c
index ed72428..fc31def 100644
--- a/fs/ceph/file.c
+++ b/fs/ceph/file.c
@@ -10,6 +10,11 @@
#include "super.h"
#include "mds_client.h"
+#include <linux/tracepoint.h>
+#define CREATE_TRACE_POINTS
+#define CEPH_TRACE_FS_FILE
+#include <trace/events/ceph.h>
+
/*
* Ceph file operations
*
@@ -568,6 +573,7 @@ more:
req->r_inode = inode;
ret = ceph_osdc_start_request(&fsc->client->osdc, req, false);
+ trace_ceph_sync_writepages_req(req);
if (!ret) {
if (req->r_safe_callback) {
/*
diff --git a/include/trace/events/ceph.h b/include/trace/events/ceph.h
new file mode 100644
index 0000000..182af2c
--- /dev/null
+++ b/include/trace/events/ceph.h
@@ -0,0 +1,77 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM ceph
+
+#if !defined(_TRACE_CEPH_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_CEPH_H
+
+
+#if !defined(TRACE_HEADER_MULTI_READ)
+
+static __always_inline int
+__ceph_req_num_ops(struct ceph_osd_request *req)
+{
+ struct ceph_osd_request_head *reqhead = req->r_request->front.iov_base;
+ return le16_to_cpu(reqhead->num_ops);
+}
+
+static __always_inline int
+__ceph_req_op_opcode(struct ceph_osd_request *req, int op)
+{
+ struct ceph_osd_request_head *reqhead = req->r_request->front.iov_base;
+ if (op < le16_to_cpu(reqhead->num_ops))
+ return le16_to_cpu(reqhead->ops[op].op);
+ else
+ return 0;
+}
+
+#endif
+
+DECLARE_EVENT_CLASS(ceph_start_req_class,
+ TP_PROTO(struct ceph_osd_request *req),
+ TP_ARGS(req),
+ TP_STRUCT__entry(
+ __field(unsigned long long, tid)
+ __field(int, osd)
+ __field(int, num_ops)
+ __array(unsigned, ops, 3)
+ __field(unsigned, pages)
+ ),
+ TP_fast_assign(
+ __entry->tid = req->r_tid;
+ __entry->osd = req->r_osd->o_osd;
+ __entry->num_ops = __ceph_req_num_ops(req);
+ __entry->ops[0] = __ceph_req_op_opcode(req, 0);
+ __entry->ops[1] = __ceph_req_op_opcode(req, 1);
+ __entry->ops[2] = __ceph_req_op_opcode(req, 2);
+ __entry->pages = req->r_num_pages;
+ ),
+ TP_printk("tid %llu osd%d ops %d 0x%04x/0x%04x/0x%04x pages %u",
+ __entry->tid, __entry->osd, __entry->num_ops,
+ __entry->ops[0], __entry->ops[1], __entry->ops[2],
+ __entry->pages
+ )
+);
+
+#define DEFINE_CEPH_START_REQ_EVENT(name) \
+DEFINE_EVENT(ceph_start_req_class, name, \
+ TP_PROTO(struct ceph_osd_request *req), TP_ARGS(req))
+
+#ifdef CEPH_TRACE_FS_FILE
+DEFINE_CEPH_START_REQ_EVENT(ceph_sync_writepages_req);
+#endif
+
+#ifdef CEPH_TRACE_FS_ADDR
+DEFINE_CEPH_START_REQ_EVENT(ceph_async_writepages_req);
+DEFINE_CEPH_START_REQ_EVENT(ceph_async_readpages_req);
+#endif
+
+#ifdef CEPH_TRACE_NET_OSDC
+DEFINE_CEPH_START_REQ_EVENT(ceph_osdc_writepages_req);
+DEFINE_CEPH_START_REQ_EVENT(ceph_osdc_readpages_req);
+#endif
+
+
+#endif /* _TRACE_CEPH_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
index 5e25405..f44e400 100644
--- a/net/ceph/osd_client.c
+++ b/net/ceph/osd_client.c
@@ -18,6 +18,11 @@
#include <linux/ceph/auth.h>
#include <linux/ceph/pagelist.h>
+#include <linux/tracepoint.h>
+#define CREATE_TRACE_POINTS
+#define CEPH_TRACE_NET_OSDC
+#include <trace/events/ceph.h>
+
#define OSD_OP_FRONT_LEN 4096
#define OSD_OPREPLY_FRONT_LEN 512
@@ -1906,6 +1911,7 @@ int ceph_osdc_readpages(struct ceph_osd_client *osdc,
off, *plen, req->r_num_pages, page_align);
rc = ceph_osdc_start_request(osdc, req, false);
+ trace_ceph_osdc_readpages_req(req);
if (!rc)
rc = ceph_osdc_wait_request(osdc, req);
@@ -1948,6 +1954,7 @@ int ceph_osdc_writepages(struct ceph_osd_client *osdc, struct ceph_vino vino,
req->r_num_pages);
rc = ceph_osdc_start_request(osdc, req, nofail);
+ trace_ceph_osdc_writepages_req(req);
if (!rc)
rc = ceph_osdc_wait_request(osdc, req);
--
1.7.8.2
^ permalink raw reply related [flat|nested] 4+ messages in thread* [PATCH 2/2] ceph: add tracepoints for message send queueing and completion, reply handling
2012-05-10 14:35 [PATCH 0/2] Ceph tracepoints Jim Schutt
2012-05-10 14:35 ` [PATCH 1/2] ceph: add tracepoints for message submission on read/write requests Jim Schutt
@ 2012-05-10 14:35 ` Jim Schutt
2012-05-10 15:39 ` [PATCH 0/2] Ceph tracepoints Alex Elder
2 siblings, 0 replies; 4+ messages in thread
From: Jim Schutt @ 2012-05-10 14:35 UTC (permalink / raw)
To: elder; +Cc: ceph-devel, Jim Schutt
Signed-off-by: Jim Schutt <jaschut@sandia.gov>
---
include/trace/events/ceph.h | 67 +++++++++++++++++++++++++++++++++++++++++++
net/ceph/messenger.c | 9 +++++-
net/ceph/osd_client.c | 1 +
3 files changed, 76 insertions(+), 1 deletions(-)
diff --git a/include/trace/events/ceph.h b/include/trace/events/ceph.h
index 182af2c..b390f78 100644
--- a/include/trace/events/ceph.h
+++ b/include/trace/events/ceph.h
@@ -4,6 +4,9 @@
#if !defined(_TRACE_CEPH_H) || defined(TRACE_HEADER_MULTI_READ)
#define _TRACE_CEPH_H
+#if defined(CEPH_TRACE_FS_FILE) \
+ || defined(CEPH_TRACE_FS_ADDR) \
+ || defined(CEPH_TRACE_NET_OSDC)
#if !defined(TRACE_HEADER_MULTI_READ)
@@ -68,8 +71,72 @@ DEFINE_CEPH_START_REQ_EVENT(ceph_async_readpages_req);
#ifdef CEPH_TRACE_NET_OSDC
DEFINE_CEPH_START_REQ_EVENT(ceph_osdc_writepages_req);
DEFINE_CEPH_START_REQ_EVENT(ceph_osdc_readpages_req);
+
+TRACE_EVENT(ceph_handle_reply_msg,
+ TP_PROTO(struct ceph_connection *con,
+ struct ceph_msg *msg,
+ struct ceph_osd_reply_head *reply,
+ void *req),
+ TP_ARGS(con, msg, reply, req),
+ TP_STRUCT__entry(
+ __field(unsigned long long, tid)
+ __field(long long, peer_num)
+ __field(void*, req)
+ __field(unsigned, peer_type)
+ __field(int, result)
+ __field(int, flags)
+ ),
+ TP_fast_assign(
+ __entry->tid = le64_to_cpu(msg->hdr.tid);
+ __entry->peer_num = le64_to_cpu(con->peer_name.num);
+ __entry->peer_type = con->peer_name.type;
+ __entry->req = req;
+ __entry->result = le32_to_cpu(reply->result);
+ __entry->flags = le32_to_cpu(reply->flags);
+ ),
+ TP_printk("peer %s%lld tid %llu result %d flags 0x%08x (req %p)",
+ ceph_entity_type_name(__entry->peer_type), __entry->peer_num,
+ __entry->tid, __entry->result, __entry->flags, __entry->req
+ )
+);
#endif
+#endif /* CEPH_TRACE_FS_FILE || CEPH_TRACE_FS_ADDR || CEPH_TRACE_NET_OSDC */
+
+#if defined(CEPH_TRACE_NET_MESSENGER)
+
+DECLARE_EVENT_CLASS(ceph_write_msg_class,
+ TP_PROTO(struct ceph_connection *con, struct ceph_msg *msg),
+ TP_ARGS(con, msg),
+ TP_STRUCT__entry(
+ __field(unsigned long long, tid)
+ __field(unsigned long long, seq)
+ __field(long long, peer_num)
+ __field(unsigned, peer_type)
+ __field(int, sent)
+ ),
+ TP_fast_assign(
+ __entry->tid = le64_to_cpu(msg->hdr.tid);
+ __entry->seq = le64_to_cpu(msg->hdr.seq);
+ __entry->peer_num = le64_to_cpu(con->peer_name.num);
+ __entry->peer_type = con->peer_name.type;
+ __entry->sent = con->out_msg_pos.data_pos;
+ ),
+ TP_printk("peer %s%lld tid %llu seq %llu sent %d",
+ ceph_entity_type_name(__entry->peer_type), __entry->peer_num,
+ __entry->tid, __entry->seq, __entry->sent)
+);
+
+#define CEPH_WRITE_MSG_EVENT(name) \
+DEFINE_EVENT(ceph_write_msg_class, name, \
+ TP_PROTO(struct ceph_connection *con, struct ceph_msg *msg), \
+ TP_ARGS(con, msg))
+
+CEPH_WRITE_MSG_EVENT(ceph_prepare_write_msg);
+CEPH_WRITE_MSG_EVENT(ceph_try_write_msg);
+CEPH_WRITE_MSG_EVENT(ceph_try_write_msg_done);
+
+#endif /* CEPH_TRACE_NET_MESSENGER */
#endif /* _TRACE_CEPH_H */
diff --git a/net/ceph/messenger.c b/net/ceph/messenger.c
index ad5b708..033c4ab 100644
--- a/net/ceph/messenger.c
+++ b/net/ceph/messenger.c
@@ -20,6 +20,11 @@
#include <linux/ceph/pagelist.h>
#include <linux/export.h>
+#include <linux/tracepoint.h>
+#define CREATE_TRACE_POINTS
+#define CEPH_TRACE_NET_MESSENGER
+#include <trace/events/ceph.h>
+
/*
* Ceph uses the messenger to exchange ceph_msg messages with other
* hosts in the system. The messenger provides ordered and reliable
@@ -555,7 +560,7 @@ static void prepare_write_message(struct ceph_connection *con)
/* no, queue up footer too and be done */
prepare_write_message_footer(con, v);
}
-
+ trace_ceph_prepare_write_msg(con, m);
set_bit(WRITE_PENDING, &con->state);
}
@@ -1853,8 +1858,10 @@ more_kvec:
/* msg pages? */
if (con->out_msg) {
+ trace_ceph_try_write_msg(con, con->out_msg);
if (con->out_msg_done) {
ceph_msg_put(con->out_msg);
+ trace_ceph_try_write_msg_done(con, con->out_msg);
con->out_msg = NULL; /* we're done with this one */
goto do_next;
}
diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
index f44e400..767e253 100644
--- a/net/ceph/osd_client.c
+++ b/net/ceph/osd_client.c
@@ -1200,6 +1200,7 @@ static void handle_reply(struct ceph_osd_client *osdc, struct ceph_msg *msg,
/* lookup */
mutex_lock(&osdc->request_mutex);
req = __lookup_request(osdc, tid);
+ trace_ceph_handle_reply_msg(con, msg, rhead, req);
if (req == NULL) {
dout("handle_reply tid %llu dne\n", tid);
mutex_unlock(&osdc->request_mutex);
--
1.7.8.2
^ permalink raw reply related [flat|nested] 4+ messages in thread* Re: [PATCH 0/2] Ceph tracepoints
2012-05-10 14:35 [PATCH 0/2] Ceph tracepoints Jim Schutt
2012-05-10 14:35 ` [PATCH 1/2] ceph: add tracepoints for message submission on read/write requests Jim Schutt
2012-05-10 14:35 ` [PATCH 2/2] ceph: add tracepoints for message send queueing and completion, reply handling Jim Schutt
@ 2012-05-10 15:39 ` Alex Elder
2 siblings, 0 replies; 4+ messages in thread
From: Alex Elder @ 2012-05-10 15:39 UTC (permalink / raw)
To: Jim Schutt; +Cc: elder, ceph-devel
On 05/10/2012 09:35 AM, Jim Schutt wrote:
> Hi Alex,
>
> I ran across tracker #2374 today - I've been carrying these two
> tracepoint patches for a while. Perhaps you'll find them useful.
GREAT!
I haven't looked at them but I will as soon as I get the chance.
I don't expect there's any reason not to use this as the foundation
I was looking for.
Thanks a lot.
-Alex
> Jim Schutt (2):
> ceph: add tracepoints for message submission on read/write requests
> ceph: add tracepoints for message send queueing and completion, reply
> handling
>
> fs/ceph/addr.c | 8 +++
> fs/ceph/file.c | 6 ++
> include/trace/events/ceph.h | 144 +++++++++++++++++++++++++++++++++++++++++++
> net/ceph/messenger.c | 9 +++-
> net/ceph/osd_client.c | 8 +++
> 5 files changed, 174 insertions(+), 1 deletions(-)
> create mode 100644 include/trace/events/ceph.h
>
^ permalink raw reply [flat|nested] 4+ messages in thread