X-Git-Url: http://git.lttng.org./?a=blobdiff_plain;f=benchmark%2Fbenchmark.c;h=9100fae5735c64bdc3cc41001908afdfa3597a4a;hb=1980ec5e594098de6e37b4d9d88a75ca014ad4f9;hp=72a75c6198e5f948bb3728b8e7fcac81b2c2ecd0;hpb=b25a886891f7172c0abb189ac71bf2bf9b40ec76;p=lttng-tools.git

diff --git a/benchmark/benchmark.c b/benchmark/benchmark.c
index 72a75c619..9100fae57 100644
--- a/benchmark/benchmark.c
+++ b/benchmark/benchmark.c
@@ -23,64 +23,273 @@
 
 #include "benchmark.h"
 
-static FILE *fp;
+FILE *fp;
+static double g_freq;
 
-void benchmark_print_boot_results(void)
+static double calibrate_cpu_freq(void)
 {
-	uint64_t freq = 0;
-	double res;
 	int i, nb_calib = 10;
-	double global_boot_time = 0.0;
+	double freq;
+
+	printf("CPU frequency calibration, this should take 10 seconds\n");
+
+	/* CPU Frequency calibration */
+	for (i = 0; i < nb_calib; i++) {
+		freq += (double) get_cpu_freq();
+	}
+	return (freq / (double)nb_calib);
+}
 
-	fp = fopen(RESULTS_FILE_NAME, "w");
+static void close_logs(void)
+{
+	fclose(fp);
+}
+
+static void open_logs(void)
+{
+	fp = fopen(RESULTS_FILE_NAME, "a");
 	if (fp == NULL) {
 		perror("fopen benchmark");
-		return;
 	}
+}
 
-	/* CPU Frequency calibration */
-	for (i = 0; i < nb_calib; i++) {
-		freq += get_cpu_freq();
+static double get_bench_time(cycles_t before, cycles_t after)
+{
+	double ret;
+
+	ret = (((double)(after - before) / (g_freq / 1000.0)) / 1000000000.0);
+
+	return ret;
+}
+
+void bench_init(void)
+{
+	open_logs();
+	if (g_freq == 0) {
+		g_freq = calibrate_cpu_freq();
+		//fprintf(fp, "CPU frequency %f Ghz\n\n", g_freq);
+	}
+}
+
+void bench_close(void)
+{
+	close_logs();
+	printf("Benchmark results in %s\n", RESULTS_FILE_NAME);
+}
+
+double bench_get_create_session(void)
+{
+	if ((time_create_session_start == 0) &&
+			(time_create_session_end == 0)) {
+		fprintf(fp, "NO DATA\n");
+		return 0;
+	}
+
+	return get_bench_time(time_create_session_start, time_create_session_end);
+}
+
+double bench_get_destroy_session(void)
+{
+	if ((time_destroy_session_start == 0) &&
+			(time_destroy_session_end == 0)) {
+		fprintf(fp, "NO DATA\n");
+		return 0;
+	}
+
+	return get_bench_time(time_destroy_session_start, time_destroy_session_end);
+}
+
+/*
+ * Complete UST notification process time break down in different actions.
+ */
+void bench_print_ust_notification(void)
+{
+	double res, total = 0;
+
+	fprintf(fp, "--- UST notification time ---\n");
+
+	if (time_ust_notify_mmap_start == 0 || time_ust_notify_mmap_stop == 0) {
+		goto no_data;
+	}
+
+	res = get_bench_time(time_ust_notify_mmap_start,
+			time_ust_notify_mmap_stop);
+	fprintf(fp, "mmap() call time\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	total += res;
+
+	if (time_ust_notify_perms_start == 0 || time_ust_notify_perms_stop == 0) {
+		goto no_data;
+	}
+
+	res = get_bench_time(time_ust_notify_perms_start,
+			time_ust_notify_perms_stop);
+	fprintf(fp, "Setting permissions (chown/chmod)\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	total += res;
+
+	if (time_ust_notify_shm_start == 0 || time_ust_notify_shm_stop == 0) {
+		goto no_data;
+	}
+
+	res = get_bench_time(time_ust_notify_shm_start,
+			time_ust_notify_shm_stop);
+	fprintf(fp, "shm_open/ftruncate/fchmod\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	total += res;
+
+	fprintf(fp, "Global UST nonification time\n");
+	fprintf(fp, "Time: %.20f sec.\n", total);
+	return;
+
+no_data:
+	fprintf(fp, "NO DATA\n");
+	return;
+}
+
+/*
+ * Time taken by an UST apps to unregister.
+ */
+void bench_print_ust_unregister(void)
+{
+    double res;
+
+    fprintf(fp, "--- UST unregister time ---\n");
+
+    if (time_ust_unregister_start == 0 || time_ust_unregister_stop == 0) {
+        goto no_data;
+    }
+
+    res = get_bench_time(time_ust_unregister_start, time_ust_unregister_stop);
+    fprintf(fp, "UST unregister time\n");
+    fprintf(fp, "Time: %.20f sec.\n", res);
+    return;
+
+no_data:
+    fprintf(fp, "NO DATA\n");
+    return;
+}
+
+/*
+ * This time value is only coherent is an UST application registered.
+ */
+void bench_print_ust_register(void)
+{
+	double res, total = 0;
+
+	fprintf(fp, "--- UST registration time ---\n");
+
+	if (time_ust_register_start == 0 || time_ust_register_stop == 0) {
+		goto no_data;
 	}
-	freq = freq / nb_calib;
 
-	fprintf(fp, "CPU frequency %lu Ghz\n\n", freq);
+	res = get_bench_time(time_ust_register_start, time_ust_register_stop);
+	fprintf(fp, "UST registration received and send to dispatch time\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	total += res;
+
+	if (time_ust_dispatch_register_start == 0 ||
+			time_ust_dispatch_register_stop == 0) {
+		goto no_data;
+	}
+
+	res = get_bench_time(time_ust_dispatch_register_start,
+			time_ust_dispatch_register_stop);
+	fprintf(fp, "Dispatch UST registration request time\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	total += res;
+
+	fprintf(fp, "--> Manage registration breakdown\n");
 
-	fprintf(fp, "Results:\n----------\n");
+	res = get_bench_time(time_ust_register_read_start,
+			time_ust_register_read_stop);
+	fprintf(fp, "read() from pipe time\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
 
-	res = (double) (((double)(time_sessiond_boot_end - time_sessiond_boot_start)
-				/ (((double)freq) / 1000)) / 1000000000);
+	total += res;
 
-	fprintf(fp, "Boot time inside main() from start to first pthread_join (blocking state)\n");
+	res = get_bench_time(time_ust_register_add_start,
+			time_ust_register_add_stop);
+	fprintf(fp, "register_traceable_app time\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	total += res;
+
+	res = get_bench_time(time_ust_register_done_start,
+			time_ust_register_done_stop);
+	fprintf(fp, "send register done command time\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	total += res;
+
+	fprintf(fp, "Global time of an UST application registration\n");
+	fprintf(fp, "Time: %.20f sec.\n", total);
+	return;
+
+no_data:
+	fprintf(fp, "NO DATA\n");
+	return;
+}
+
+
+/*
+ * Log results of the sessiond boot process.
+ *
+ * Uses all time_sessiond_* values (see measures.h)
+ */
+void bench_print_boot_process(void)
+{
+	double res;
+	double global_boot_time = 0.0;
+
+	fprintf(fp, "--- Session daemon boot process ---\n");
+
+	res = get_bench_time(time_sessiond_boot_start, time_sessiond_boot_end);
+
+	fprintf(fp, "Inside main() from start to first pthread_join"
+			"(blocking state)\n");
 	fprintf(fp, "Time: %.20f sec.\n", res);
 
 	global_boot_time += res;
 
-	res = (double) (((double)(time_sessiond_th_kern_poll - time_sessiond_th_kern_start)
-				/ (((double)freq) / 1000)) / 1000000000);
+	res = get_bench_time(time_sessiond_th_kern_start,
+			time_sessiond_th_kern_poll);
 
-	fprintf(fp, "Boot time of the kernel thread from start to poll() (ready state)\n");
+	fprintf(fp, "Kernel thread from start to poll() (ready state)\n");
 	fprintf(fp, "Time: %.20f sec.\n", res);
 
 	global_boot_time += res;
 
-	res = (double) (((double)(time_sessiond_th_apps_poll - time_sessiond_th_apps_start)
-				/ (((double)freq) / 1000)) / 1000000000);
+	res = get_bench_time(time_sessiond_th_apps_start,
+			time_sessiond_th_apps_poll);
 
-	fprintf(fp, "Boot time of the application thread from start to poll() (ready state)\n");
+	fprintf(fp, "Application thread from start to poll() (ready state)\n");
 	fprintf(fp, "Time: %.20f sec.\n", res);
 
 	global_boot_time += res;
 
-	res = (double) (((double)(time_sessiond_th_cli_poll - time_sessiond_th_cli_start)
-				/ (((double)freq) / 1000)) / 1000000000);
+	res = get_bench_time(time_sessiond_th_cli_start,
+			time_sessiond_th_cli_poll);
 
-	fprintf(fp, "Boot time of the client thread from start to poll() (ready state)\n");
+	fprintf(fp, "Client thread from start to poll() (ready state)\n");
 	fprintf(fp, "Time: %.20f sec.\n", res);
 
 	global_boot_time += res;
 
-	fprintf(fp, "Global Boot Time of ltt-sessiond: %0.20f sec.\n", global_boot_time);
+	res = get_bench_time(time_sessiond_th_dispatch_start,
+			time_sessiond_th_dispatch_block);
 
-	fclose(fp);
+	fprintf(fp, "Dispatch registration thread from start to poll()"
+			"(ready state)\n");
+	fprintf(fp, "Time: %.20f sec.\n", res);
+
+	global_boot_time += res;
+
+	fprintf(fp, "Global Boot Time\n");
+	fprintf(fp, "Time: %0.20f sec.\n", global_boot_time);
 }