[lttng-dev] [PATCH lttng-modules] Add throughput test to LTTng

[Julien Desfossez]

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