[lttng-modules] Add throughput test to LTTng

Message ID 1473355662-29891-1-git-send-email-mohamad.gebai@gmail.com
State Superseded, archived
Headers show

Commit Message

Mohamad Gebai Sept. 8, 2016, 5:27 p.m. UTC
- Create the lttng-test subdirectory under /proc for testing purposes.

- Create the procfs throughput file. Start a throughput test by writing
  the number of iterations for the test. Read from this file to get the
  result in nanoseconds. Note that the test automatically tries to reach
  a steady state before benchmarking.

Signed-off-by: Mohamad Gebai <mohamad.gebai at gmail.com>
---
 instrumentation/events/lttng-module/lttng-test.h |   8 ++
 tests/probes/lttng-test.c                        | 118 +++++++++++++++++++++--
 2 files changed, 116 insertions(+), 10 deletions(-)

Comments

Julien Desfossez Sept. 12, 2016, 3:27 p.m. UTC | #1
Hi,

See comments below

On 08-Sep-2016 01:27:42 PM, Mohamad Gebai wrote:
> - Create the lttng-test subdirectory under /proc for testing purposes.
> 
> - Create the procfs throughput file. Start a throughput test by writing
>   the number of iterations for the test. Read from this file to get the
>   result in nanoseconds. Note that the test automatically tries to reach
>   a steady state before benchmarking.
> 
> Signed-off-by: Mohamad Gebai <mohamad.gebai at gmail.com>
> ---
>  instrumentation/events/lttng-module/lttng-test.h |   8 ++
>  tests/probes/lttng-test.c                        | 118 +++++++++++++++++++++--
>  2 files changed, 116 insertions(+), 10 deletions(-)
> 
> diff --git a/instrumentation/events/lttng-module/lttng-test.h b/instrumentation/events/lttng-module/lttng-test.h
> index 05d028c..54b4404 100644
> --- a/instrumentation/events/lttng-module/lttng-test.h
> +++ b/instrumentation/events/lttng-module/lttng-test.h
> @@ -48,6 +48,14 @@ LTTNG_TRACEPOINT_EVENT(lttng_test_filter_event,
>  	)
>  )
>  
> +LTTNG_TRACEPOINT_EVENT(lttng_test_throughput,
> +    TP_PROTO(int anint),
> +    TP_ARGS(anint),
> +    TP_FIELDS(
> +        ctf_integer(int, intfield, anint)
> +    )
> +)
> +
>  #endif /*  LTTNG_TRACE_LTTNG_TEST_H */
>  
>  /* This part must be outside protection */
> diff --git a/tests/probes/lttng-test.c b/tests/probes/lttng-test.c
> index 54be4c7..dc59680 100644
> --- a/tests/probes/lttng-test.c
> +++ b/tests/probes/lttng-test.c
> @@ -23,6 +23,7 @@
>  #include <linux/init.h>
>  #include <linux/module.h>
>  #include <linux/proc_fs.h>
> +#include <linux/timekeeping.h>
>  #include <linux/byteorder/generic.h>
>  
>  #include <lttng-events.h>
> @@ -39,12 +40,18 @@
>  #include <instrumentation/events/lttng-module/lttng-test.h>
>  
>  DEFINE_TRACE(lttng_test_filter_event);
> +DEFINE_TRACE(lttng_test_throughput);
>  
> -#define LTTNG_TEST_FILTER_EVENT_FILE	"lttng-test-filter-event"

Note that a patch to update all the tests that use this file in
lttng-tools will be needed if we change the path of
lttng-test-filter-event.

> +#define LTTNG_TEST_PROCFS_DIR           "lttng-test"
> +#define LTTNG_TEST_FILTER_EVENT_FILE    "filter-event"
> +/* Do a throughput benchmark by writing to this file the number of events.
> + * Read the results in nanoseconds. */
> +#define LTTNG_TEST_THROUGHPUT_FILE      "throughput"
>  
>  #define LTTNG_WRITE_COUNT_MAX	64
>  
> -static struct proc_dir_entry *lttng_test_filter_event_dentry;
> +static struct proc_dir_entry *lttng_test_dentry;
> +static u64 latest_throughput_results = 0;
>  
>  static
>  void trace_test_event(unsigned int nr_iter)
> @@ -60,6 +67,24 @@ void trace_test_event(unsigned int nr_iter)
>  	}
>  }
>  
> +static
> +void lttng_throughput_test(unsigned int nr_iter)
> +{
> +	int i;
> +	ktime_t start_time, end_time;
> +
> +	/* Warm up and get to a steady state */
> +	for(i = 0; i < nr_iter / 2; i++)
for (i =...
> +		trace_lttng_test_throughput(i);
> +
> +	start_time = ktime_get();
Do we really want to use ktime_get() directly and not the
trace_clock_read64 wrapper instead ? It might be easier to correlate the
aggregated result from latest_throughput_results with the generated
events list if they use the same clock.

> +	for(i = 0; i < nr_iter; i++)
for (i =...
> +		trace_lttng_test_throughput(i);
> +	end_time = ktime_get();
> +
> +	latest_throughput_results = ktime_to_ns(end_time) - ktime_to_ns(start_time);
> +}
> +
>  /**
>   * lttng_filter_event_write - trigger a lttng_test_filter_event
>   * @file: file pointer
> @@ -90,10 +115,72 @@ end:
>  	return written;
>  }
>  
> +/**
> + * lttng_throughput_test_write - trigger a lttng_throughput_test
> + * @file: file pointer
> + * @user_buf: user string
> + * @count: length to copy
> + *
> + * Return -1 on error, with EFAULT errno. Returns count on success.
> + */
> +static
> +ssize_t lttng_throughput_test_write(struct file *file,
> +                                    const char __user *user_buf,
> +                                    size_t count, loff_t *ppos)
> +{
> +	unsigned int nr_iter;
> +	ssize_t written;
> +	int ret;
> +
> +	/* Get the number of iterations */
> +	ret = lttng_kstrtouint_from_user(user_buf, count, 10, &nr_iter);
> +	if (ret) {
> +		written = ret;
> +		goto end;
> +	}
> +	/* Do throughput test */
> +	lttng_throughput_test(nr_iter);
> +	written = count;
> +	*ppos += written;
add new line here
> +end:
> +    return written;
> +}
> +
> +/**
> + * lttng_throughput_test_read - read latest results of throughput test
> + * @file: file pointer
> + * @user_buf: user string
> + * @count: length to copy
> + *
> + * Return -1 on error, with EFAULT errno. Returns count on success.
> + */
> +static
> +ssize_t lttng_throughput_test_read(struct file *file, char __user *user_buf,
> +                           size_t count, loff_t *ppos)
> +{
> +	char buf[count];
> +	ssize_t read_count = 0;
> +
> +	if(latest_throughput_results == 0)
if (latest_...
> +		goto end;
> +
> +	read_count += snprintf(buf, count, "%llu\n", latest_throughput_results);
> +	copy_to_user(user_buf, buf, count);
> +	latest_throughput_results = 0;
> +
> +end:
> +    return read_count;
> +}
> +
>  static const struct file_operations lttng_test_filter_event_operations = {
>  	.write = lttng_test_filter_event_write,
>  };
>  
> +static const struct file_operations lttng_throughput_test_operations = {
> +	.write = lttng_throughput_test_write,
> +	.read = lttng_throughput_test_read,
> +};
> +
>  static
>  int __init lttng_test_init(void)
>  {
> @@ -101,22 +188,33 @@ int __init lttng_test_init(void)
>  
>  	(void) wrapper_lttng_fixup_sig(THIS_MODULE);
>  	wrapper_vmalloc_sync_all();
> -	lttng_test_filter_event_dentry =
> -			proc_create_data(LTTNG_TEST_FILTER_EVENT_FILE,
> -				S_IRUGO | S_IWUGO, NULL,
> -				&lttng_test_filter_event_operations, NULL);
> -	if (!lttng_test_filter_event_dentry) {
> +	lttng_test_dentry = proc_mkdir(LTTNG_TEST_PROCFS_DIR, NULL);
> +	if (!lttng_test_dentry) {
> +		printk(KERN_ERR "Error creating LTTng test directory\n");
> +		ret = -ENOMEM;
> +		goto error;
> +	}
> +	if (!proc_create_data(LTTNG_TEST_FILTER_EVENT_FILE,
> +				S_IRUGO | S_IWUGO, lttng_test_dentry,
> +				&lttng_test_filter_event_operations, NULL)) {
>  		printk(KERN_ERR "Error creating LTTng test filter file\n");
>  		ret = -ENOMEM;
>  		goto error;
goto error_event
>  	}
> +	if(!proc_create_data(LTTNG_TEST_THROUGHPUT_FILE,
if (!proc...
> +				S_IRUGO | S_IWUGO, lttng_test_dentry,
> +				&lttng_throughput_test_operations, NULL)) {
> +		printk(KERN_ERR "Error creating LTTng test throughput file\n");
> +		ret = -ENOMEM;
> +		goto error;
goto error_event
> +	}
>  	ret = __lttng_events_init__lttng_test();
>  	if (ret)
>  		goto error_events;
>  	return ret;
>  
>  error_events:
> -	remove_proc_entry(LTTNG_TEST_FILTER_EVENT_FILE, NULL);
> +	remove_proc_subtree(LTTNG_TEST_PROCFS_DIR, NULL);
>  error:
>  	return ret;
>  }
> @@ -127,8 +225,8 @@ static
>  void __exit lttng_test_exit(void)
>  {
>  	__lttng_events_exit__lttng_test();
> -	if (lttng_test_filter_event_dentry)
> -		remove_proc_entry(LTTNG_TEST_FILTER_EVENT_FILE, NULL);
> +	if (lttng_test_dentry)
> +		remove_proc_subtree(LTTNG_TEST_PROCFS_DIR, NULL);
>  }
>  
>  module_exit(lttng_test_exit);
> -- 
> 2.5.0

Thanks,

Julien

Patch

diff --git a/instrumentation/events/lttng-module/lttng-test.h b/instrumentation/events/lttng-module/lttng-test.h
index 05d028c..54b4404 100644
--- a/instrumentation/events/lttng-module/lttng-test.h
+++ b/instrumentation/events/lttng-module/lttng-test.h
@@ -48,6 +48,14 @@  LTTNG_TRACEPOINT_EVENT(lttng_test_filter_event,
 	)
 )
 
+LTTNG_TRACEPOINT_EVENT(lttng_test_throughput,
+    TP_PROTO(int anint),
+    TP_ARGS(anint),
+    TP_FIELDS(
+        ctf_integer(int, intfield, anint)
+    )
+)
+
 #endif /*  LTTNG_TRACE_LTTNG_TEST_H */
 
 /* This part must be outside protection */
diff --git a/tests/probes/lttng-test.c b/tests/probes/lttng-test.c
index 54be4c7..dc59680 100644
--- a/tests/probes/lttng-test.c
+++ b/tests/probes/lttng-test.c
@@ -23,6 +23,7 @@ 
 #include <linux/init.h>
 #include <linux/module.h>
 #include <linux/proc_fs.h>
+#include <linux/timekeeping.h>
 #include <linux/byteorder/generic.h>
 
 #include <lttng-events.h>
@@ -39,12 +40,18 @@ 
 #include <instrumentation/events/lttng-module/lttng-test.h>
 
 DEFINE_TRACE(lttng_test_filter_event);
+DEFINE_TRACE(lttng_test_throughput);
 
-#define LTTNG_TEST_FILTER_EVENT_FILE	"lttng-test-filter-event"
+#define LTTNG_TEST_PROCFS_DIR           "lttng-test"
+#define LTTNG_TEST_FILTER_EVENT_FILE    "filter-event"
+/* Do a throughput benchmark by writing to this file the number of events.
+ * Read the results in nanoseconds. */
+#define LTTNG_TEST_THROUGHPUT_FILE      "throughput"
 
 #define LTTNG_WRITE_COUNT_MAX	64
 
-static struct proc_dir_entry *lttng_test_filter_event_dentry;
+static struct proc_dir_entry *lttng_test_dentry;
+static u64 latest_throughput_results = 0;
 
 static
 void trace_test_event(unsigned int nr_iter)
@@ -60,6 +67,24 @@  void trace_test_event(unsigned int nr_iter)
 	}
 }
 
+static
+void lttng_throughput_test(unsigned int nr_iter)
+{
+	int i;
+	ktime_t start_time, end_time;
+
+	/* Warm up and get to a steady state */
+	for(i = 0; i < nr_iter / 2; i++)
+		trace_lttng_test_throughput(i);
+
+	start_time = ktime_get();
+	for(i = 0; i < nr_iter; i++)
+		trace_lttng_test_throughput(i);
+	end_time = ktime_get();
+
+	latest_throughput_results = ktime_to_ns(end_time) - ktime_to_ns(start_time);
+}
+
 /**
  * lttng_filter_event_write - trigger a lttng_test_filter_event
  * @file: file pointer
@@ -90,10 +115,72 @@  end:
 	return written;
 }
 
+/**
+ * lttng_throughput_test_write - trigger a lttng_throughput_test
+ * @file: file pointer
+ * @user_buf: user string
+ * @count: length to copy
+ *
+ * Return -1 on error, with EFAULT errno. Returns count on success.
+ */
+static
+ssize_t lttng_throughput_test_write(struct file *file,
+                                    const char __user *user_buf,
+                                    size_t count, loff_t *ppos)
+{
+	unsigned int nr_iter;
+	ssize_t written;
+	int ret;
+
+	/* Get the number of iterations */
+	ret = lttng_kstrtouint_from_user(user_buf, count, 10, &nr_iter);
+	if (ret) {
+		written = ret;
+		goto end;
+	}
+	/* Do throughput test */
+	lttng_throughput_test(nr_iter);
+	written = count;
+	*ppos += written;
+end:
+    return written;
+}
+
+/**
+ * lttng_throughput_test_read - read latest results of throughput test
+ * @file: file pointer
+ * @user_buf: user string
+ * @count: length to copy
+ *
+ * Return -1 on error, with EFAULT errno. Returns count on success.
+ */
+static
+ssize_t lttng_throughput_test_read(struct file *file, char __user *user_buf,
+                           size_t count, loff_t *ppos)
+{
+	char buf[count];
+	ssize_t read_count = 0;
+
+	if(latest_throughput_results == 0)
+		goto end;
+
+	read_count += snprintf(buf, count, "%llu\n", latest_throughput_results);
+	copy_to_user(user_buf, buf, count);
+	latest_throughput_results = 0;
+
+end:
+    return read_count;
+}
+
 static const struct file_operations lttng_test_filter_event_operations = {
 	.write = lttng_test_filter_event_write,
 };
 
+static const struct file_operations lttng_throughput_test_operations = {
+	.write = lttng_throughput_test_write,
+	.read = lttng_throughput_test_read,
+};
+
 static
 int __init lttng_test_init(void)
 {
@@ -101,22 +188,33 @@  int __init lttng_test_init(void)
 
 	(void) wrapper_lttng_fixup_sig(THIS_MODULE);
 	wrapper_vmalloc_sync_all();
-	lttng_test_filter_event_dentry =
-			proc_create_data(LTTNG_TEST_FILTER_EVENT_FILE,
-				S_IRUGO | S_IWUGO, NULL,
-				&lttng_test_filter_event_operations, NULL);
-	if (!lttng_test_filter_event_dentry) {
+	lttng_test_dentry = proc_mkdir(LTTNG_TEST_PROCFS_DIR, NULL);
+	if (!lttng_test_dentry) {
+		printk(KERN_ERR "Error creating LTTng test directory\n");
+		ret = -ENOMEM;
+		goto error;
+	}
+	if (!proc_create_data(LTTNG_TEST_FILTER_EVENT_FILE,
+				S_IRUGO | S_IWUGO, lttng_test_dentry,
+				&lttng_test_filter_event_operations, NULL)) {
 		printk(KERN_ERR "Error creating LTTng test filter file\n");
 		ret = -ENOMEM;
 		goto error;
 	}
+	if(!proc_create_data(LTTNG_TEST_THROUGHPUT_FILE,
+				S_IRUGO | S_IWUGO, lttng_test_dentry,
+				&lttng_throughput_test_operations, NULL)) {
+		printk(KERN_ERR "Error creating LTTng test throughput file\n");
+		ret = -ENOMEM;
+		goto error;
+	}
 	ret = __lttng_events_init__lttng_test();
 	if (ret)
 		goto error_events;
 	return ret;
 
 error_events:
-	remove_proc_entry(LTTNG_TEST_FILTER_EVENT_FILE, NULL);
+	remove_proc_subtree(LTTNG_TEST_PROCFS_DIR, NULL);
 error:
 	return ret;
 }
@@ -127,8 +225,8 @@  static
 void __exit lttng_test_exit(void)
 {
 	__lttng_events_exit__lttng_test();
-	if (lttng_test_filter_event_dentry)
-		remove_proc_entry(LTTNG_TEST_FILTER_EVENT_FILE, NULL);
+	if (lttng_test_dentry)
+		remove_proc_subtree(LTTNG_TEST_PROCFS_DIR, NULL);
 }
 
 module_exit(lttng_test_exit);