trace: add re_trace api

Makefile

@@ -34,7 +34,7 @@ MODULES += dns
 MODULES += md5 crc32 sha hmac base64
 MODULES += udp sa net tcp tls
 MODULES += list mbuf hash
-MODULES += fmt tmr main mem dbg sys lock mqueue
+MODULES += fmt tmr trace main mem dbg sys lock mqueue
 MODULES += mod conf
 MODULES += bfcp
 MODULES += aes srtp

README.md

@@ -137,6 +137,7 @@ Patches can sent via Github
 | udp      | stable   | UDP transport                                  |
 | uri      | stable   | Generic URI library                            |
 | websock  | stable   | WebSocket Client and Server                    |
+| trace    | development | Trace Helpers JSON traces (chrome://tracing)|
 
 legend:
 * *stable* - code complete; stable code and stable API

include/re.h

@@ -56,6 +56,7 @@ extern "C" {
 #include "re_tcp.h"
 #include "re_telev.h"
 #include "re_tmr.h"
+#include "re_trace.h"
 #include "re_tls.h"
 #include "re_turn.h"
 #include "re_udp.h"

include/re_trace.h

@@ -0,0 +1,70 @@
+/**
+ * @file re_trace.h RE_TRACE helpers
+ * JSON traces (chrome://tracing)
+ */
+
+typedef enum {
+	RE_TRACE_ARG_NONE,
+	RE_TRACE_ARG_INT,
+	RE_TRACE_ARG_STRING_CONST,
+	RE_TRACE_ARG_STRING_COPY,
+} re_trace_arg_type;
+
+
+int re_trace_init(const char *json_file);
+int re_trace_close(void);
+int re_trace_flush(void);
+void re_trace_event(const char *cat, const char *name, char ph, void *id,
+			int32_t async_id, re_trace_arg_type arg_type,
+			const char *arg_name, void *arg_value);
+
+#if !defined(RELEASE) && !defined(RE_TRACE_ENABLED)
+#define RE_TRACE_ENABLED 1
+#endif
+
+#ifdef RE_TRACE_ENABLED
+
+#define RE_TRACE_BEGIN(c, n) \
+	re_trace_event(c, n, 'B', 0, 0, RE_TRACE_ARG_NONE, NULL, NULL)
+#define RE_TRACE_END(c, n) \
+	re_trace_event(c, n, 'E', 0, 0, RE_TRACE_ARG_NONE, NULL, NULL)
+
+#define RE_TRACE_ID_BEGIN(c, n, id) \
+	re_trace_event(c, n, 'B', 0, id, RE_TRACE_ARG_NONE, NULL, NULL)
+#define RE_TRACE_ID_END(c, n, id) \
+	re_trace_event(c, n, 'E', 0, id, RE_TRACE_ARG_NONE, NULL, NULL)
+
+#define RE_TRACE_INSTANT(c, n) \
+	re_trace_event(c, n, 'I', 0, 0, RE_TRACE_ARG_NONE, NULL, NULL)
+#define RE_TRACE_INSTANT_C(c, n, vname, str) \
+	re_trace_event(c, n, 'I', 0, 0, RE_TRACE_ARG_STRING_CONST, \
+	vname, (void *)(str))
+#define RE_TRACE_INSTANT_I(c, n, i) \
+	re_trace_event(c, n, 'I', 0, 0, RE_TRACE_ARG_INT, \
+	n, (void *)(intptr_t)i)
+
+#define RE_TRACE_PROCESS_NAME(n) \
+	re_trace_event("", "process_name", 'M', 0, 0, \
+	RE_TRACE_ARG_STRING_COPY, \
+	"name", (void *)(n))
+#define RE_TRACE_THREAD_NAME(n) \
+	re_trace_event("", "thread_name", 'M', 0, 0, \
+	RE_TRACE_ARG_STRING_COPY, \
+	"name", (void *)(n))
+
+#else
+
+#define RE_TRACE_BEGIN(c, n)
+#define RE_TRACE_END(c, n)
+#define RE_TRACE_ID_BEGIN(c, n, id)
+#define RE_TRACE_ID_END(c, n, id)
+#define RE_TRACE_INSTANT(c, n)
+#define RE_TRACE_INSTANT_C(c, n, str)
+#define RE_TRACE_INSTANT_I(c, n, i)
+#define RE_TRACE_META_PROCESS_NAME(n)
+#define RE_TRACE_THREAD_NAME(n)
+
+#endif
+
+#define RE_TRACE_BEGIN_FUNC() RE_TRACE_BEGIN(__FILE__, __func__)
+#define RE_TRACE_END_FUNC() RE_TRACE_END(__FILE__, __func__)

src/trace/mod.mk

@@ -0,0 +1 @@
+SRCS	+= trace/trace.c

src/trace/trace.c

@@ -0,0 +1,275 @@
+/**
+ * @file trace.c RE_TRACE helpers
+ * JSON traces (chrome://tracing)
+ */
+#include <re_types.h>
+#include <re_mem.h>
+#include <re_trace.h>
+#include <re_fmt.h>
+#include <re_list.h>
+#include <re_tmr.h>
+#include <re_lock.h>
+
+#ifdef HAVE_PTHREAD
+#include <pthread.h>
+#endif
+
+#if defined(WIN32)
+#include <windows.h>
+#else
+#include <unistd.h>
+#endif
+
+#define TRACE_BUFFER_SIZE 1000000
+
+struct trace_event {
+	const char *name;
+	const char *cat;
+	void *id;
+	uint64_t ts;
+	int pid;
+	unsigned long tid;
+	char ph;
+	re_trace_arg_type arg_type;
+	const char *arg_name;
+	union {
+		const char *a_str;
+		int a_int;
+	} arg;
+};
+
+/** Trace configuration */
+static struct {
+	int process_id;
+	FILE *f;
+	int event_count;
+	struct trace_event *event_buffer;
+	struct trace_event *event_buffer_flush;
+	struct lock *lock;
+	bool init;
+	uint64_t start_time;
+} trace = {
+	0,
+	NULL,
+	0,
+	NULL,
+	NULL,
+	NULL,
+	true,
+	0
+};
+
+
+static inline unsigned long get_thread_id(void)
+{
+#if defined(WIN32)
+	return (unsigned long)GetCurrentThreadId();
+#elif defined(DARWIN) || defined(FREEBSD) || defined(OPENBSD) || \
+      defined(NETBSD) || defined(DRAGONFLY)
+	return (unsigned long)(void *)pthread_self();
+#else
+	return (unsigned long)pthread_self();
+#endif
+}
+
+
+static inline int get_process_id(void)
+{
+#if defined(WIN32)
+	return (int)GetCurrentProcessId();
+#else
+	return (int)getpid();
+#endif
+}
+
+
+int re_trace_init(const char *json_file)
+{
+#ifndef RE_TRACE_ENABLED
+	return 0;
+#endif
+	int err = 0;
+
+	if (!json_file)
+		return EINVAL;
+
+	trace.event_buffer = mem_zalloc(
+		TRACE_BUFFER_SIZE * sizeof(struct trace_event), NULL);
+	if (!trace.event_buffer)
+		return ENOMEM;
+
+	trace.event_buffer_flush = mem_zalloc(
+		TRACE_BUFFER_SIZE * sizeof(struct trace_event), NULL);
+	if (!trace.event_buffer_flush) {
+		mem_deref(trace.event_buffer);
+		return ENOMEM;
+	}
+
+	lock_alloc(&trace.lock);
+
+	trace.f = fopen(json_file, "w+");
+	if (!trace.f) {
+		err = errno;
+		goto out;
+	}
+
+	(void)re_fprintf(trace.f, "{\t\n\t\"traceEvents\": [\n");
+	(void)fflush(trace.f);
+
+	trace.start_time = tmr_jiffies_usec();
+	trace.init = true;
+
+out:
+	if (err) {
+		trace.init = false;
+		mem_deref(trace.event_buffer);
+		mem_deref(trace.event_buffer_flush);
+	}
+
+	return err;
+}
+
+
+int re_trace_close(void)
+{
+#ifndef RE_TRACE_ENABLED
+	return 0;
+#endif
+	int err = 0;
+
+	re_trace_flush();
+
+	trace.event_buffer = mem_deref(trace.event_buffer);
+	trace.event_buffer_flush = mem_deref(trace.event_buffer_flush);
+	trace.lock = mem_deref(trace.lock);
+
+	(void)re_fprintf(trace.f, "\n\t]\n}\n");
+	if (trace.f)
+		err = fclose(trace.f);
+
+	if (err)
+		return errno;
+
+	trace.f = NULL;
+
+	return 0;
+}
+
+
+int re_trace_flush(void)
+{
+#ifndef RE_TRACE_ENABLED
+	return 0;
+#endif
+	int i, flush_count;
+	struct trace_event *event_tmp;
+	struct trace_event *e;
+	char json_arg[256];
+	char name[128];
+
+	if (!trace.lock)
+		return 0;
+
+	lock_write_get(trace.lock);
+	event_tmp = trace.event_buffer_flush;
+	trace.event_buffer_flush = trace.event_buffer;
+	trace.event_buffer = event_tmp;
+
+	flush_count = trace.event_count;
+	trace.event_count = 0;
+	lock_rel(trace.lock);
+
+	for (i = 0; i < flush_count; i++)
+	{
+		e = &trace.event_buffer_flush[i];
+
+		switch (e->arg_type) {
+		case RE_TRACE_ARG_NONE:
+			json_arg[0] = '\0';
+			break;
+		case RE_TRACE_ARG_INT:
+			(void)re_snprintf(json_arg, sizeof(json_arg),
+					", \"args\":{\"%s\":%i}",
+					e->arg_name, e->arg.a_int);
+			break;
+		case RE_TRACE_ARG_STRING_CONST:
+			(void)re_snprintf(json_arg, sizeof(json_arg),
+					", \"args\":{\"%s\":\"%s\"}",
+					e->arg_name, e->arg.a_str);
+			break;
+		case RE_TRACE_ARG_STRING_COPY:
+			(void)re_snprintf(json_arg, sizeof(json_arg),
+					", \"args\":{\"%s\":\"%s\"}",
+					e->arg_name, e->arg.a_str);
+
+			mem_deref((void *)e->arg.a_str);
+			break;
+		}
+
+		re_snprintf(name, sizeof(name), "\"name\":\"%s\"", e->name);
+
+		(void)re_fprintf(trace.f,
+			"%s{\"cat\":\"%s\",\"pid\":%i,\"tid\":%lu,\"ts\":%llu,"
+			"\"ph\":\"%c\",%s%s}",
+			trace.init ? "" : ",\n",
+			e->cat, e->pid, e->tid, e->ts - trace.start_time,
+			e->ph, name, str_isset(json_arg) ? json_arg : "");
+		trace.init = false;
+	}
+
+	(void)fflush(trace.f);
+	return 0;
+}
+
+
+void re_trace_event(const char *cat, const char *name, char ph, void *id,
+                    int32_t custom_id, re_trace_arg_type arg_type,
+                    const char *arg_name, void *arg_value)
+{
+#ifndef RE_TRACE_ENABLED
+	return;
+#endif
+	struct trace_event *e;
+
+	if (!trace.lock)
+		return;
+
+	lock_write_get(trace.lock);
+	if (trace.event_count >= TRACE_BUFFER_SIZE) {
+		lock_rel(trace.lock);
+		return;
+	}
+	e = &trace.event_buffer[trace.event_count];
+	++trace.event_count;
+	lock_rel(trace.lock);
+
+	e->ts = tmr_jiffies_usec();
+	e->id = id;
+	e->ph = ph;
+	e->cat = cat;
+	e->name = name;
+	e->pid = get_process_id();
+	if (custom_id) {
+		e->tid = custom_id;
+	}
+	else {
+		e->tid = get_thread_id();
+	}
+	e->arg_type = arg_type;
+	e->arg_name = arg_name;
+
+	switch (arg_type) {
+	case RE_TRACE_ARG_NONE:
+		break;
+	case RE_TRACE_ARG_INT:
+		e->arg.a_int = (int)(intptr_t)arg_value;
+		break;
+	case RE_TRACE_ARG_STRING_CONST:
+		e->arg.a_str = (const char *)arg_value;
+		break;
+	case RE_TRACE_ARG_STRING_COPY:
+		str_dup((char **)&e->arg.a_str,
+			(const char *)arg_value);
+		break;
+	}
+}