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;
+}
+
+/*
+ * 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;
+ }
+
+ 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;
+
+ if (time_ust_manage_register_start == 0 ||
+ time_ust_manage_register_stop == 0) {
+ goto no_data;
+ }
+
+ res = get_bench_time(time_ust_manage_register_start,
+ time_ust_manage_register_stop);
+ fprintf(fp, "Manage UST registration 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.
*
void bench_init(void);
void bench_close(void);
void bench_print_boot_process(void);
+void bench_print_ust_register(void);
+void bench_print_ust_notification(void);
double bench_get_create_session(void);
double bench_get_destroy_session(void);
cycles_t time_sessiond_th_apps_start;
cycles_t time_sessiond_th_apps_poll;
+/* Session daemon thread registration apps time */
+cycles_t time_sessiond_th_reg_start;
+cycles_t time_sessiond_th_reg_poll;
+
/* Session daemon thread manage client time */
cycles_t time_sessiond_th_cli_start;
cycles_t time_sessiond_th_cli_poll;
cycles_t time_destroy_session_start;
cycles_t time_destroy_session_end;
+/*
+ * UST registration time
+ *
+ * Start time is taken *after* the poll() has detected activity on the apps
+ * socket and right *before* the accept(). There is a malloc() after that
+ * accept and then we recv() the request from the client. We need to measure
+ * the complete process.
+ */
+cycles_t time_ust_register_start;
+/*
+ * The stop time is measured right after the futex() wake up.
+ */
+cycles_t time_ust_register_stop;
+
+/*
+ * UST dispatch registration request time
+ *
+ * Start time taken *after* the dequeue which is a blocking call.
+ */
+cycles_t time_ust_dispatch_register_start;
+/*
+ * Stop time taken *before* the futex() wait so at this point, the registration
+ * was sent to the manage apps thread.
+ */
+cycles_t time_ust_dispatch_register_stop;
+
+/*
+ * UST managing registration time
+ *
+ * Start *before* the thread reads the pipe containing the registration data.
+ */
+cycles_t time_ust_manage_register_start;
+/*
+ * Stop time taken *after* the register command is sent to the application.
+ */
+cycles_t time_ust_manage_register_stop;
+
+/*
+ * UST notification time (using the shm/futex scheme). Those times were break
+ * down in seperate time for each big action step.
+ *
+ * Start time taken *before* we create/get the SHM mmap.
+ */
+cycles_t time_ust_notify_apps_start;
+/*
+ * Stop time taken after waiting all processes (futex_wait_update()).
+ */
+cycles_t time_ust_notify_apps_stop;
+/* mmap() call */
+cycles_t time_ust_notify_mmap_start;
+cycles_t time_ust_notify_mmap_stop;
+/* Permissions time (chmod/chown) */
+cycles_t time_ust_notify_perms_start;
+cycles_t time_ust_notify_perms_stop;
+/* Fork process */
+cycles_t time_ust_notify_fork_start;
+cycles_t time_ust_notify_fork_stop;
+/* shm_open call */
+cycles_t time_ust_notify_shm_start;
+cycles_t time_ust_notify_shm_stop;
+
#endif /* _MEASURES_H */
echo "Session daemon boot process benchmark"
-$BASEDIR/../ltt-sessiond/$SESSIOND_BIN --daemonize --quiet
+`BENCH_BOOT_PROCESS=1 $BASEDIR/../ltt-sessiond/$SESSIOND_BIN --daemonize --quiet`
if [ $? -ne 0 ]; then
echo -e '\e[1;31mFAILED\e[0m'
exit 1
#### ADD TESTS HERE ####
-test_suite=( "run-boot-time.sh" "run-sessions.sh" )
+test_suite=( "run-boot-time.sh" "run-sessions.sh" "run-ust-register.sh" )
#### END TESTS HERE ####
BASEDIR=`dirname $0`
if [ -e $RESULTS_PATH ]; then
- mv -v $RESULTS_PATH $RESULTS_PATH.`date +%s`
+ mv -v $RESULTS_PATH "$RESULTS_PATH.`date +%s`.txt"
fi
echo ""
echo ""
done
-mv -v $RESULTS_PATH results-`date +%d%m%Y.%H%M%S`.txt
+mv -v $RESULTS_PATH "results-`date +%d%m%Y.%H%M%S`.txt"
exit 0
/* OUTPUT BENCHMARK RESULTS */
bench_init();
- bench_print_boot_process();
+ if (getenv("BENCH_UST_NOTIFY")) {
+ bench_print_ust_notification();
+ }
+
+ if (getenv("BENCH_UST_REGISTER")) {
+ bench_print_ust_register();
+ }
+
+ if (getenv("BENCH_BOOT_PROCESS")) {
+ bench_print_boot_process();
+ }
bench_close();
/* END BENCHMARK */
DBG("Notifying applications of session daemon state: %d", active);
+ tracepoint(ust_notify_apps_start);
+
/* See shm.c for this call implying mmap, shm and futex calls */
wait_shm_mmap = shm_ust_get_mmap(wait_shm_path, is_root);
if (wait_shm_mmap == NULL) {
/* Wake waiting process */
futex_wait_update((int32_t *) wait_shm_mmap, active);
+ tracepoint(ust_notify_apps_stop);
+
/* Apps notified successfully */
return 0;
ERR("Apps command pipe poll error");
goto error;
case POLLIN:
+ tracepoint(ust_manage_register_start);
+
/* Empty pipe */
ret = read(apps_cmd_pipe[0], &ust_cmd, sizeof(ust_cmd));
if (ret < 0 || ret < sizeof(ust_cmd)) {
*/
unregister_traceable_app(ust_cmd.sock);
}
+
+ tracepoint(ust_manage_register_stop);
break;
}
}
break;
}
+ tracepoint(ust_dispatch_register_start);
+
ust_cmd = caa_container_of(node, struct ust_command, node);
DBG("Dispatching UST registration pid:%d ppid:%d uid:%d"
free(ust_cmd);
} while (node != NULL);
+ tracepoint(ust_dispatch_register_stop);
+
/* Futex wait on queue. Blocking call on futex() */
futex_nto1_wait(&ust_cmd_queue.futex);
}
*/
struct ust_command *ust_cmd = NULL;
- tracepoint(sessiond_th_apps_start);
+ tracepoint(sessiond_th_reg_start);
DBG("[thread] Manage application registration started");
while (1) {
DBG("Accepting application registration");
- tracepoint(sessiond_th_apps_poll);
+ tracepoint(sessiond_th_reg_poll);
/* Inifinite blocking call, waiting for transmission */
ret = poll(pollfd, 2, -1);
goto error;
}
+ /* Registration starts here. Recording cycles */
+ tracepoint(ust_register_start);
+
sock = lttcomm_accept_unix_sock(apps_sock);
if (sock < 0) {
goto error;
* Implicit memory barrier with the exchange in cds_wfq_enqueue.
*/
futex_nto1_wake(&ust_cmd_queue.futex);
+
+ tracepoint(ust_register_stop);
}
error:
#include <lttngerr.h>
+#include "benchmark.h"
+#include "measures.h"
#include "shm.h"
/*
int wait_shm_fd, ret;
mode_t mode;
+ tracepoint(ust_notify_perms_start);
+
/* Default permissions */
mode = S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP;
*/
umask(~mode);
+ tracepoint(ust_notify_perms_stop);
+
+ tracepoint(ust_notify_shm_start);
/*
* Try creating shm (or get rw access). We don't do an exclusive open,
* because we allow other processes to create+ftruncate it concurrently.
exit(EXIT_FAILURE);
}
+ tracepoint(ust_notify_shm_stop);
+
DBG("Got the wait shm fd %d", wait_shm_fd);
return wait_shm_fd;
goto error;
}
+ tracepoint(ust_notify_mmap_start);
+
wait_shm_mmap = mmap(NULL, mmap_size, PROT_WRITE | PROT_READ,
MAP_SHARED, wait_shm_fd, 0);
+ tracepoint(ust_notify_mmap_stop);
/* close shm fd immediately after taking the mmap reference */
ret = close(wait_shm_fd);
if (ret) {
projects / lttng-tools.git / commitdiff
