tildefriends/src/trace.c

#define _GNU_SOURCE
#include <pthread.h>
#undef _GNU_SOURCE

#include "trace.h"

#include "mem.h"

#include "sqlite3.h"
#include "uv.h"

#include <assert.h>
#include <stdio.h>
#include <string.h>
#include <time.h>
#include <unistd.h>

#if !defined(_countof)
#define _countof(a) ((int)(sizeof((a)) / sizeof(*(a))))
#endif

enum
{
	k_buffer_size = 4 * 1024 * 1024,
};

typedef struct _tf_trace_stack_t tf_trace_stack_t;

typedef struct _tf_trace_stack_t
{
	const char* names[256];
	const char* tags[256];
	int count;
	tf_trace_stack_t* next;
} tf_trace_stack_t;

typedef struct _tf_trace_thread_t
{
	pthread_t id;
	tf_trace_stack_t* stack;
	char name[64];
} tf_trace_thread_t;

typedef struct _tf_trace_t
{
	char buffer[k_buffer_size];
	char process_name[256];
	int write_offset;

	uv_mutex_t mutex;
	tf_trace_write_callback_t* callback;
	void* user_data;

	uv_rwlock_t threads_lock;
	tf_trace_thread_t** threads;
	int threads_count;
} tf_trace_t;

static void _trace_append(tf_trace_t* trace, const char* buffer, size_t size, void* user_data)
{
	uv_mutex_lock(&trace->mutex);
	if (trace->write_offset + size + 2 >= k_buffer_size)
	{
		trace->buffer[trace->write_offset] = '\0';
		trace->write_offset = 0;
	}

	if (trace->write_offset + size + 2 < k_buffer_size)
	{
		memcpy(trace->buffer + trace->write_offset, buffer, size);
		trace->write_offset += size;
		trace->buffer[trace->write_offset++] = '\n';
	}
	uv_mutex_unlock(&trace->mutex);
}

tf_trace_t* tf_trace_create()
{
	tf_trace_t* trace = tf_malloc(sizeof(tf_trace_t));
	memset(trace, 0, sizeof(*trace));
	trace->callback = _trace_append;
	uv_mutex_init(&trace->mutex);
	uv_rwlock_init(&trace->threads_lock);
	return trace;
}

void tf_trace_destroy(tf_trace_t* trace)
{
	for (int i = 0; i < trace->threads_count; i++)
	{
		tf_trace_thread_t* thread = trace->threads[i];
		while (thread->stack)
		{
			tf_trace_stack_t* stack = thread->stack;
			thread->stack = stack->next;
			tf_free(stack);
		}
		tf_free(thread);
	}
	tf_free(trace->threads);
	uv_rwlock_destroy(&trace->threads_lock);
	uv_mutex_destroy(&trace->mutex);
	tf_free(trace);
}

void tf_trace_set_process_name(tf_trace_t* trace, const char* name)
{
	snprintf(trace->process_name, sizeof(trace->process_name), "%s", name);
}

void tf_trace_raw(tf_trace_t* trace, const char* buffer, size_t size)
{
	trace->callback(trace, buffer, size, trace->user_data);
}

static int64_t _trace_ts()
{
	int64_t result = 0;
	struct timespec ts;
	if (clock_gettime(CLOCK_MONOTONIC, &ts) == 0)
	{
		result = (ts.tv_sec * 1e9 + ts.tv_nsec) / 1e3;
	}
	return result;
}

void tf_trace_counter(tf_trace_t* trace, const char* name, int argc, const char** arg_names, const int64_t* arg_values)
{
	if (!trace)
	{
		return;
	}

	char line[1024];
	int p = 0;
	p += snprintf(line + p, sizeof(line) - p, "{\"ph\": \"C\", \"pid\": %d, \"ts\": %" PRId64 ", \"name\": \"%s\", \"args\": {", getpid(), _trace_ts(), name);
	for (int i = 0; i < argc; i++)
	{
		p += snprintf(line + p, sizeof(line) - p, "\"%s\": %" PRId64 "%s", arg_names[i], arg_values[i], i == argc - 1 ? "}}," : ", ");
	}

	trace->callback(trace, line, p, trace->user_data);
}

static int _tf_trace_escape_name(char* out, size_t out_size, const char* name)
{
	int p = 0;
	for (const char* c = name; *c && (size_t)p < out_size; c++)
	{
		switch (*c)
		{
		case '"':
		case '\\':
			out[p++] = '\\';
			if ((size_t)p + 1 < out_size)
			{
				out[p++] = *c;
			}
			break;
		case '\t':
			out[p++] = '\\';
			if ((size_t)p + 1 < out_size)
			{
				out[p++] = 't';
			}
			break;
		case '\n':
			out[p++] = '\\';
			if ((size_t)p + 1 < out_size)
			{
				out[p++] = 'n';
			}
			break;
		default:
			out[p++] = *c;
			break;
		}
	}
	return p;
}

static tf_trace_thread_t* _tf_trace_get_thread(tf_trace_t* trace, pthread_t self)
{
	tf_trace_thread_t* found = NULL;
	uv_rwlock_rdlock(&trace->threads_lock);
	for (int i = 0; i < trace->threads_count; i++)
	{
		if (trace->threads[i]->id == self)
		{
			found = trace->threads[i];
			break;
		}
	}
	uv_rwlock_rdunlock(&trace->threads_lock);

	if (!found)
	{
		uv_rwlock_wrlock(&trace->threads_lock);
		/* Maybe it was added while we changed from rd to rw. */
		for (int i = 0; i < trace->threads_count; i++)
		{
			if (trace->threads[i]->id == self)
			{
				found = trace->threads[i];
				break;
			}
		}

		if (!found)
		{
			found = tf_malloc(sizeof(tf_trace_thread_t));
			*found = (tf_trace_thread_t)
			{
				.id = self,
			};
#if defined(__linux__)
			pthread_getname_np(self, found->name, sizeof(found->name));
#endif
			trace->threads = tf_resize_vec(trace->threads, sizeof(tf_trace_thread_t*) * (trace->threads_count + 1));
			trace->threads[trace->threads_count++] = found;
		}
		uv_rwlock_wrunlock(&trace->threads_lock);
	}

	return found;
}

static void _tf_push_stack(tf_trace_t* trace, pthread_t self, const char* name, void* tag)
{
	tf_trace_thread_t* thread = _tf_trace_get_thread(trace, self);
	if (!thread->stack || thread->stack->count + 1 > (int)_countof(thread->stack->names))
	{
		tf_trace_stack_t* stack = tf_malloc(sizeof(tf_trace_stack_t));
		memset(stack, 0, sizeof(*stack));
		stack->next = thread->stack;
		thread->stack = stack;
	}
	tf_trace_stack_t* stack = thread->stack;
	while (stack->count == 0 && stack->next && stack->next->count + 1 <= (int)_countof(thread->stack->names))
	{
		stack = stack->next;
	}
	stack->names[stack->count] = name;
	stack->tags[stack->count] = tag;
	stack->count++;

}

static const char* _tf_pop_stack(tf_trace_t* trace, pthread_t self, void* tag)
{
	tf_trace_thread_t* thread = _tf_trace_get_thread(trace, self);
	tf_trace_stack_t* stack = thread->stack;
	while (stack && stack->count == 0)
	{
		stack = stack->next;
	}
	const char* name = NULL;
	if (stack &&
		stack->count > 0 &&
		stack->tags[stack->count - 1] == tag)
	{
		name = stack->names[stack->count - 1];
		stack->count--;
	}
	return name;
}

static void _tf_trace_begin_tagged(tf_trace_t* trace, const char* name, void* tag)
{
	if (!trace || !name)
	{
		return;
	}

	pthread_t self = pthread_self();
	_tf_push_stack(trace, self, name, tag);

	char line[1024];
	int p = snprintf(line, sizeof(line), "{\"ph\": \"B\", \"pid\": %d, \"tid\": \"0x%" PRIx64 "\", \"ts\": %" PRId64 ", \"name\": \"", getpid(), (int64_t)self, _trace_ts());
	p += _tf_trace_escape_name(line + p, sizeof(line) - p, name);
	p += snprintf(line + p, sizeof(line) - p, "\"},");
	trace->callback(trace, line, p, trace->user_data);
}

void tf_trace_begin(tf_trace_t* trace, const char* name)
{
	_tf_trace_begin_tagged(trace, name, NULL);
}

static void _tf_trace_end_tagged(tf_trace_t* trace, void* tag)
{
	if (!trace)
	{
		return;
	}

	pthread_t self = pthread_self();
	const char* name = _tf_pop_stack(trace, self, tag);
	if (!name)
	{
		return;
	}

	char line[1024];
	int p = snprintf(line, sizeof(line), "{\"ph\": \"E\", \"pid\": %d, \"tid\": \"0x%" PRIx64 "\", \"ts\": %" PRId64 ", \"name\": \"", getpid(), (int64_t)pthread_self(), _trace_ts());
	p += _tf_trace_escape_name(line + p, sizeof(line) - p, name);
	p += snprintf(line + p, sizeof(line) - p,  "\"},");
	trace->callback(trace, line, p, trace->user_data);
}

void tf_trace_end(tf_trace_t* trace)
{
	_tf_trace_end_tagged(trace, NULL);
}

char* tf_trace_export(tf_trace_t* trace)
{
	if (!trace)
	{
		return NULL;
	}

	static const int k_extra_size = 1024;
	char* buffer = tf_malloc(k_buffer_size + k_extra_size);
	uv_mutex_lock(&trace->mutex);
	const char* newline = strchr(trace->buffer + trace->write_offset, '\n');
	int begin = newline ? newline - trace->buffer : 0;
	size_t size = 0;
	size += snprintf(buffer, k_buffer_size, "{\"displayTimeUnit\": \"ns\",\n\"traceEvents\": [\n");
	if (*trace->process_name)
	{
		size += snprintf(buffer + size, k_buffer_size - size,
			"{\"ph\":\"M\",\"pid\":%d,\"name\":\"process_name\",\"args\":{\"name\":\"%s\"}},\n",
			getpid(),
			trace->process_name);
	}
	uv_rwlock_rdlock(&trace->threads_lock);
	for (int i = 0; i < trace->threads_count; i++)
	{
		tf_trace_thread_t* thread = trace->threads[i];
		size += snprintf(buffer + size, k_buffer_size - size,
			"{\"ph\":\"M\",\"pid\":%d,\"tid\":\"0x%" PRIx64 "\",\"name\":\"thread_name\",\"args\":{\"name\":\"%s\"}},\n",
			getpid(),
			(uint64_t)thread->id,
			thread->name);
	}
	uv_rwlock_rdunlock(&trace->threads_lock);
	if (begin)
	{
		size_t this_size = strlen(trace->buffer + begin);
		memcpy(buffer + size, trace->buffer + begin, this_size);
		size += this_size;
	}
	memcpy(buffer + size, trace->buffer, trace->write_offset);
	size += trace->write_offset;
	uv_mutex_unlock(&trace->mutex);
	if (size > 2 && buffer[size - 1] == '\n' && buffer[size - 2] == ',')
	{
		buffer[size - 2] = '\n';
		size--;
	}
	size += snprintf(buffer + size, k_buffer_size - size, "]}\n");
	assert(size < (size_t)k_buffer_size + k_extra_size);
	buffer[size] = '\0';
	return buffer;
}

static int _tf_trace_sqlite_callback(unsigned int t, void* c, void* p, void* x)
{
	tf_trace_t* trace = c;
	switch (t)
	{
	case SQLITE_TRACE_STMT:
		{
			const char* statement = x;
			if (statement[0] != '-' || statement[1] != '-')
			{
				_tf_trace_begin_tagged(trace, statement, p);
			}
		}
		break;
	case SQLITE_TRACE_PROFILE:
		_tf_trace_end_tagged(trace, p);
		break;
	}
	return 0;
}

void tf_trace_set_write_callback(tf_trace_t* trace, tf_trace_write_callback_t* callback, void* user_data)
{
	trace->callback = callback;
	trace->user_data = user_data;
}

void tf_trace_sqlite(tf_trace_t* trace, sqlite3* sqlite)
{
	if (sqlite)
	{
		sqlite3_trace_v2(sqlite, SQLITE_TRACE_STMT | SQLITE_TRACE_PROFILE, _tf_trace_sqlite_callback, trace);
	}
	else
	{
		sqlite3_trace_v2(sqlite, 0, NULL, NULL);
	}
}