Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 5d75a20f authored by Mohan Srinivasan's avatar Mohan Srinivasan
Browse files

Android: MMC/UFS IO Latency Histograms. 



This patch adds a new sysfs node (latency_hist) and reports
IO (svc time) latency histograms. Disabled by default, can be
enabled by echoing 0 into latency_hist, stats can be cleared
by writing 2 into latency_hist.

Bug: 30677035
Change-Id: Ic6c2ef660aa686e2b32142af4769a3b9e1d0a172
Signed-off-by: default avatarMohan Srinivasan <srmohan@google.com>
parent d519f95a

block/blk-core.c

+80 −0
Original line number Diff line number Diff line
@@ -3321,3 +3321,83 @@ int __init blk_dev_init(void) 


	return 0;

}



/*

 * Blk IO latency support. We want this to be as cheap as possible, so doing

 * this lockless (and avoiding atomics), a few off by a few errors in this

 * code is not harmful, and we don't want to do anything that is

 * perf-impactful.

 * TODO : If necessary, we can make the histograms per-cpu and aggregate

 * them when printing them out.

 */

void

blk_zero_latency_hist(struct io_latency_state *s)

{

	memset(s->latency_y_axis_read, 0,

	       sizeof(s->latency_y_axis_read));

	memset(s->latency_y_axis_write, 0,

	       sizeof(s->latency_y_axis_write));

	s->latency_reads_elems = 0;

	s->latency_writes_elems = 0;

}



ssize_t

blk_latency_hist_show(struct io_latency_state *s, char *buf)

{

	int i;

	int bytes_written = 0;

	int pct, num_elem;

	u_int64_t elem;



	num_elem = s->latency_reads_elems;

	if (num_elem > 0) {

		bytes_written += scnprintf(buf + bytes_written,

			   PAGE_SIZE - bytes_written,

			   "IO svc_time Read Latency Histogram (n = %d):\n",

			   num_elem);

		for (i = 0;

		     i < ARRAY_SIZE(latency_x_axis_us);

		     i++) {

			elem = s->latency_y_axis_read[i];

			pct = (elem * 100) / num_elem;

			bytes_written += scnprintf(buf + bytes_written,

						   PAGE_SIZE - bytes_written,

						   "\t< %5lluus%15llu%15d%%\n",

						   latency_x_axis_us[i],

						   elem, pct);

		}

		/* Last element in y-axis table is overflow */

		elem = s->latency_y_axis_read[i];

		pct = (elem * 100) / num_elem;

		bytes_written += scnprintf(buf + bytes_written,

					   PAGE_SIZE - bytes_written,

					   "\t> %5dms%15llu%15d%%\n", 10,

					   elem, pct);

	}

	num_elem = s->latency_writes_elems;

	if (num_elem > 0) {

		bytes_written += scnprintf(buf + bytes_written,

			   PAGE_SIZE - bytes_written,

			   "IO svc_time Write Latency Histogram (n = %d):\n",

			   num_elem);

		for (i = 0;

		     i < ARRAY_SIZE(latency_x_axis_us);

		     i++) {

			elem = s->latency_y_axis_write[i];

			pct = (elem * 100) / num_elem;

			bytes_written += scnprintf(buf + bytes_written,

						   PAGE_SIZE - bytes_written,

						   "\t< %5lluus%15llu%15d%%\n",

						   latency_x_axis_us[i],

						   elem, pct);

		}

		/* Last element in y-axis table is overflow */

		elem = s->latency_y_axis_write[i];

		pct = (elem * 100) / num_elem;

		bytes_written += scnprintf(buf + bytes_written,

					   PAGE_SIZE - bytes_written,

					   "\t> %5dms%15llu%15d%%\n", 10,

					   elem, pct);

	}

	return bytes_written;

}

drivers/mmc/core/core.c

+65 −1
Original line number Diff line number Diff line
@@ -160,6 +160,17 @@ void mmc_request_done(struct mmc_host *host, struct mmc_request *mrq) 
			pr_debug("%s:     %d bytes transferred: %d\n",

				mmc_hostname(host),

				mrq->data->bytes_xfered, mrq->data->error);

			if (mrq->lat_hist_enabled) {

				ktime_t completion;

				u_int64_t delta_us;



				completion = ktime_get();

				delta_us = ktime_us_delta(completion,

							  mrq->io_start);

				blk_update_latency_hist(&host->io_lat_s,

					(mrq->data->flags & MMC_DATA_READ),

					delta_us);

			}

			trace_mmc_blk_rw_end(cmd->opcode, cmd->arg, mrq->data);

		}
@@ -546,6 +557,11 @@ struct mmc_async_req *mmc_start_req(struct mmc_host *host, 
	}



	if (!err && areq) {

		if (host->latency_hist_enabled) {

			areq->mrq->io_start = ktime_get();

			areq->mrq->lat_hist_enabled = 1;

		} else

			areq->mrq->lat_hist_enabled = 0;

		trace_mmc_blk_rw_start(areq->mrq->cmd->opcode,

				       areq->mrq->cmd->arg,

				       areq->mrq->data);
@@ -2740,6 +2756,54 @@ static void __exit mmc_exit(void) 
	destroy_workqueue(workqueue);

}



static ssize_t

latency_hist_show(struct device *dev, struct device_attribute *attr, char *buf)

{

	struct mmc_host *host = cls_dev_to_mmc_host(dev);



	return blk_latency_hist_show(&host->io_lat_s, buf);

}



/*

 * Values permitted 0, 1, 2.

 * 0 -> Disable IO latency histograms (default)

 * 1 -> Enable IO latency histograms

 * 2 -> Zero out IO latency histograms

 */

static ssize_t

latency_hist_store(struct device *dev, struct device_attribute *attr,

		   const char *buf, size_t count)

{

	struct mmc_host *host = cls_dev_to_mmc_host(dev);

	long value;



	if (kstrtol(buf, 0, &value))

		return -EINVAL;

	if (value == BLK_IO_LAT_HIST_ZERO)

		blk_zero_latency_hist(&host->io_lat_s);

	else if (value == BLK_IO_LAT_HIST_ENABLE ||

		 value == BLK_IO_LAT_HIST_DISABLE)

		host->latency_hist_enabled = value;

	return count;

}



static DEVICE_ATTR(latency_hist, S_IRUGO | S_IWUSR,

		   latency_hist_show, latency_hist_store);



void

mmc_latency_hist_sysfs_init(struct mmc_host *host)

{

	if (device_create_file(&host->class_dev, &dev_attr_latency_hist))

		dev_err(&host->class_dev,

			"Failed to create latency_hist sysfs entry\n");

}



void

mmc_latency_hist_sysfs_exit(struct mmc_host *host)

{

	device_remove_file(&host->class_dev, &dev_attr_latency_hist);

}



subsys_initcall(mmc_init);

module_exit(mmc_exit);

drivers/mmc/core/host.c

+3 −2
Original line number Diff line number Diff line
@@ -30,8 +30,6 @@ 
#include "core.h"

#include "host.h"



#define cls_dev_to_mmc_host(d)	container_of(d, struct mmc_host, class_dev)



static void mmc_host_classdev_release(struct device *dev)

{

	struct mmc_host *host = cls_dev_to_mmc_host(dev);
@@ -558,6 +556,7 @@ int mmc_add_host(struct mmc_host *host) 
	mmc_add_host_debugfs(host);

#endif

	mmc_host_clk_sysfs_init(host);

	mmc_latency_hist_sysfs_init(host);



	mmc_start_host(host);

	if (!(host->pm_flags & MMC_PM_IGNORE_PM_NOTIFY))
@@ -587,6 +586,8 @@ void mmc_remove_host(struct mmc_host *host) 
	mmc_remove_host_debugfs(host);

#endif



	mmc_latency_hist_sysfs_exit(host);



	device_del(&host->class_dev);



	led_trigger_unregister_simple(host->led);

drivers/mmc/core/host.h

+5 −0
Original line number Diff line number Diff line
@@ -12,8 +12,13 @@ 
#define _MMC_CORE_HOST_H

#include <linux/mmc/host.h>



#define cls_dev_to_mmc_host(d)	container_of(d, struct mmc_host, class_dev)



int mmc_register_host_class(void);

void mmc_unregister_host_class(void);



void mmc_latency_hist_sysfs_init(struct mmc_host *host);

void mmc_latency_hist_sysfs_exit(struct mmc_host *host);



#endif

drivers/scsi/ufs/ufshcd.c

+80 −0
Original line number Diff line number Diff line
@@ -39,6 +39,7 @@ 


#include <linux/async.h>

#include <linux/devfreq.h>

#include <linux/blkdev.h>



#include "ufshcd.h"

#include "unipro.h"
@@ -1313,6 +1314,16 @@ static int ufshcd_queuecommand(struct Scsi_Host *host, struct scsi_cmnd *cmd) 
		clear_bit_unlock(tag, &hba->lrb_in_use);

		goto out;

	}

	/* IO svc time latency histogram */

	if (hba != NULL && cmd->request != NULL) {

		if (hba->latency_hist_enabled &&

		    (cmd->request->cmd_type == REQ_TYPE_FS)) {

			cmd->request->lat_hist_io_start = ktime_get();

			cmd->request->lat_hist_enabled = 1;

		} else

			cmd->request->lat_hist_enabled = 0;

	}



	WARN_ON(hba->clk_gating.state != CLKS_ON);



	lrbp = &hba->lrb[tag];
@@ -3051,6 +3062,7 @@ static void ufshcd_transfer_req_compl(struct ufs_hba *hba) 
	u32 tr_doorbell;

	int result;

	int index;

	struct request *req;



	/* Resetting interrupt aggregation counters first and reading the

	 * DOOR_BELL afterward allows us to handle all the completed requests.
@@ -3074,6 +3086,22 @@ static void ufshcd_transfer_req_compl(struct ufs_hba *hba) 
			/* Mark completed command as NULL in LRB */

			lrbp->cmd = NULL;

			clear_bit_unlock(index, &hba->lrb_in_use);

			req = cmd->request;

			if (req) {

				/* Update IO svc time latency histogram */

				if (req->lat_hist_enabled) {

					ktime_t completion;

					u_int64_t delta_us;



					completion = ktime_get();

					delta_us = ktime_us_delta(completion,

						  req->lat_hist_io_start);

					/* rq_data_dir() => true if WRITE */

					blk_update_latency_hist(&hba->io_lat_s,

						(rq_data_dir(req) == READ),

						delta_us);

				}

			}

			/* Do not touch lrbp after scsi done */

			cmd->scsi_done(cmd);

			__ufshcd_release(hba);
@@ -5248,6 +5276,54 @@ out: 
}

EXPORT_SYMBOL(ufshcd_shutdown);



/*

 * Values permitted 0, 1, 2.

 * 0 -> Disable IO latency histograms (default)

 * 1 -> Enable IO latency histograms

 * 2 -> Zero out IO latency histograms

 */

static ssize_t

latency_hist_store(struct device *dev, struct device_attribute *attr,

		   const char *buf, size_t count)

{

	struct ufs_hba *hba = dev_get_drvdata(dev);

	long value;



	if (kstrtol(buf, 0, &value))

		return -EINVAL;

	if (value == BLK_IO_LAT_HIST_ZERO)

		blk_zero_latency_hist(&hba->io_lat_s);

	else if (value == BLK_IO_LAT_HIST_ENABLE ||

		 value == BLK_IO_LAT_HIST_DISABLE)

		hba->latency_hist_enabled = value;

	return count;

}



ssize_t

latency_hist_show(struct device *dev, struct device_attribute *attr,

		  char *buf)

{

	struct ufs_hba *hba = dev_get_drvdata(dev);



	return blk_latency_hist_show(&hba->io_lat_s, buf);

}



static DEVICE_ATTR(latency_hist, S_IRUGO | S_IWUSR,

		   latency_hist_show, latency_hist_store);



static void

ufshcd_init_latency_hist(struct ufs_hba *hba)

{

	if (device_create_file(hba->dev, &dev_attr_latency_hist))

		dev_err(hba->dev, "Failed to create latency_hist sysfs entry\n");

}



static void

ufshcd_exit_latency_hist(struct ufs_hba *hba)

{

	device_create_file(hba->dev, &dev_attr_latency_hist);

}



/**

 * ufshcd_remove - de-allocate SCSI host and host memory space

 *		data structure memory
@@ -5263,6 +5339,7 @@ void ufshcd_remove(struct ufs_hba *hba) 
	scsi_host_put(hba->host);



	ufshcd_exit_clk_gating(hba);

	ufshcd_exit_latency_hist(hba);

	if (ufshcd_is_clkscaling_enabled(hba))

		devfreq_remove_device(hba->devfreq);

	ufshcd_hba_exit(hba);
@@ -5552,6 +5629,8 @@ int ufshcd_init(struct ufs_hba *hba, void __iomem *mmio_base, unsigned int irq) 
	/* Hold auto suspend until async scan completes */

	pm_runtime_get_sync(dev);



	ufshcd_init_latency_hist(hba);



	/*

	 * The device-initialize-sequence hasn't been invoked yet.

	 * Set the device to power-off state
@@ -5566,6 +5645,7 @@ out_remove_scsi_host: 
	scsi_remove_host(hba->host);

exit_gating:

	ufshcd_exit_clk_gating(hba);

	ufshcd_exit_latency_hist(hba);

out_disable:

	hba->is_irq_enabled = false;

	scsi_host_put(host);