modified) versions of this file, nor is leaving this notice intact mandatory.
-------------------------------------------------------------------------------
+src/minitrace.[hc]
+~~~~~~~~~~~~~~~~~~
+
+A library for producing JSON traces suitable for Chrome's built-in trace viewer
+(chrome://tracing). Downloaded from <https://github.com/hrydgard/minitrace>
+
+-------------------------------------------------------------------------------
+The MIT License (MIT)
+
+Copyright (c) 2014 Henrik Rydgård
+
+Permission is hereby granted, free of charge, to any person obtaining a copy
+of this software and associated documentation files (the "Software"), to deal
+in the Software without restriction, including without limitation the rights
+to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+copies of the Software, and to permit persons to whom the Software is
+furnished to do so, subject to the following conditions:
+
+The above copyright notice and this permission notice shall be included in all
+copies or substantial portions of the Software.
+
+THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+SOFTWARE.
+-------------------------------------------------------------------------------
src/zlib/*.[hc]
~~~~~~~~~~~~~~~
src/hashtable_itr.c \
src/murmurhashneutral2.c \
src/snprintf.c
-base_sources = $(non_3pp_sources) $(generated_sources) $(3pp_sources)
+extra_sources = @extra_sources@
+base_sources = $(non_3pp_sources) $(generated_sources) $(3pp_sources) $(extra_sources)
base_objs = $(base_sources:.c=.o)
non_3pp_objs = $(non_3pp_sources:.c=.o)
AC_SUBST(disable_man)
AC_SUBST(extra_libs)
+AC_SUBST(extra_sources)
AC_SUBST(include_dev_mk)
AC_SUBST(more_warnings)
AC_SUBST(no_implicit_fallthrough_warning)
disable_man='#'
fi
+AC_ARG_ENABLE(tracing,
+ [AS_HELP_STRING([--enable-tracing],
+ [enable possibility to use internal ccache tracing])])
+if test x${enable_tracing} = xyes; then
+ CPPFLAGS="$CPPFLAGS -DMTR_ENABLED"
+ extra_sources="src/minitrace.c"
+fi
+
dnl Linking on Windows needs ws2_32
if test x${windows_os} = xyes; then
LIBS="$LIBS -lws2_32"
src/macroskip.h \
src/manifest.h \
src/mdfour.h \
+ src/minitrace.h \
src/murmurhashneutral2.h \
src/system.h \
src/unify.h \
src/envtoconfitems.gperf \
src/envtoconfitems_lookup.c \
src/main.c \
+ src/minitrace.c \
src/zlib/*.c \
src/zlib/*.h \
test/run \
--- /dev/null
+Developer Manual
+================
+
+Tracing
+-------
+
+In order to see what ccache is doing, it is possible to enable microsecond tracing.
+This needs to be done when compiling ccache, using the `--enable-tracing` feature.
+
+By setting *CCACHE_INTERNAL_TRACE*, one can obtain a trace of an individual compile.
+This trace can then be loaded into the `chrome://tracing` page of Chromium/Chrome.
+
+The current event categories are: config, main, hash, manifest, cache, file, execute
+
+With a unique file per compile, there is a script to combine them all into one trace:
+
+`misc/combine_events.py file1.json file2.json file3.json | gzip > ccache.trace.gz`
+
+This will offset each invididual trace by starting time, to make one combined trace.
+
+If you set the variable, the trace JSON output will be put next to the object file:
+
+e.g. `output.o.ccache-trace`
+
+This is done by first generating a temporary file, until the output name is known.
+
+There is another script, to generate a summary (per job slot) of all the ccache runs:
+
+`misc/combine_events.py *.ccache-trace | misc/summarize_events.py 1 > ccache.trace`
+
+You will need to give the number of job slots used (`make -j`), as input to the script.
--- /dev/null
+#!/usr/bin/env python
+
+import sys
+import json
+
+traces = {}
+for arg in sys.argv[1:]:
+ object = json.load(open(arg))
+ for event in object["traceEvents"]:
+ if event["name"] == "" and event["ph"] == "I":
+ time = float(event["args"]["time"])
+ # print "%.6f" % time
+ traces[time] = object
+ break
+
+times = traces.keys()
+mintime = min(times)
+times.sort()
+
+events = []
+for time in times:
+ offset = (time - mintime) * 1000000.0
+ object = traces[time]
+ for event in object["traceEvents"]:
+ event["ts"] = int(event["ts"] + offset)
+ events.append(event)
+
+print json.dumps({"traceEvents": events})
--- /dev/null
+#!/usr/bin/env python
+
+import sys
+import json
+
+trace = json.load(sys.stdin)
+
+events = trace["traceEvents"]
+slotevents = []
+
+events.sort(key = lambda event: event["ts"])
+
+jobs = int(sys.argv[1])
+
+pids = {}
+busy = [None] * jobs
+
+def find_slot(pid):
+ if pid in pids:
+ return pids[pid]
+ for slot in range(jobs):
+ if not busy[slot]:
+ busy[slot] = pid
+ pids[pid] = slot
+ return slot
+ return None
+
+def end_slot(pid):
+ for slot in range(jobs):
+ if busy[slot] == pid:
+ busy[slot] = None
+ del pids[pid]
+ return slot
+ return slot
+
+name = {}
+slot = -1
+for event in events:
+ cat = event['cat']
+ pid = event['pid']
+ phase = event['ph']
+ args = event['args']
+
+ if phase == 'M' and event['name'] == "thread_name":
+ name[pid] = args["name"]
+ if cat != "program":
+ continue
+
+ if phase == 'B' or phase == 'S':
+ slot = find_slot(pid)
+ elif phase == 'E' or phase == 'F':
+ slot = end_slot(pid)
+ elif phase == 'M':
+ pass
+ else:
+ continue
+
+ event['pid'] = slot
+ event['tid'] = pid
+
+ slotevents.append(event)
+
+slotevents.sort(key = lambda event: event["tid"])
+
+for event in slotevents:
+ if event['cat'] == "program":
+ event['cat'] = "ccache"
+ if event['tid'] in name:
+ event['name'] = name[event['tid']]
+ else:
+ if event['tid'] in name:
+ event['name'] = event['name'] + ':' + name[event['tid']]
+ del event['tid']
+ if event['ph'] == 'S':
+ event['ph'] = 'B'
+ if event['ph'] == 'F':
+ event['ph'] = 'E'
+
+for slot in range(jobs):
+ slotevents.append({"cat":"","pid":slot,"tid":0,"ph":"M","name":"process_name","args":{"name":"Job %d" % slot}})
+
+json.dump({"traceEvents": slotevents}, sys.stdout, indent=4)
if (stat(manifest_path, &st) == 0) {
old_size = file_size(&st);
}
+ MTR_BEGIN("manifest", "manifest_put");
if (manifest_put(manifest_path, cached_obj_hash, included_files)) {
cc_log("Added object file hash to %s", manifest_path);
if (x_stat(manifest_path, &st) == 0) {
} else {
cc_log("Failed to add object file hash to %s", manifest_path);
}
+ MTR_END("manifest", "manifest_put");
}
static void
}
cc_log("Running real compiler");
+ MTR_BEGIN("execute", "compiler");
char *tmp_stdout;
int tmp_stdout_fd;
char *tmp_stderr;
depend_mode_args->argv, tmp_stdout_fd, tmp_stderr_fd, &compiler_pid);
args_free(depend_mode_args);
}
+ MTR_END("execute", "compiler");
struct stat st;
if (x_stat(tmp_stdout, &st) != 0) {
tmp_unlink(tmp_stderr);
}
+ MTR_BEGIN("file", "file_put");
+
copy_file_to_cache(output_obj, cached_obj);
if (generating_dependencies) {
copy_file_to_cache(output_dep, cached_dep);
copy_file_to_cache(output_dwo, cached_dwo);
}
+ MTR_END("file", "file_put");
+
stats_update(STATS_TOCACHE);
// Make sure we have a CACHEDIR.TAG in the cache part of cache_dir. This can
args_add(args, input_file);
add_prefix(args, conf->prefix_command_cpp);
cc_log("Running preprocessor");
+ MTR_BEGIN("execute", "preprocessor");
status = execute(args->argv, path_stdout_fd, path_stderr_fd, &compiler_pid);
+ MTR_END("execute", "preprocessor");
args_pop(args, args_added);
}
free(manifest_name);
cc_log("Looking for object file hash in %s", manifest_path);
+ MTR_BEGIN("manifest", "manifest_get");
object_hash = manifest_get(conf, manifest_path);
+ MTR_END("manifest", "manifest_get");
if (object_hash) {
cc_log("Got object file hash from manifest");
update_mtime(manifest_path);
return;
}
+ MTR_BEGIN("cache", "from_cache");
+
// (If mode != FROMCACHE_DIRECT_MODE, the dependency file is created by gcc.)
bool produce_dep_file =
generating_dependencies && mode == FROMCACHE_DIRECT_MODE;
+ MTR_BEGIN("file", "file_get");
+
// Get result from cache.
if (!str_eq(output_obj, "/dev/null")) {
get_file_from_cache(cached_obj, output_obj);
get_file_from_cache(cached_dia, output_dia);
}
+ MTR_END("file", "file_get");
+
// Update modification timestamps to save files from LRU cleanup. Also gives
// files a sensible mtime when hard-linking.
update_mtime(cached_obj);
break;
}
+ MTR_END("cache", "from_cache");
+
// And exit with the right status code.
x_exit(0);
}
fclose(f);
}
+#ifdef MTR_ENABLED
+static void *trace_id;
+static const char *trace_file;
+#endif
+
+#ifdef MTR_ENABLED
+static void trace_init(const char *json)
+{
+ trace_file = json;
+ mtr_init(json);
+ char *s = format("%f", time_seconds());
+ MTR_INSTANT_C("", "", "time", s);
+}
+
+static void trace_start(const char *json)
+{
+ trace_file = json;
+ cc_log("Starting tracing: %s", json);
+ MTR_META_PROCESS_NAME(MYNAME);
+ trace_id = (void *) ((long) getpid());
+ MTR_START("program", "ccache", trace_id);
+}
+
+static void trace_stop(void *context)
+{
+ const char *json = (const char *) context;
+ if (str_eq(json, "")) {
+ json = format("%s%s", output_obj, ".ccache-trace");
+ }
+ cc_log("Stopping tracing: %s", json);
+ MTR_FINISH("program", "ccache", trace_id);
+ mtr_flush();
+ mtr_shutdown();
+ if (!str_eq(trace_file, json)) {
+ move_file(trace_file, json, 0);
+ }
+}
+
+static const char *
+tmpdir()
+{
+#ifndef _WIN32
+ const char *tmpdir = getenv("TMPDIR");
+ if (tmpdir != NULL) {
+ return tmpdir;
+ }
+#else
+ static char dirbuf[PATH_MAX];
+ DWORD retval = GetTempPath(PATH_MAX, dirbuf);
+ if (retval > 0 && retval < PATH_MAX) {
+ return dirbuf;
+ }
+#endif
+ return "/tmp";
+}
+#endif
+
// Read config file(s), populate variables, create configuration file in cache
// directory if missing, etc.
static void
initialize(void)
{
+ char *tracefile = getenv("CCACHE_INTERNAL_TRACE");
+ if (tracefile != NULL) {
+#ifdef MTR_ENABLED
+ // We don't have any conf yet, so we can't use temp_dir() here
+ tracefile = format("%s/trace.%d.json", tmpdir(), (int)getpid());
+
+ trace_init(tracefile);
+#else
+ cc_log("Error: tracing is not enabled!");
+#endif
+ }
+
conf_free(conf);
+ MTR_BEGIN("config", "conf_create");
conf = conf_create();
+ MTR_END("config", "conf_create");
char *errmsg;
char *p = getenv("CCACHE_CONFIGPATH");
primary_config_path = x_strdup(p);
} else {
secondary_config_path = format("%s/ccache.conf", TO_STRING(SYSCONFDIR));
+ MTR_BEGIN("config", "conf_read_secondary");
if (!conf_read(conf, secondary_config_path, &errmsg)) {
if (errno == 0) {
// We could read the file but it contained errors.
// A missing config file in SYSCONFDIR is OK.
free(errmsg);
}
+ MTR_END("config", "conf_read_secondary");
if (str_eq(conf->cache_dir, "")) {
fatal("configuration setting \"cache_dir\" must not be the empty string");
}
bool should_create_initial_config = false;
+ MTR_BEGIN("config", "conf_read_primary");
if (!conf_read(conf, primary_config_path, &errmsg)) {
if (errno == 0) {
// We could read the file but it contained errors.
should_create_initial_config = true;
}
}
+ MTR_END("config", "conf_read_primary");
+ MTR_BEGIN("config", "conf_update_from_environment");
if (!conf_update_from_environment(conf, &errmsg)) {
fatal("%s", errmsg);
}
+ MTR_END("config", "conf_update_from_environment");
if (should_create_initial_config) {
create_initial_config_file(primary_config_path);
if (conf->umask != UINT_MAX) {
umask(conf->umask);
}
+
+#ifdef MTR_ENABLED
+ if (tracefile != NULL) {
+ trace_start(tracefile);
+ exitfn_add(trace_stop, tracefile);
+ }
+#endif
}
// Reset the global state. Used by the test suite.
orig_args = args_init(argc, argv);
initialize();
+ MTR_BEGIN("main", "find_compiler");
find_compiler(argv);
+ MTR_END("main", "find_compiler");
+ MTR_BEGIN("main", "clean_up_internal_tempdir");
if (str_eq(conf->temporary_dir, "")) {
clean_up_internal_tempdir();
}
+ MTR_END("main", "clean_up_internal_tempdir");
if (!str_eq(conf->log_file, "") || conf->debug) {
conf_print_items(conf, configuration_logger, NULL);
failed();
}
+ MTR_BEGIN("main", "set_up_uncached_err");
set_up_uncached_err();
+ MTR_END("main", "set_up_uncached_err");
cc_log_argv("Command line: ", argv);
cc_log("Hostname: %s", get_hostname());
conf->limit_multiple = MIN(MAX(conf->limit_multiple, 0.0), 1.0);
+ MTR_BEGIN("main", "guess_compiler");
guessed_compiler = guess_compiler(orig_args->argv[0]);
+ MTR_END("main", "guess_compiler");
// Arguments (except -E) to send to the preprocessor.
struct args *preprocessor_args;
// Arguments to send to the real compiler.
struct args *compiler_args;
+ MTR_BEGIN("main", "process_args");
if (!cc_process_args(orig_args, &preprocessor_args, &compiler_args)) {
failed();
}
+ MTR_END("main", "process_args");
if (conf->depend_mode
&& (!generating_dependencies || !conf->run_second_cpp || conf->unify)) {
}
cc_log("Object file: %s", output_obj);
+ MTR_META_THREAD_NAME(output_obj);
// Need to dump log buffer as the last exit function to not lose any logs.
exitfn_add_last(dump_debug_log_buffer_exitfn, output_obj);
struct hash *common_hash = hash_init();
init_hash_debug(common_hash, output_obj, 'c', "COMMON", debug_text_file);
+ MTR_BEGIN("hash", "common_hash");
calculate_common_hash(preprocessor_args, common_hash);
+ MTR_END("hash", "common_hash");
// Try to find the hash using the manifest.
struct hash *direct_hash = hash_copy(common_hash);
struct file_hash *object_hash_from_manifest = NULL;
if (conf->direct_mode) {
cc_log("Trying direct lookup");
+ MTR_BEGIN("hash", "direct_hash");
object_hash = calculate_object_hash(preprocessor_args, direct_hash, 1);
+ MTR_END("hash", "direct_hash");
if (object_hash) {
update_cached_result_globals(object_hash);
init_hash_debug(
cpp_hash, output_obj, 'p', "PREPROCESSOR MODE", debug_text_file);
+ MTR_BEGIN("hash", "cpp_hash");
object_hash = calculate_object_hash(preprocessor_args, cpp_hash, 0);
+ MTR_END("hash", "cpp_hash");
if (!object_hash) {
fatal("internal error: object hash from cpp returned NULL");
}
struct hash *depend_mode_hash = conf->depend_mode ? direct_hash : NULL;
// Run real compiler, sending output to cache.
+ MTR_BEGIN("cache", "to_cache");
to_cache(compiler_args, depend_mode_hash);
+ MTR_END("cache", "to_cache");
x_exit(0);
}
#include "system.h"
#include "conf.h"
#include "counters.h"
+#include "minitrace.h"
#ifdef __GNUC__
#define ATTR_FORMAT(x, y, z) __attribute__((format (x, y, z)))
char *read_text_file(const char *path, size_t size_hint);
char *subst_env_in_string(const char *str, char **errmsg);
void set_cloexec_flag(int fd);
+double time_seconds(void);
// ----------------------------------------------------------------------------
// stats.c
--- /dev/null
+// minitrace
+// Copyright 2014 by Henrik Rydgård
+// http://www.github.com/hrydgard/minitrace
+// Released under the MIT license.
+
+// See minitrace.h for basic documentation.
+
+#include <stdlib.h>
+#include <stdio.h>
+#include <string.h>
+
+#ifdef _WIN32
+#pragma warning (disable:4996)
+#define WIN32_LEAN_AND_MEAN
+#include <windows.h>
+#define __thread __declspec(thread)
+#define pthread_mutex_t CRITICAL_SECTION
+#define pthread_mutex_init(a, b) InitializeCriticalSection(a)
+#define pthread_mutex_lock(a) EnterCriticalSection(a)
+#define pthread_mutex_unlock(a) LeaveCriticalSection(a)
+#define pthread_mutex_destroy(a) DeleteCriticalSection(a)
+#else
+#include <signal.h>
+#include <pthread.h>
+#include <sys/time.h>
+#include <unistd.h>
+#endif
+
+#include "minitrace.h"
+
+#ifdef __GNUC__
+#define ATTR_NORETURN __attribute__((noreturn))
+#else
+#define ATTR_NORETURN
+#endif
+
+#define ARRAY_SIZE(x) sizeof(x)/sizeof(x[0])
+
+// Ugh, this struct is already pretty heavy.
+// Will probably need to move arguments to a second buffer to support more than one.
+typedef struct raw_event {
+ const char *name;
+ const char *cat;
+ void *id;
+ int64_t ts;
+ uint32_t pid;
+ uint32_t tid;
+ char ph;
+ mtr_arg_type arg_type;
+ const char *arg_name;
+ union {
+ const char *a_str;
+ int a_int;
+ double a_double;
+ };
+} raw_event_t;
+
+static raw_event_t *buffer;
+static volatile int count;
+static int is_tracing = 0;
+static int64_t time_offset;
+static int first_line = 1;
+static FILE *f;
+static __thread int cur_thread_id; // Thread local storage
+static int cur_process_id;
+static pthread_mutex_t mutex;
+
+#define STRING_POOL_SIZE 100
+static char *str_pool[100];
+
+// Tiny portability layer.
+// Exposes:
+// get_cur_thread_id()
+// get_cur_process_id()
+// mtr_time_s()
+// pthread basics
+#ifdef _WIN32
+static int get_cur_thread_id() {
+ return (int)GetCurrentThreadId();
+}
+static int get_cur_process_id() {
+ return (int)GetCurrentProcessId();
+}
+
+static uint64_t _frequency = 0;
+static uint64_t _starttime = 0;
+double mtr_time_s() {
+ if (_frequency == 0) {
+ QueryPerformanceFrequency((LARGE_INTEGER*)&_frequency);
+ QueryPerformanceCounter((LARGE_INTEGER*)&_starttime);
+ }
+ __int64 time;
+ QueryPerformanceCounter((LARGE_INTEGER*)&time);
+ return ((double) (time - _starttime) / (double) _frequency);
+}
+
+// Ctrl+C handling for Windows console apps
+static BOOL WINAPI CtrlHandler(DWORD fdwCtrlType) {
+ if (is_tracing && fdwCtrlType == CTRL_C_EVENT) {
+ printf("Ctrl-C detected! Flushing trace and shutting down.\n\n");
+ mtr_flush();
+ mtr_shutdown();
+ }
+ ExitProcess(1);
+}
+
+void mtr_register_sigint_handler() {
+ // For console apps:
+ SetConsoleCtrlHandler(&CtrlHandler, TRUE);
+}
+
+#else
+
+static inline int get_cur_thread_id() {
+ return (int)(intptr_t)pthread_self();
+}
+static inline int get_cur_process_id() {
+ return (int)getpid();
+}
+
+#if defined(BLACKBERRY)
+double mtr_time_s() {
+ struct timespec time;
+ clock_gettime(CLOCK_MONOTONIC, &time); // Linux must use CLOCK_MONOTONIC_RAW due to time warps
+ return time.tv_sec + time.tv_nsec / 1.0e9;
+}
+#else
+double mtr_time_s() {
+ static time_t start;
+ struct timeval tv;
+ gettimeofday(&tv, NULL);
+ if (start == 0) {
+ start = tv.tv_sec;
+ }
+ tv.tv_sec -= start;
+ return (double)tv.tv_sec + (double)tv.tv_usec / 1000000.0;
+}
+#endif // !BLACKBERRY
+
+static void termination_handler(int signum) ATTR_NORETURN;
+static void termination_handler(int signum) {
+ (void) signum;
+ if (is_tracing) {
+ printf("Ctrl-C detected! Flushing trace and shutting down.\n\n");
+ mtr_flush();
+ fwrite("\n]}\n", 1, 4, f);
+ fclose(f);
+ }
+ exit(1);
+}
+
+void mtr_register_sigint_handler() {
+#ifndef MTR_ENABLED
+ return;
+#endif
+ // Avoid altering set-to-be-ignored handlers while registering.
+ if (signal(SIGINT, &termination_handler) == SIG_IGN)
+ signal(SIGINT, SIG_IGN);
+}
+
+#endif
+
+void mtr_init(const char *json_file) {
+#ifndef MTR_ENABLED
+ return;
+#endif
+ buffer = (raw_event_t *)malloc(INTERNAL_MINITRACE_BUFFER_SIZE * sizeof(raw_event_t));
+ is_tracing = 1;
+ count = 0;
+ f = fopen(json_file, "wb");
+ const char *header = "{\"traceEvents\":[\n";
+ fwrite(header, 1, strlen(header), f);
+ time_offset = (uint64_t)(mtr_time_s() * 1000000);
+ first_line = 1;
+ pthread_mutex_init(&mutex, 0);
+}
+
+void mtr_shutdown() {
+ int i;
+#ifndef MTR_ENABLED
+ return;
+#endif
+ is_tracing = 0;
+ mtr_flush();
+ fwrite("\n]}\n", 1, 4, f);
+ fclose(f);
+ pthread_mutex_destroy(&mutex);
+ f = 0;
+ free(buffer);
+ buffer = 0;
+ for (i = 0; i < STRING_POOL_SIZE; i++) {
+ if (str_pool[i]) {
+ free(str_pool[i]);
+ str_pool[i] = 0;
+ }
+ }
+}
+
+const char *mtr_pool_string(const char *str) {
+ int i;
+ for (i = 0; i < STRING_POOL_SIZE; i++) {
+ if (!str_pool[i]) {
+ str_pool[i] = (char*)malloc(strlen(str) + 1);
+ strcpy(str_pool[i], str);
+ return str_pool[i];
+ } else {
+ if (!strcmp(str, str_pool[i]))
+ return str_pool[i];
+ }
+ }
+ return "string pool full";
+}
+
+void mtr_start() {
+#ifndef MTR_ENABLED
+ return;
+#endif
+ is_tracing = 1;
+}
+
+void mtr_stop() {
+#ifndef MTR_ENABLED
+ return;
+#endif
+ is_tracing = 0;
+}
+
+// TODO: fwrite more than one line at a time.
+void mtr_flush() {
+#ifndef MTR_ENABLED
+ return;
+#endif
+ int i = 0;
+ char linebuf[1024];
+ char arg_buf[256];
+ char id_buf[256];
+ // We have to lock while flushing. So we really should avoid flushing as much as possible.
+
+
+ pthread_mutex_lock(&mutex);
+ int old_tracing = is_tracing;
+ is_tracing = 0; // Stop logging even if using interlocked increments instead of the mutex. Can cause data loss.
+
+ for (i = 0; i < count; i++) {
+ raw_event_t *raw = &buffer[i];
+ int len;
+ switch (raw->arg_type) {
+ case MTR_ARG_TYPE_INT:
+ snprintf(arg_buf, ARRAY_SIZE(arg_buf), "\"%s\":%i", raw->arg_name, raw->a_int);
+ break;
+ case MTR_ARG_TYPE_STRING_CONST:
+ snprintf(arg_buf, ARRAY_SIZE(arg_buf), "\"%s\":\"%s\"", raw->arg_name, raw->a_str);
+ break;
+ case MTR_ARG_TYPE_STRING_COPY:
+ if (strlen(raw->a_str) > 700) {
+ snprintf(arg_buf, ARRAY_SIZE(arg_buf), "\"%s\":\"%.*s\"", raw->arg_name, 700, raw->a_str);
+ } else {
+ snprintf(arg_buf, ARRAY_SIZE(arg_buf), "\"%s\":\"%s\"", raw->arg_name, raw->a_str);
+ }
+ break;
+ case MTR_ARG_TYPE_NONE:
+ arg_buf[0] = '\0';
+ break;
+ }
+ if (raw->id) {
+ switch (raw->ph) {
+ case 'S':
+ case 'T':
+ case 'F':
+ // TODO: Support full 64-bit pointers
+ snprintf(id_buf, ARRAY_SIZE(id_buf), ",\"id\":\"0x%08x\"", (uint32_t)(uintptr_t)raw->id);
+ break;
+ case 'X':
+ snprintf(id_buf, ARRAY_SIZE(id_buf), ",\"dur\":%i", (int)raw->a_double);
+ break;
+ }
+ } else {
+ id_buf[0] = 0;
+ }
+ const char *cat = raw->cat;
+#ifdef _WIN32
+ // On Windows, we often end up with backslashes in category.
+ {
+ char temp[256];
+ int len = (int)strlen(cat);
+ int i;
+ if (len > 255) len = 255;
+ for (i = 0; i < len; i++) {
+ temp[i] = cat[i] == '\\' ? '/' : cat[i];
+ }
+ temp[len] = 0;
+ cat = temp;
+ }
+#endif
+
+ len = snprintf(linebuf, ARRAY_SIZE(linebuf), "%s{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 ",\"ph\":\"%c\",\"name\":\"%s\",\"args\":{%s}%s}",
+ first_line ? "" : ",\n",
+ cat, raw->pid, raw->tid, raw->ts - time_offset, raw->ph, raw->name, arg_buf, id_buf);
+ fwrite(linebuf, 1, len, f);
+ first_line = 0;
+ }
+ count = 0;
+ is_tracing = old_tracing;
+ pthread_mutex_unlock(&mutex);
+}
+
+void internal_mtr_raw_event(const char *category, const char *name, char ph, void *id) {
+#ifndef MTR_ENABLED
+ return;
+#endif
+ if (!is_tracing || count >= INTERNAL_MINITRACE_BUFFER_SIZE)
+ return;
+ double ts = mtr_time_s();
+ if (!cur_thread_id) {
+ cur_thread_id = get_cur_thread_id();
+ }
+ if (!cur_process_id) {
+ cur_process_id = get_cur_process_id();
+ }
+
+#if 0 && _WIN32 // TODO: This needs testing
+ int bufPos = InterlockedIncrement(&count);
+ raw_event_t *ev = &buffer[count - 1];
+#else
+ pthread_mutex_lock(&mutex);
+ raw_event_t *ev = &buffer[count];
+ count++;
+ pthread_mutex_unlock(&mutex);
+#endif
+
+ ev->cat = category;
+ ev->name = name;
+ ev->id = id;
+ ev->ph = ph;
+ if (ev->ph == 'X') {
+ double x;
+ memcpy(&x, id, sizeof(double));
+ ev->ts = (int64_t)(x * 1000000);
+ ev->a_double = (ts - x) * 1000000;
+ } else {
+ ev->ts = (int64_t)(ts * 1000000);
+ }
+ ev->tid = cur_thread_id;
+ ev->pid = cur_process_id;
+}
+
+void internal_mtr_raw_event_arg(const char *category, const char *name, char ph, void *id, mtr_arg_type arg_type, const char *arg_name, void *arg_value) {
+#ifndef MTR_ENABLED
+ return;
+#endif
+ if (!is_tracing || count >= INTERNAL_MINITRACE_BUFFER_SIZE)
+ return;
+ if (!cur_thread_id) {
+ cur_thread_id = get_cur_thread_id();
+ }
+ if (!cur_process_id) {
+ cur_process_id = get_cur_process_id();
+ }
+ double ts = mtr_time_s();
+
+#if 0 && _WIN32 // TODO: This needs testing
+ int bufPos = InterlockedIncrement(&count);
+ raw_event_t *ev = &buffer[count - 1];
+#else
+ pthread_mutex_lock(&mutex);
+ raw_event_t *ev = &buffer[count];
+ count++;
+ pthread_mutex_unlock(&mutex);
+#endif
+
+ ev->cat = category;
+ ev->name = name;
+ ev->id = id;
+ ev->ts = (int64_t)(ts * 1000000);
+ ev->ph = ph;
+ ev->tid = cur_thread_id;
+ ev->pid = cur_process_id;
+ ev->arg_type = arg_type;
+ ev->arg_name = arg_name;
+ switch (arg_type) {
+ case MTR_ARG_TYPE_INT: ev->a_int = (int)(uintptr_t)arg_value; break;
+ case MTR_ARG_TYPE_STRING_CONST: ev->a_str = (const char*)arg_value; break;
+ case MTR_ARG_TYPE_STRING_COPY: ev->a_str = strdup((const char*)arg_value); break;
+ case MTR_ARG_TYPE_NONE: break;
+ }
+}
+
--- /dev/null
+// Minitrace
+//
+// Copyright 2014 by Henrik Rydgård
+// http://www.github.com/hrydgard/minitrace
+// Released under the MIT license.
+//
+// Ultra-light dependency free library for performance tracing C/C++ applications.
+// Produces traces compatible with Google Chrome's trace viewer.
+// Simply open "about:tracing" in Chrome and load the produced JSON.
+//
+// This contains far less template magic than the original libraries from Chrome
+// because this is meant to be usable from C.
+//
+// See README.md for a tutorial.
+//
+// The trace format is documented here:
+// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/edit
+// More:
+// http://www.altdevblogaday.com/2012/08/21/using-chrometracing-to-view-your-inline-profiling-data/
+
+#include <inttypes.h>
+
+// If MTR_ENABLED is not defined, Minitrace does nothing and has near zero overhead.
+// Preferably, set this flag in your build system. If you can't just uncomment this line.
+// #define MTR_ENABLED
+
+// By default, will collect up to 1000000 events, then you must flush.
+// It's recommended that you simply call mtr_flush on a background thread
+// occasionally. It's safe...ish.
+#define INTERNAL_MINITRACE_BUFFER_SIZE 1000000
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+// Initializes Minitrace. Must be called very early during startup of your executable,
+// before any MTR_ statements..
+void mtr_init(const char *json_file);
+
+// Shuts down minitrace cleanly, flushing the trace buffer.
+void mtr_shutdown(void);
+
+// Lets you enable and disable Minitrace at runtime.
+// May cause strange discontinuities in the output.
+// Minitrace is enabled on startup by default.
+void mtr_start(void);
+void mtr_stop(void);
+
+// Flushes the collected data to disk, clearing the buffer for new data.
+void mtr_flush(void);
+
+// Returns the current time in seconds. Used internally by Minitrace. No caching.
+double mtr_time_s(void);
+
+// Registers a handler that will flush the trace on Ctrl+C.
+// Works on Linux and MacOSX, and in Win32 console applications.
+void mtr_register_sigint_handler(void);
+
+// Utility function that should rarely be used.
+// If str is semi dynamic, store it permanently in a small pool so we don't need to malloc it.
+// The pool fills up fast though and performance isn't great.
+// Returns a fixed string if the pool is full.
+const char *mtr_pool_string(const char *str);
+
+// Commented-out types will be supported in the future.
+typedef enum {
+ MTR_ARG_TYPE_NONE = 0,
+ MTR_ARG_TYPE_INT = 1, // I
+ // MTR_ARG_TYPE_FLOAT = 2, // TODO
+ // MTR_ARG_TYPE_DOUBLE = 3, // TODO
+ MTR_ARG_TYPE_STRING_CONST = 8, // C
+ MTR_ARG_TYPE_STRING_COPY = 9,
+ // MTR_ARG_TYPE_JSON_COPY = 10,
+} mtr_arg_type;
+
+// TODO: Add support for more than one argument (metadata) per event
+// Having more costs speed and memory.
+#define MTR_MAX_ARGS 1
+
+// Only use the macros to call these.
+void internal_mtr_raw_event(const char *category, const char *name, char ph, void *id);
+void internal_mtr_raw_event_arg(const char *category, const char *name, char ph, void *id, mtr_arg_type arg_type, const char *arg_name, void *arg_value);
+
+#ifdef MTR_ENABLED
+
+// c - category. Can be filtered by in trace viewer (or at least that's the intention).
+// A good use is to pass __FILE__, there are macros further below that will do it for you.
+// n - name. Pass __FUNCTION__ in most cases, unless you are marking up parts of one.
+
+// Scopes. In C++, use MTR_SCOPE. In C, always match them within the same scope.
+#define MTR_BEGIN(c, n) internal_mtr_raw_event(c, n, 'B', 0)
+#define MTR_END(c, n) internal_mtr_raw_event(c, n, 'E', 0)
+#define MTR_SCOPE(c, n) MTRScopedTrace ____mtr_scope(c, n)
+#define MTR_SCOPE_LIMIT(c, n, l) MTRScopedTraceLimit ____mtr_scope(c, n, l)
+
+// Async events. Can span threads. ID identifies which events to connect in the view.
+#define MTR_START(c, n, id) internal_mtr_raw_event(c, n, 'S', (void *)(id))
+#define MTR_STEP(c, n, id, step) internal_mtr_raw_event_arg(c, n, 'T', (void *)(id), MTR_ARG_TYPE_STRING_CONST, "step", (void *)(step))
+#define MTR_FINISH(c, n, id) internal_mtr_raw_event(c, n, 'F', (void *)(id))
+
+// Flow events. Like async events, but displayed in a more fancy way in the viewer.
+#define MTR_FLOW_START(c, n, id) internal_mtr_raw_event(c, n, 's', (void *)(id))
+#define MTR_FLOW_STEP(c, n, id, step) internal_mtr_raw_event_arg(c, n, 't', (void *)(id), MTR_ARG_TYPE_STRING_CONST, "step", (void *)(step))
+#define MTR_FLOW_FINISH(c, n, id) internal_mtr_raw_event(c, n, 'f', (void *)(id))
+
+// The same macros, but with a single named argument which shows up as metadata in the viewer.
+// _I for int.
+// _C is for a const string arg.
+// _S will copy the string, freeing on flush (expensive but sometimes necessary).
+// but required if the string was generated dynamically.
+
+// Note that it's fine to match BEGIN_S with END and BEGIN with END_S, etc.
+#define MTR_BEGIN_C(c, n, aname, astrval) internal_mtr_raw_event_arg(c, n, 'B', 0, MTR_ARG_TYPE_STRING_CONST, aname, (void *)(astrval))
+#define MTR_END_C(c, n, aname, astrval) internal_mtr_raw_event_arg(c, n, 'E', 0, MTR_ARG_TYPE_STRING_CONST, aname, (void *)(astrval))
+#define MTR_SCOPE_C(c, n, aname, astrval) MTRScopedTraceArg ____mtr_scope(c, n, MTR_ARG_TYPE_STRING_CONST, aname, (void *)(astrval))
+
+#define MTR_BEGIN_S(c, n, aname, astrval) internal_mtr_raw_event_arg(c, n, 'B', 0, MTR_ARG_TYPE_STRING_COPY, aname, (void *)(astrval))
+#define MTR_END_S(c, n, aname, astrval) internal_mtr_raw_event_arg(c, n, 'E', 0, MTR_ARG_TYPE_STRING_COPY, aname, (void *)(astrval))
+#define MTR_SCOPE_S(c, n, aname, astrval) MTRScopedTraceArg ____mtr_scope(c, n, MTR_ARG_TYPE_STRING_COPY, aname, (void *)(astrval))
+
+#define MTR_BEGIN_I(c, n, aname, aintval) internal_mtr_raw_event_arg(c, n, 'B', 0, MTR_ARG_TYPE_INT, aname, (void*)(intptr_t)(aintval))
+#define MTR_END_I(c, n, aname, aintval) internal_mtr_raw_event_arg(c, n, 'E', 0, MTR_ARG_TYPE_INT, aname, (void*)(intptr_t)(aintval))
+#define MTR_SCOPE_I(c, n, aname, aintval) MTRScopedTraceArg ____mtr_scope(c, n, MTR_ARG_TYPE_INT, aname, (void*)(intptr_t)(aintval))
+
+// Instant events. For things with no duration.
+#define MTR_INSTANT(c, n) internal_mtr_raw_event(c, n, 'I', 0)
+#define MTR_INSTANT_C(c, n, aname, astrval) internal_mtr_raw_event_arg(c, n, 'I', 0, MTR_ARG_TYPE_STRING_CONST, aname, (void *)(astrval))
+#define MTR_INSTANT_I(c, n, aname, aintval) internal_mtr_raw_event_arg(c, n, 'I', 0, MTR_ARG_TYPE_INT, aname, (void *)(aintval))
+
+// Counters (can't do multi-value counters yet)
+#define MTR_COUNTER(c, n, val) internal_mtr_raw_event_arg(c, n, 'C', 0, MTR_ARG_TYPE_INT, n, (void *)(intptr_t)(val))
+
+// Metadata. Call at the start preferably. Must be const strings.
+
+#define MTR_META_PROCESS_NAME(n) internal_mtr_raw_event_arg("", "process_name", 'M', 0, MTR_ARG_TYPE_STRING_COPY, "name", (void *)(n))
+#define MTR_META_THREAD_NAME(n) internal_mtr_raw_event_arg("", "thread_name", 'M', 0, MTR_ARG_TYPE_STRING_COPY, "name", (void *)(n))
+#define MTR_META_THREAD_SORT_INDEX(i) internal_mtr_raw_event_arg("", "thread_sort_index", 'M', 0, MTR_ARG_TYPE_INT, "sort_index", (void *)(i))
+
+#else
+
+#define MTR_BEGIN(c, n)
+#define MTR_END(c, n)
+#define MTR_SCOPE(c, n)
+#define MTR_START(c, n, id)
+#define MTR_STEP(c, n, id, step)
+#define MTR_FINISH(c, n, id)
+#define MTR_FLOW_START(c, n, id)
+#define MTR_FLOW_STEP(c, n, id, step)
+#define MTR_FLOW_FINISH(c, n, id)
+#define MTR_INSTANT(c, n)
+
+#define MTR_BEGIN_C(c, n, aname, astrval)
+#define MTR_END_C(c, n, aname, astrval)
+#define MTR_SCOPE_C(c, n, aname, astrval)
+
+#define MTR_BEGIN_S(c, n, aname, astrval)
+#define MTR_END_S(c, n, aname, astrval)
+#define MTR_SCOPE_S(c, n, aname, astrval)
+
+#define MTR_BEGIN_I(c, n, aname, aintval)
+#define MTR_END_I(c, n, aname, aintval)
+#define MTR_SCOPE_I(c, n, aname, aintval)
+
+#define MTR_INSTANT(c, n)
+#define MTR_INSTANT_C(c, n, aname, astrval)
+#define MTR_INSTANT_I(c, n, aname, aintval)
+
+// Counters (can't do multi-value counters yet)
+#define MTR_COUNTER(c, n, val)
+
+// Metadata. Call at the start preferably. Must be const strings.
+
+#define MTR_META_PROCESS_NAME(n)
+
+#define MTR_META_THREAD_NAME(n)
+#define MTR_META_THREAD_SORT_INDEX(i)
+
+#endif
+
+// Shortcuts for simple function timing with automatic categories and names.
+
+#define MTR_BEGIN_FUNC() MTR_BEGIN(__FILE__, __FUNCTION__)
+#define MTR_END_FUNC() MTR_END(__FILE__, __FUNCTION__)
+#define MTR_SCOPE_FUNC() MTR_SCOPE(__FILE__, __FUNCTION__)
+#define MTR_INSTANT_FUNC() MTR_INSTANT(__FILE__, __FUNCTION__)
+#define MTR_SCOPE_FUNC_LIMIT_S(l) MTRScopedTraceLimit ____mtr_scope(__FILE__, __FUNCTION__, l)
+#define MTR_SCOPE_FUNC_LIMIT_MS(l) MTRScopedTraceLimit ____mtr_scope(__FILE__, __FUNCTION__, (double)l * 0.000001)
+
+// Same, but with a single argument of the usual types.
+#define MTR_BEGIN_FUNC_S(aname, arg) MTR_BEGIN_S(__FILE__, __FUNCTION__, aname, arg)
+#define MTR_END_FUNC_S(aname, arg) MTR_END_S(__FILE__, __FUNCTION__, aname, arg)
+#define MTR_SCOPE_FUNC_S(aname, arg) MTR_SCOPE_S(__FILE__, __FUNCTION__, aname, arg)
+
+#define MTR_BEGIN_FUNC_C(aname, arg) MTR_BEGIN_C(__FILE__, __FUNCTION__, aname, arg)
+#define MTR_END_FUNC_C(aname, arg) MTR_END_C(__FILE__, __FUNCTION__, aname, arg)
+#define MTR_SCOPE_FUNC_C(aname, arg) MTR_SCOPE_C(__FILE__, __FUNCTION__, aname, arg)
+
+#define MTR_BEGIN_FUNC_I(aname, arg) MTR_BEGIN_I(__FILE__, __FUNCTION__, aname, arg)
+#define MTR_END_FUNC_I(aname, arg) MTR_END_I(__FILE__, __FUNCTION__, aname, arg)
+#define MTR_SCOPE_FUNC_I(aname, arg) MTR_SCOPE_I(__FILE__, __FUNCTION__, aname, arg)
+
+#ifdef __cplusplus
+}
+
+#ifdef MTR_ENABLED
+// These are optimized to use X events (combined B and E). Much easier to do in C++ than in C.
+class MTRScopedTrace {
+public:
+ MTRScopedTrace(const char *category, const char *name)
+ : category_(category), name_(name) {
+ start_time_ = mtr_time_s();
+ }
+ ~MTRScopedTrace() {
+ internal_mtr_raw_event(category_, name_, 'X', &start_time_);
+ }
+
+private:
+ const char *category_;
+ const char *name_;
+ double start_time_;
+};
+
+// Only outputs a block if execution time exceeded the limit.
+// TODO: This will effectively call mtr_time_s twice at the end, which is bad.
+class MTRScopedTraceLimit {
+public:
+ MTRScopedTraceLimit(const char *category, const char *name, double limit_s)
+ : category_(category), name_(name), limit_(limit_s) {
+ start_time_ = mtr_time_s();
+ }
+ ~MTRScopedTraceLimit() {
+ double end_time = mtr_time_s();
+ if (end_time - start_time_ >= limit_) {
+ internal_mtr_raw_event(category_, name_, 'X', &start_time_);
+ }
+ }
+
+private:
+ const char *category_;
+ const char *name_;
+ double start_time_;
+ double limit_;
+};
+
+class MTRScopedTraceArg {
+public:
+ MTRScopedTraceArg(const char *category, const char *name, mtr_arg_type arg_type, const char *arg_name, void *arg_value)
+ : category_(category), name_(name) {
+ internal_mtr_raw_event_arg(category, name, 'B', 0, arg_type, arg_name, arg_value);
+ }
+ ~MTRScopedTraceArg() {
+ internal_mtr_raw_event(category_, name_, 'E', 0);
+ }
+
+private:
+ const char *category_;
+ const char *name_;
+};
+#endif
+
+#endif
(void)fd;
#endif
}
+
+double time_seconds(void)
+{
+#ifdef HAVE_GETTIMEOFDAY
+ struct timeval tv;
+ gettimeofday(&tv, NULL);
+ return (double)tv.tv_sec + (double)tv.tv_usec / 1000000.0;
+#else
+ return (double)time(NULL);
+#endif
+}