Skip to contentSkip to conversation

driver data: pass zfcp data through blktrace

PATCH In review Martin Peschke 3 participants 5 messages Jul 16, 2008 – Oct 6, 2008

Subsystems (2)
lore
Share & tools
lore
#0 lore raw

PATCH 2/3 driver data: pass zfcp data through blktrace

From: Stefan Raspl <[email protected]>

This patch writes the channel and fabric latencies in nanoseconds per request via blktrace for later analysis. The utilization of the inbound and outbound adapter queue is also reported.

---
 drivers/s390/scsi/zfcp_def.h  |    2 ++
 drivers/s390/scsi/zfcp_fsf.c  |   32 ++++++++++++++++++++++++++++++++
 drivers/s390/scsi/zfcp_fsf.h  |   12 ++++++++++++
 drivers/s390/scsi/zfcp_qdio.c |    1 +
 4 files changed, 47 insertions(+)
drivers/s390/scsi/zfcp_fsf.c +32 -0
@@ -6,6 +6,7 @@
  * Copyright IBM Corporation 2002, 2008
  */
 
+#include <linux/blktrace_api.h>
 #include "zfcp_ext.h"
 
 static void zfcp_fsf_request_timeout_handler(unsigned long data)
@@ -844,6 +845,7 @@ static int zfcp_fsf_req_send(struct zfcp
 	list_add_tail(&req->list, &adapter->req_list[idx]);
 	spin_unlock(&adapter->req_list_lock);
 
+	req->qdio_outb_usage = atomic_read(&req_q->count);
 	req->issued = get_clock();
 	if (zfcp_qdio_send(req)) {
 		/* Queues are down..... */
@@ -2046,6 +2048,34 @@ static void zfcp_fsf_req_latency(struct 
 	spin_unlock_irqrestore(&unit->latencies.lock, flags);
 }
 
+#ifdef CONFIG_BLK_DEV_IO_TRACE
+static void zfcp_fsf_trace_latency(struct zfcp_fsf_req *fsf_req)
+{
+	struct fsf_qual_latency_info *lat_inf;
+	struct scsi_cmnd *scsi_cmnd = (struct scsi_cmnd *)fsf_req->data;
+	struct request *req = scsi_cmnd->request;
+	struct zfcp_blk_drv_data trace;
+	int ticks = fsf_req->adapter->timer_ticks;
+
+	trace.flags = 0;
+	trace.magic = cpu_to_be32(ZFCP_BLK_DRV_DATA_MAGIC);
+	if (fsf_req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA) {
+		trace.flags |= ZFCP_BLK_LAT_VALID;
+		lat_inf = &fsf_req->qtcb->prefix.prot_status_qual.latency_info;
+		trace.channel_lat = cpu_to_be64(lat_inf->channel_lat * ticks);
+		trace.fabric_lat = cpu_to_be64(lat_inf->fabric_lat * ticks);
+	}
+	if (fsf_req->status & ZFCP_STATUS_FSFREQ_ERROR)
+		trace.flags |= ZFCP_BLK_REQ_ERROR;
+	trace.inb_usage = cpu_to_be16(fsf_req->qdio_inb_usage);
+	trace.outb_usage = cpu_to_be16(fsf_req->qdio_outb_usage);
+
+	blk_add_driver_data(req->q, req, &trace, sizeof(trace));
+}
+#else
+#define zfcp_fsf_trace_latency(fsf_req)	do { } while (0)
+#endif
+
 static void zfcp_fsf_send_fcp_command_task_handler(struct zfcp_fsf_req *req)
 {
 	struct scsi_cmnd *scpnt = req->data;
@@ -2078,6 +2108,8 @@ static void zfcp_fsf_send_fcp_command_ta
 	if (req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA)
 		zfcp_fsf_req_latency(req);
 
+	zfcp_fsf_trace_latency(req);
+
 	if (unlikely(fcp_rsp_iu->validity.bits.fcp_rsp_len_valid)) {
 		if (fcp_rsp_info[3] = RSP_CODE_GOOD)
 			set_host_byte(scpnt, DID_OK);
drivers/s390/scsi/zfcp_def.h +2 -0
@@ -639,6 +639,8 @@ struct zfcp_fsf_req {
 	unsigned long long     issued;         /* request sent time (STCK) */
 	struct zfcp_unit       *unit;
 	void			(*handler)(struct zfcp_fsf_req *);
+	u16			qdio_outb_usage;/* usage of outbound queue */
+	u16			qdio_inb_usage;	/* usage of inbound queue */
 };
 
 /* driver data */
drivers/s390/scsi/zfcp_qdio.c +1 -0
@@ -117,6 +117,7 @@ static void zfcp_qdio_reqid_check(struct
 	spin_unlock_irqrestore(&adapter->req_list_lock, flags);
 
 	fsf_req->sbal_response = sbal_idx;
+	fsf_req->qdio_inb_usage = atomic_read(&adapter->resp_q.count);
 	zfcp_fsf_req_complete(fsf_req);
 }
 
drivers/s390/scsi/zfcp_fsf.h +12 -0
@@ -514,4 +514,16 @@ struct fsf_qtcb {
 	u8 log[FSF_QTCB_LOG_SIZE];
 } __attribute__ ((packed));
 
+struct zfcp_blk_drv_data {
+#define ZFCP_BLK_DRV_DATA_MAGIC			0x1
+	u32 magic;
+#define ZFCP_BLK_LAT_VALID			0x1
+#define ZFCP_BLK_REQ_ERROR			0x2
+	u16 flags;
+	u8 inb_usage;
+	u8 outb_usage;
+	u64 channel_lat;
+	u64 fabric_lat;
+} __attribute__ ((packed));
+
 #endif				/* FSF_H */
#1 lore raw

PATCH 2/3 driver data: pass zfcp data through blktrace

From: Stefan Raspl <[email protected]>

This patch writes the channel and fabric latencies in nanoseconds per request via blktrace for later analysis. The utilization of the inbound and outbound adapter queue is also reported.

---
 drivers/s390/scsi/zfcp_def.h  |    2 ++
 drivers/s390/scsi/zfcp_fsf.c  |   32 ++++++++++++++++++++++++++++++++
 drivers/s390/scsi/zfcp_fsf.h  |   12 ++++++++++++
 drivers/s390/scsi/zfcp_qdio.c |    1 +
 4 files changed, 47 insertions(+)
drivers/s390/scsi/zfcp_fsf.c +32 -0
@@ -6,6 +6,7 @@
  * Copyright IBM Corporation 2002, 2008
  */
 
+#include <linux/blktrace_api.h>
 #include "zfcp_ext.h"
 
 static void zfcp_fsf_request_timeout_handler(unsigned long data)
@@ -777,6 +778,7 @@ static int zfcp_fsf_req_send(struct zfcp
 	list_add_tail(&req->list, &adapter->req_list[idx]);
 	spin_unlock(&adapter->req_list_lock);
 
+	req->qdio_outb_usage = atomic_read(&req_q->count);
 	req->issued = get_clock();
 	if (zfcp_qdio_send(req)) {
 		/* Queues are down..... */
@@ -2082,6 +2084,34 @@ static void zfcp_fsf_req_latency(struct 
 	spin_unlock_irqrestore(&unit->latencies.lock, flags);
 }
 
+#ifdef CONFIG_BLK_DEV_IO_TRACE
+static void zfcp_fsf_trace_latency(struct zfcp_fsf_req *fsf_req)
+{
+	struct fsf_qual_latency_info *lat_inf;
+	struct scsi_cmnd *scsi_cmnd = (struct scsi_cmnd *)fsf_req->data;
+	struct request *req = scsi_cmnd->request;
+	struct zfcp_blk_drv_data trace;
+	int ticks = fsf_req->adapter->timer_ticks;
+
+	trace.flags = 0;
+	trace.magic = cpu_to_be32(ZFCP_BLK_DRV_DATA_MAGIC);
+	if (fsf_req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA) {
+		trace.flags |= ZFCP_BLK_LAT_VALID;
+		lat_inf = &fsf_req->qtcb->prefix.prot_status_qual.latency_info;
+		trace.channel_lat = cpu_to_be64(lat_inf->channel_lat * ticks);
+		trace.fabric_lat = cpu_to_be64(lat_inf->fabric_lat * ticks);
+	}
+	if (fsf_req->status & ZFCP_STATUS_FSFREQ_ERROR)
+		trace.flags |= ZFCP_BLK_REQ_ERROR;
+	trace.inb_usage = cpu_to_be16(fsf_req->qdio_inb_usage);
+	trace.outb_usage = cpu_to_be16(fsf_req->qdio_outb_usage);
+
+	blk_add_driver_data(req->q, req, &trace, sizeof(trace));
+}
+#else
+#define zfcp_fsf_trace_latency(fsf_req)	do { } while (0)
+#endif
+
 static void zfcp_fsf_send_fcp_command_task_handler(struct zfcp_fsf_req *req)
 {
 	struct scsi_cmnd *scpnt = req->data;
@@ -2114,6 +2144,8 @@ static void zfcp_fsf_send_fcp_command_ta
 	if (req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA)
 		zfcp_fsf_req_latency(req);
 
+	zfcp_fsf_trace_latency(req);
+
 	if (unlikely(fcp_rsp_iu->validity.bits.fcp_rsp_len_valid)) {
 		if (fcp_rsp_info[3] = RSP_CODE_GOOD)
 			set_host_byte(scpnt, DID_OK);
drivers/s390/scsi/zfcp_def.h +2 -0
@@ -583,6 +583,8 @@ struct zfcp_fsf_req {
 	unsigned long long     issued;         /* request sent time (STCK) */
 	struct zfcp_unit       *unit;
 	void			(*handler)(struct zfcp_fsf_req *);
+	u16			qdio_outb_usage;/* usage of outbound queue */
+	u16			qdio_inb_usage;	/* usage of inbound queue */
 };
 
 /* driver data */
drivers/s390/scsi/zfcp_qdio.c +1 -0
@@ -115,6 +115,7 @@ static void zfcp_qdio_reqid_check(struct
 	spin_unlock_irqrestore(&adapter->req_list_lock, flags);
 
 	fsf_req->sbal_response = sbal_idx;
+	fsf_req->qdio_inb_usage = atomic_read(&adapter->resp_q.count);
 	zfcp_fsf_req_complete(fsf_req);
 }
 
drivers/s390/scsi/zfcp_fsf.h +12 -0
@@ -439,4 +439,16 @@ struct fsf_qtcb {
 	u8 log[FSF_QTCB_LOG_SIZE];
 } __attribute__ ((packed));
 
+struct zfcp_blk_drv_data {
+#define ZFCP_BLK_DRV_DATA_MAGIC			0x1
+	u32 magic;
+#define ZFCP_BLK_LAT_VALID			0x1
+#define ZFCP_BLK_REQ_ERROR			0x2
+	u16 flags;
+	u8 inb_usage;
+	u8 outb_usage;
+	u64 channel_lat;
+	u64 fabric_lat;
+} __attribute__ ((packed));
+
 #endif				/* FSF_H */
#2 lore raw
In reply to Martin Peschke

drivers/s390/scsi/zfcp_fsf.c static void zfcp_fsf_req_latency(struct · line 2071

Quoted 12 lines
drivers/s390/scsi/zfcp_fsf.c +12 -0
+	trace.flags = 0;
+	trace.magic = cpu_to_be32(ZFCP_BLK_DRV_DATA_MAGIC);
+	if (fsf_req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA) {
+		trace.flags |= ZFCP_BLK_LAT_VALID;
+		lat_inf = &fsf_req->qtcb->prefix.prot_status_qual.latency_info;
+		trace.channel_lat = cpu_to_be64(lat_inf->channel_lat * ticks);
+		trace.fabric_lat = cpu_to_be64(lat_inf->fabric_lat * ticks);
+	}
+	if (fsf_req->status & ZFCP_STATUS_FSFREQ_ERROR)
+		trace.flags |= ZFCP_BLK_REQ_ERROR;
+	trace.inb_usage = cpu_to_be16(fsf_req->qdio_inb_usage);
+	trace.outb_usage = cpu_to_be16(fsf_req->qdio_outb_usage);

Could we please not add any cpu_to_be* calls to s390 only code? s390 is a big endian architecture and therefore these calls are confusing and pointless.

drivers/s390/scsi/zfcp_fsf.c static void zfcp_fsf_req_latency(struct · line 2077

Quoted 3 lines
drivers/s390/scsi/zfcp_fsf.c +3 -0
+#else
+#define zfcp_fsf_trace_latency(fsf_req)	do { } while (0)
+#endif

Please convert that to a static inline function for type checking.

Thanks.

#3 lore raw
In reply to Martin Peschke
Quoted 16 lines · Heiko Carstens

drivers/s390/scsi/zfcp_fsf.c static void zfcp_fsf_req_latency(struct · line 2071

Quoted 12 lines
drivers/s390/scsi/zfcp_fsf.c +12 -0
+	trace.flags = 0;
+	trace.magic = cpu_to_be32(ZFCP_BLK_DRV_DATA_MAGIC);
+	if (fsf_req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA) {
+		trace.flags |= ZFCP_BLK_LAT_VALID;
+		lat_inf = &fsf_req->qtcb->prefix.prot_status_qual.latency_info;
+		trace.channel_lat = cpu_to_be64(lat_inf->channel_lat * ticks);
+		trace.fabric_lat = cpu_to_be64(lat_inf->fabric_lat * ticks);
+	}
+	if (fsf_req->status & ZFCP_STATUS_FSFREQ_ERROR)
+		trace.flags |= ZFCP_BLK_REQ_ERROR;
+	trace.inb_usage = cpu_to_be16(fsf_req->qdio_inb_usage);
+	trace.outb_usage = cpu_to_be16(fsf_req->qdio_outb_usage);

Could we please not add any cpu_to_be* calls to s390 only code? s390 is a big endian architecture and therefore these calls are confusing and pointless.

Quoted 5 lines

drivers/s390/scsi/zfcp_fsf.c static void zfcp_fsf_req_latency(struct · line 2077

Quoted 3 lines
drivers/s390/scsi/zfcp_fsf.c +3 -0
+#else
+#define zfcp_fsf_trace_latency(fsf_req)	do { } while (0)
+#endif

Please convert that to a static inline function for type checking.

Correct. Fixed patch will follow..

Thanks,
Martin

#4 lore raw

PATCH 2/3 driver data: pass zfcp data through blktrace

Removed pointless cpu_to_be* and changed define to static inline.

From: Stefan Raspl <[email protected]>

This patch writes the channel and fabric latencies in nanoseconds per request via blktrace for later analysis. The utilization of the inbound and outbound adapter queue is also reported.

---
 drivers/s390/scsi/zfcp_def.h  |    2 ++
 drivers/s390/scsi/zfcp_fsf.c  |   34 ++++++++++++++++++++++++++++++++++
 drivers/s390/scsi/zfcp_fsf.h  |   12 ++++++++++++
 drivers/s390/scsi/zfcp_qdio.c |    1 +
 4 files changed, 49 insertions(+)
drivers/s390/scsi/zfcp_fsf.c +34 -0
@@ -6,6 +6,7 @@
  * Copyright IBM Corporation 2002, 2008
  */
 
+#include <linux/blktrace_api.h>
 #include "zfcp_ext.h"
 
 static void zfcp_fsf_request_timeout_handler(unsigned long data)
@@ -777,6 +778,7 @@ static int zfcp_fsf_req_send(struct zfcp
 	list_add_tail(&req->list, &adapter->req_list[idx]);
 	spin_unlock(&adapter->req_list_lock);
 
+	req->qdio_outb_usage = atomic_read(&req_q->count);
 	req->issued = get_clock();
 	if (zfcp_qdio_send(req)) {
 		/* Queues are down..... */
@@ -2082,6 +2084,36 @@ static void zfcp_fsf_req_latency(struct 
 	spin_unlock_irqrestore(&unit->latencies.lock, flags);
 }
 
+#ifdef CONFIG_BLK_DEV_IO_TRACE
+static void zfcp_fsf_trace_latency(struct zfcp_fsf_req *fsf_req)
+{
+	struct fsf_qual_latency_info *lat_inf;
+	struct scsi_cmnd *scsi_cmnd = (struct scsi_cmnd *)fsf_req->data;
+	struct request *req = scsi_cmnd->request;
+	struct zfcp_blk_drv_data trace;
+	int ticks = fsf_req->adapter->timer_ticks;
+
+	trace.flags = 0;
+	trace.magic = ZFCP_BLK_DRV_DATA_MAGIC;
+	if (fsf_req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA) {
+		trace.flags |= ZFCP_BLK_LAT_VALID;
+		lat_inf = &fsf_req->qtcb->prefix.prot_status_qual.latency_info;
+		trace.channel_lat = lat_inf->channel_lat * ticks;
+		trace.fabric_lat = lat_inf->fabric_lat * ticks;
+	}
+	if (fsf_req->status & ZFCP_STATUS_FSFREQ_ERROR)
+		trace.flags |= ZFCP_BLK_REQ_ERROR;
+	trace.inb_usage = fsf_req->qdio_inb_usage;
+	trace.outb_usage = fsf_req->qdio_outb_usage;
+
+	blk_add_driver_data(req->q, req, &trace, sizeof(trace));
+}
+#else
+static inline void zfcp_fsf_trace_latency(struct zfcp_fsf_req *fsf_req)
+{
+}
+#endif
+
 static void zfcp_fsf_send_fcp_command_task_handler(struct zfcp_fsf_req *req)
 {
 	struct scsi_cmnd *scpnt = req->data;
@@ -2114,6 +2146,8 @@ static void zfcp_fsf_send_fcp_command_ta
 	if (req->adapter->adapter_features & FSF_FEATURE_MEASUREMENT_DATA)
 		zfcp_fsf_req_latency(req);
 
+	zfcp_fsf_trace_latency(req);
+
 	if (unlikely(fcp_rsp_iu->validity.bits.fcp_rsp_len_valid)) {
 		if (fcp_rsp_info[3] = RSP_CODE_GOOD)
 			set_host_byte(scpnt, DID_OK);
drivers/s390/scsi/zfcp_def.h +2 -0
@@ -583,6 +583,8 @@ struct zfcp_fsf_req {
 	unsigned long long     issued;         /* request sent time (STCK) */
 	struct zfcp_unit       *unit;
 	void			(*handler)(struct zfcp_fsf_req *);
+	u16			qdio_outb_usage;/* usage of outbound queue */
+	u16			qdio_inb_usage;	/* usage of inbound queue */
 };
 
 /* driver data */
drivers/s390/scsi/zfcp_qdio.c +1 -0
@@ -115,6 +115,7 @@ static void zfcp_qdio_reqid_check(struct
 	spin_unlock_irqrestore(&adapter->req_list_lock, flags);
 
 	fsf_req->sbal_response = sbal_idx;
+	fsf_req->qdio_inb_usage = atomic_read(&adapter->resp_q.count);
 	zfcp_fsf_req_complete(fsf_req);
 }
 
drivers/s390/scsi/zfcp_fsf.h +12 -0
@@ -439,4 +439,16 @@ struct fsf_qtcb {
 	u8 log[FSF_QTCB_LOG_SIZE];
 } __attribute__ ((packed));
 
+struct zfcp_blk_drv_data {
+#define ZFCP_BLK_DRV_DATA_MAGIC			0x1
+	u32 magic;
+#define ZFCP_BLK_LAT_VALID			0x1
+#define ZFCP_BLK_REQ_ERROR			0x2
+	u16 flags;
+	u8 inb_usage;
+	u8 outb_usage;
+	u64 channel_lat;
+	u64 fabric_lat;
+} __attribute__ ((packed));
+
 #endif				/* FSF_H */