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

Commit fc2b8f06 authored by Hemant Kumar's avatar Hemant Kumar Committed by Mayank Rana
Browse files

usb: gadget: f_mtp: Add support to capture time taken with vfs_write/read 



This change captures time taken by each vfs_read() and vfs_write() call
made from USB MTP gadget driver where data size is equal to USB request
buffer size. It provides debugfs entry to get this information for 100
such call and resetting the same.

How-To use:
To get stats:
cat /sys/kernel/debug/usb_mtp/status
To reset stats:
echo 0 > /sys/kernel/debug/usb_mtp/status

Change-Id: I252e830568704e9e557660c1ae0f7597823e4b17
Signed-off-by: default avatarMayank Rana <mrana@codeaurora.org>
Signed-off-by: default avatarHemant Kumar <hemantk@codeaurora.org>
parent 63e7d79c

drivers/usb/gadget/function/f_mtp.c

+142 −1
Original line number Diff line number Diff line
@@ -26,6 +26,8 @@ 
#include <linux/err.h>

#include <linux/interrupt.h>



#include <linux/seq_file.h>

#include <linux/debugfs.h>

#include <linux/types.h>

#include <linux/file.h>

#include <linux/device.h>
@@ -73,6 +75,8 @@ 
#define MTP_RESPONSE_DEVICE_BUSY    0x2019

#define DRIVER_NAME "mtp"



#define MAX_ITERATION		100



unsigned int mtp_rx_req_len = MTP_BULK_BUFFER_SIZE;

module_param(mtp_rx_req_len, uint, 0644);
@@ -122,6 +126,14 @@ struct mtp_dev { 
	uint16_t xfer_command;

	uint32_t xfer_transaction_id;

	int xfer_result;

	struct {

		unsigned long vfs_rbytes;

		unsigned long vfs_wbytes;

		unsigned int vfs_rtime;

		unsigned int vfs_wtime;

	} perf[MAX_ITERATION];

	unsigned int dbg_read_index;

	unsigned int dbg_write_index;

};



static struct usb_interface_descriptor mtp_interface_desc = {
@@ -762,6 +774,7 @@ static void send_file_work(struct work_struct *data) 
	int xfer, ret, hdr_size;

	int r = 0;

	int sendZLP = 0;

	ktime_t start_time;



	/* read our parameters */

	smp_rmb();
@@ -817,14 +830,19 @@ static void send_file_work(struct work_struct *data) 
			header->transaction_id =

					__cpu_to_le32(dev->xfer_transaction_id);

		}



		start_time = ktime_get();

		ret = vfs_read(filp, req->buf + hdr_size, xfer - hdr_size,

								&offset);

		if (ret < 0) {

			r = ret;

			break;

		}



		xfer = ret + hdr_size;

		dev->perf[dev->dbg_read_index].vfs_rtime =

			ktime_to_us(ktime_sub(ktime_get(), start_time));

		dev->perf[dev->dbg_read_index].vfs_rbytes = xfer;

		dev->dbg_read_index = (dev->dbg_read_index + 1) % MAX_ITERATION;

		hdr_size = 0;



		req->length = xfer;
@@ -864,6 +882,7 @@ static void receive_file_work(struct work_struct *data) 
	int64_t count;

	int ret, cur_buf = 0;

	int r = 0;

	ktime_t start_time;



	/* read our parameters */

	smp_rmb();
@@ -897,6 +916,7 @@ static void receive_file_work(struct work_struct *data) 


		if (write_req) {

			DBG(cdev, "rx %p %d\n", write_req, write_req->actual);

			start_time = ktime_get();

			ret = vfs_write(filp, write_req->buf, write_req->actual,

				&offset);

			DBG(cdev, "vfs_write %d\n", ret);
@@ -906,6 +926,11 @@ static void receive_file_work(struct work_struct *data) 
					dev->state = STATE_ERROR;

				break;

			}

			dev->perf[dev->dbg_write_index].vfs_wtime =

				ktime_to_us(ktime_sub(ktime_get(), start_time));

			dev->perf[dev->dbg_write_index].vfs_wbytes = ret;

			dev->dbg_write_index =

				(dev->dbg_write_index + 1) % MAX_ITERATION;

			write_req = NULL;

		}
@@ -1453,6 +1478,120 @@ static void mtp_function_disable(struct usb_function *f) 
	VDBG(cdev, "%s disabled\n", dev->function.name);

}



static int debug_mtp_read_stats(struct seq_file *s, void *unused)

{

	struct mtp_dev *dev = _mtp_dev;

	int i;

	unsigned long flags;

	unsigned int min, max = 0, sum = 0, iteration = 0;



	seq_puts(s, "\n=======================\n");

	seq_puts(s, "USB MTP OUT related VFS write stats:\n");

	seq_puts(s, "\n=======================\n");

	spin_lock_irqsave(&dev->lock, flags);

	min = dev->perf[0].vfs_wtime;

	for (i = 0; i < MAX_ITERATION; i++) {

		seq_printf(s, "vfs write: bytes:%ld\t\t time:%d\n",

				dev->perf[i].vfs_wbytes,

				dev->perf[i].vfs_wtime);

		if (dev->perf[i].vfs_wbytes == mtp_rx_req_len) {

			sum += dev->perf[i].vfs_wtime;

			if (min > dev->perf[i].vfs_wtime)

				min = dev->perf[i].vfs_wtime;

			if (max < dev->perf[i].vfs_wtime)

				max = dev->perf[i].vfs_wtime;

			iteration++;

		}

	}



	seq_printf(s, "vfs_write(time in usec) min:%d\t max:%d\t avg:%d\n",

						min, max, sum / iteration);

	min = max = sum = iteration = 0;

	seq_puts(s, "\n=======================\n");

	seq_puts(s, "USB MTP IN related VFS read stats:\n");

	seq_puts(s, "\n=======================\n");



	min = dev->perf[0].vfs_rtime;

	for (i = 0; i < MAX_ITERATION; i++) {

		seq_printf(s, "vfs read: bytes:%ld\t\t time:%d\n",

				dev->perf[i].vfs_rbytes,

				dev->perf[i].vfs_rtime);

		if (dev->perf[i].vfs_rbytes == mtp_tx_req_len) {

			sum += dev->perf[i].vfs_rtime;

			if (min > dev->perf[i].vfs_rtime)

				min = dev->perf[i].vfs_rtime;

			if (max < dev->perf[i].vfs_rtime)

				max = dev->perf[i].vfs_rtime;

			iteration++;

		}

	}



	seq_printf(s, "vfs_read(time in usec) min:%d\t max:%d\t avg:%d\n",

						min, max, sum / iteration);

	spin_unlock_irqrestore(&dev->lock, flags);

	return 0;

}



static ssize_t debug_mtp_reset_stats(struct file *file, const char __user *buf,

				 size_t count, loff_t *ppos)

{

	int clear_stats;

	unsigned long flags;

	struct mtp_dev *dev = _mtp_dev;



	if (buf == NULL) {

		pr_err("[%s] EINVAL\n", __func__);

		goto done;

	}



	if (kstrtoint(buf, 0, &clear_stats) || clear_stats != 0) {

		pr_err("Wrong value. To clear stats, enter value as 0.\n");

		goto done;

	}



	spin_lock_irqsave(&dev->lock, flags);

	memset(&dev->perf[0], 0, MAX_ITERATION * sizeof(dev->perf[0]));

	dev->dbg_read_index = 0;

	dev->dbg_write_index = 0;

	spin_unlock_irqrestore(&dev->lock, flags);

done:

	return count;

}



static int debug_mtp_open(struct inode *inode, struct file *file)

{

	return single_open(file, debug_mtp_read_stats, inode->i_private);

}



static const struct file_operations debug_mtp_ops = {

	.open = debug_mtp_open,

	.read = seq_read,

	.write = debug_mtp_reset_stats,

};



struct dentry *dent_mtp;

static void mtp_debugfs_init(void)

{

	struct dentry *dent_mtp_status;



	dent_mtp = debugfs_create_dir("usb_mtp", 0);

	if (!dent_mtp || IS_ERR(dent_mtp))

		return;



	dent_mtp_status = debugfs_create_file("status", 0644, dent_mtp,

						0, &debug_mtp_ops);

	if (!dent_mtp_status || IS_ERR(dent_mtp_status)) {

		debugfs_remove(dent_mtp);

		dent_mtp = NULL;

		return;

	}

}



static void mtp_debugfs_remove(void)

{

	debugfs_remove_recursive(dent_mtp);

}



static int __mtp_setup(struct mtp_instance *fi_mtp)

{

	struct mtp_dev *dev;
@@ -1489,6 +1628,7 @@ static int __mtp_setup(struct mtp_instance *fi_mtp) 
	if (ret)

		goto err2;



	mtp_debugfs_init();

	return 0;



err2:
@@ -1513,6 +1653,7 @@ static void mtp_cleanup(void) 
	if (!dev)

		return;



	mtp_debugfs_remove();

	misc_deregister(&mtp_device);

	destroy_workqueue(dev->wq);

	_mtp_dev = NULL;