2010-06-23 23:03:09 -05:00
|
|
|
/*
|
2011-07-27 14:33:22 -05:00
|
|
|
* Logging infrastructure that aims to support multi-threading
|
2010-06-23 23:03:09 -05:00
|
|
|
*/
|
|
|
|
|
|
|
|
#include "rust_internal.h"
|
2010-07-19 16:05:18 -05:00
|
|
|
#include "util/array_list.h"
|
|
|
|
#include <stdarg.h>
|
2010-10-11 18:40:18 -05:00
|
|
|
#include <stdlib.h>
|
|
|
|
#include <string.h>
|
2012-01-07 00:13:41 -06:00
|
|
|
#include "rust_util.h"
|
2010-07-19 16:05:18 -05:00
|
|
|
|
|
|
|
/**
|
|
|
|
* Synchronizes access to the underlying logging mechanism.
|
|
|
|
*/
|
2010-09-08 21:13:49 -05:00
|
|
|
static lock_and_signal _log_lock;
|
2012-01-13 15:19:26 -06:00
|
|
|
/**
|
|
|
|
* Indicates whether we are outputing to the console.
|
|
|
|
* Protected by _log_lock;
|
|
|
|
*/
|
|
|
|
static bool _log_to_console = true;
|
|
|
|
|
|
|
|
/*
|
|
|
|
* Request that console logging be turned on.
|
|
|
|
*/
|
|
|
|
void
|
|
|
|
log_console_on() {
|
|
|
|
scoped_lock with(_log_lock);
|
|
|
|
_log_to_console = true;
|
|
|
|
}
|
|
|
|
|
|
|
|
/*
|
|
|
|
* Request that console logging be turned off. Can be
|
|
|
|
* overridden by the environment.
|
|
|
|
*/
|
|
|
|
void
|
|
|
|
log_console_off(rust_env *env) {
|
|
|
|
scoped_lock with(_log_lock);
|
|
|
|
if (env->logspec == NULL) {
|
|
|
|
_log_to_console = false;
|
|
|
|
}
|
|
|
|
}
|
2010-07-19 16:05:18 -05:00
|
|
|
|
2012-04-01 22:18:40 -05:00
|
|
|
rust_log::rust_log(rust_env *env, rust_sched_loop *sched_loop) :
|
|
|
|
_env(env),
|
2012-03-29 18:31:30 -05:00
|
|
|
_sched_loop(sched_loop) {
|
2010-06-23 23:03:09 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
rust_log::~rust_log() {
|
|
|
|
|
|
|
|
}
|
|
|
|
|
2010-07-19 16:05:18 -05:00
|
|
|
const uint16_t
|
|
|
|
hash(uintptr_t ptr) {
|
2011-10-13 14:23:50 -05:00
|
|
|
# if(ULONG_MAX == 0xFFFFFFFF)
|
2010-07-19 16:05:18 -05:00
|
|
|
// Robert Jenkins' 32 bit integer hash function
|
|
|
|
ptr = (ptr + 0x7ed55d16) + (ptr << 12);
|
|
|
|
ptr = (ptr ^ 0xc761c23c) ^ (ptr >> 19);
|
|
|
|
ptr = (ptr + 0x165667b1) + (ptr << 5);
|
|
|
|
ptr = (ptr + 0xd3a2646c) ^ (ptr << 9);
|
|
|
|
ptr = (ptr + 0xfd7046c5) + (ptr << 3);
|
|
|
|
ptr = (ptr ^ 0xb55a4f09) ^ (ptr >> 16);
|
2011-10-13 14:23:50 -05:00
|
|
|
# elif(ULONG_MAX == 0xFFFFFFFFFFFFFFFF)
|
|
|
|
// "hash64shift()" from http://www.concentric.net/~Ttwang/tech/inthash.htm
|
|
|
|
ptr = (~ptr) + (ptr << 21); // ptr = (ptr << 21) - ptr - 1;
|
|
|
|
ptr = ptr ^ (ptr >> 24);
|
|
|
|
ptr = (ptr + (ptr << 3)) + (ptr << 8); // ptr * 265
|
|
|
|
ptr = ptr ^ (ptr >> 14);
|
|
|
|
ptr = (ptr + (ptr << 2)) + (ptr << 4); // ptr * 21
|
|
|
|
ptr = ptr ^ (ptr >> 28);
|
2011-10-25 15:13:55 -05:00
|
|
|
ptr = ptr + (ptr << 31);
|
2011-10-13 14:23:50 -05:00
|
|
|
# else
|
|
|
|
# error "hash() not defined for this pointer size"
|
|
|
|
# endif
|
2010-07-19 16:05:18 -05:00
|
|
|
return (uint16_t) ptr;
|
|
|
|
}
|
|
|
|
|
|
|
|
char *
|
|
|
|
copy_string(char *dst, const char *src, size_t length) {
|
|
|
|
return strncpy(dst, src, length) + length;
|
|
|
|
}
|
|
|
|
|
|
|
|
char *
|
|
|
|
append_string(char *buffer, const char *format, ...) {
|
|
|
|
if (buffer != NULL && format) {
|
|
|
|
va_list args;
|
|
|
|
va_start(args, format);
|
2011-01-14 18:01:43 -06:00
|
|
|
size_t off = strlen(buffer);
|
|
|
|
vsnprintf(buffer + off, BUF_BYTES - off, format, args);
|
2010-07-19 16:05:18 -05:00
|
|
|
va_end(args);
|
2010-06-23 23:03:09 -05:00
|
|
|
}
|
2010-07-19 16:05:18 -05:00
|
|
|
return buffer;
|
|
|
|
}
|
2010-06-23 23:03:09 -05:00
|
|
|
|
2010-07-19 16:05:18 -05:00
|
|
|
void
|
2011-11-07 16:14:36 -06:00
|
|
|
rust_log::trace_ln(char *prefix, char *message) {
|
2011-01-14 15:41:39 -06:00
|
|
|
char buffer[BUF_BYTES] = "";
|
2010-07-19 16:05:18 -05:00
|
|
|
_log_lock.lock();
|
2011-11-07 16:14:36 -06:00
|
|
|
append_string(buffer, "%s", prefix);
|
2010-07-19 16:05:18 -05:00
|
|
|
append_string(buffer, "%s", message);
|
2012-01-13 15:19:26 -06:00
|
|
|
if (_log_to_console) {
|
2012-04-01 22:18:40 -05:00
|
|
|
fprintf(stderr, "rust: %s\n", buffer);
|
|
|
|
fflush(stderr);
|
2012-01-13 15:19:26 -06:00
|
|
|
}
|
2010-07-19 16:05:18 -05:00
|
|
|
_log_lock.unlock();
|
|
|
|
}
|
|
|
|
|
|
|
|
void
|
2011-04-19 05:21:57 -05:00
|
|
|
rust_log::trace_ln(rust_task *task, uint32_t level, char *message) {
|
2011-11-07 16:14:36 -06:00
|
|
|
|
2012-02-23 00:29:38 -06:00
|
|
|
if (task) {
|
|
|
|
// There is not enough room to be logging on the rust stack
|
|
|
|
assert(!task->on_rust_stack() && "logging on rust stack");
|
|
|
|
}
|
2011-11-07 16:14:36 -06:00
|
|
|
|
|
|
|
// FIXME: The scheduler and task names used to have meaning,
|
|
|
|
// but they are always equal to 'main' currently
|
|
|
|
#if 0
|
|
|
|
|
2010-07-19 16:05:18 -05:00
|
|
|
#if defined(__WIN32__)
|
|
|
|
uint32_t thread_id = 0;
|
|
|
|
#else
|
2011-10-13 14:23:50 -05:00
|
|
|
uint32_t thread_id = hash((uintptr_t) pthread_self());
|
2010-07-19 16:05:18 -05:00
|
|
|
#endif
|
2011-11-07 16:14:36 -06:00
|
|
|
|
2011-01-14 15:41:39 -06:00
|
|
|
char prefix[BUF_BYTES] = "";
|
2012-03-29 18:31:30 -05:00
|
|
|
if (_sched_loop && _sched_loop-.name) {
|
2010-08-11 16:04:36 -05:00
|
|
|
append_string(prefix, "%04" PRIxPTR ":%.10s:",
|
2012-03-29 18:31:30 -05:00
|
|
|
thread_id, _sched_loop->name);
|
2010-08-11 16:04:36 -05:00
|
|
|
} else {
|
|
|
|
append_string(prefix, "%04" PRIxPTR ":0x%08" PRIxPTR ":",
|
2012-03-29 18:31:30 -05:00
|
|
|
thread_id, (uintptr_t) _sched_loop);
|
2010-08-11 16:04:36 -05:00
|
|
|
}
|
2010-07-19 16:05:18 -05:00
|
|
|
if (task) {
|
2010-08-11 16:04:36 -05:00
|
|
|
if (task->name) {
|
|
|
|
append_string(prefix, "%.10s:", task->name);
|
|
|
|
} else {
|
|
|
|
append_string(prefix, "0x%08" PRIxPTR ":", (uintptr_t) task);
|
|
|
|
}
|
2010-07-19 16:05:18 -05:00
|
|
|
}
|
2011-11-07 16:14:36 -06:00
|
|
|
#else
|
|
|
|
char prefix[BUF_BYTES] = "";
|
|
|
|
#endif
|
|
|
|
|
|
|
|
trace_ln(prefix, message);
|
2010-06-23 23:03:09 -05:00
|
|
|
}
|
|
|
|
|
2011-04-19 05:21:57 -05:00
|
|
|
// Reading log directives and setting log level vars
|
2011-04-18 09:18:55 -05:00
|
|
|
|
|
|
|
struct mod_entry {
|
|
|
|
const char* name;
|
2012-01-14 13:47:29 -06:00
|
|
|
uint32_t* state;
|
2011-04-18 09:18:55 -05:00
|
|
|
};
|
|
|
|
|
|
|
|
struct cratemap {
|
2011-04-19 05:21:57 -05:00
|
|
|
const mod_entry* entries;
|
|
|
|
const cratemap* children[1];
|
2011-04-18 09:18:55 -05:00
|
|
|
};
|
|
|
|
|
|
|
|
struct log_directive {
|
|
|
|
char* name;
|
|
|
|
size_t level;
|
|
|
|
};
|
|
|
|
|
|
|
|
const size_t max_log_directives = 255;
|
2011-12-22 12:30:04 -06:00
|
|
|
const size_t max_log_level = 255;
|
2011-04-19 05:21:57 -05:00
|
|
|
const size_t default_log_level = 0;
|
2011-04-18 09:18:55 -05:00
|
|
|
|
|
|
|
// This is a rather ugly parser for strings in the form
|
2011-12-22 12:30:04 -06:00
|
|
|
// "crate1,crate2.mod3,crate3.x=1". Log levels are 0-255,
|
|
|
|
// with the most likely ones being 0-3 (defined in core::).
|
2011-04-18 09:18:55 -05:00
|
|
|
size_t parse_logging_spec(char* spec, log_directive* dirs) {
|
|
|
|
size_t dir = 0;
|
|
|
|
while (dir < max_log_directives && *spec) {
|
|
|
|
char* start = spec;
|
|
|
|
char cur;
|
|
|
|
while (true) {
|
|
|
|
cur = *spec;
|
|
|
|
if (cur == ',' || cur == '=' || cur == '\0') {
|
|
|
|
if (start == spec) {spec++; break;}
|
2011-05-13 22:20:01 -05:00
|
|
|
if (*spec != '\0') {
|
|
|
|
*spec = '\0';
|
|
|
|
spec++;
|
|
|
|
}
|
2011-04-19 05:21:57 -05:00
|
|
|
size_t level = max_log_level;
|
2011-05-13 22:20:01 -05:00
|
|
|
if (cur == '=' && *spec != '\0') {
|
2011-04-18 09:18:55 -05:00
|
|
|
level = *spec - '0';
|
2011-04-19 05:21:57 -05:00
|
|
|
if (level > max_log_level) level = max_log_level;
|
2011-04-18 09:18:55 -05:00
|
|
|
if (*spec) ++spec;
|
|
|
|
}
|
|
|
|
dirs[dir].name = start;
|
|
|
|
dirs[dir++].level = level;
|
|
|
|
break;
|
2011-05-13 22:20:01 -05:00
|
|
|
} else {
|
|
|
|
spec++;
|
2011-04-18 09:18:55 -05:00
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
return dir;
|
|
|
|
}
|
|
|
|
|
2011-04-19 05:21:57 -05:00
|
|
|
void update_module_map(const mod_entry* map, log_directive* dirs,
|
2011-06-10 19:31:48 -05:00
|
|
|
size_t n_dirs, size_t *n_matches) {
|
2011-04-19 05:21:57 -05:00
|
|
|
for (const mod_entry* cur = map; cur->name; cur++) {
|
|
|
|
size_t level = default_log_level, longest_match = 0;
|
2011-04-18 09:18:55 -05:00
|
|
|
for (size_t d = 0; d < n_dirs; d++) {
|
|
|
|
if (strstr(cur->name, dirs[d].name) == cur->name &&
|
|
|
|
strlen(dirs[d].name) > longest_match) {
|
|
|
|
longest_match = strlen(dirs[d].name);
|
|
|
|
level = dirs[d].level;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
*cur->state = level;
|
2011-06-10 19:31:48 -05:00
|
|
|
(*n_matches)++;
|
2011-04-18 09:18:55 -05:00
|
|
|
}
|
2011-04-19 05:21:57 -05:00
|
|
|
}
|
2011-04-18 09:18:55 -05:00
|
|
|
|
2011-04-19 05:21:57 -05:00
|
|
|
void update_crate_map(const cratemap* map, log_directive* dirs,
|
2011-06-10 19:31:48 -05:00
|
|
|
size_t n_dirs, size_t *n_matches) {
|
2011-04-19 05:21:57 -05:00
|
|
|
// First update log levels for this crate
|
2011-06-10 19:31:48 -05:00
|
|
|
update_module_map(map->entries, dirs, n_dirs, n_matches);
|
2011-04-18 09:18:55 -05:00
|
|
|
// Then recurse on linked crates
|
2011-04-19 05:21:57 -05:00
|
|
|
// FIXME this does double work in diamond-shaped deps. could keep
|
|
|
|
// a set of visited addresses, if it turns out to be actually slow
|
2011-04-18 09:18:55 -05:00
|
|
|
for (size_t i = 0; map->children[i]; i++) {
|
2011-06-10 19:31:48 -05:00
|
|
|
update_crate_map(map->children[i], dirs, n_dirs, n_matches);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
void print_crate_log_map(const cratemap* map) {
|
|
|
|
for (const mod_entry* cur = map->entries; cur->name; cur++) {
|
|
|
|
printf(" %s\n", cur->name);
|
|
|
|
}
|
|
|
|
for (size_t i = 0; map->children[i]; i++) {
|
|
|
|
print_crate_log_map(map->children[i]);
|
2011-04-18 09:18:55 -05:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2011-04-19 05:21:57 -05:00
|
|
|
// These are pseudo-modules used to control logging in the runtime.
|
|
|
|
|
2012-01-14 13:47:29 -06:00
|
|
|
uint32_t log_rt_mem;
|
|
|
|
uint32_t log_rt_comm;
|
|
|
|
uint32_t log_rt_task;
|
|
|
|
uint32_t log_rt_dom;
|
|
|
|
uint32_t log_rt_trace;
|
|
|
|
uint32_t log_rt_cache;
|
|
|
|
uint32_t log_rt_upcall;
|
|
|
|
uint32_t log_rt_timer;
|
|
|
|
uint32_t log_rt_gc;
|
|
|
|
uint32_t log_rt_stdlib;
|
|
|
|
uint32_t log_rt_kern;
|
|
|
|
uint32_t log_rt_backtrace;
|
|
|
|
uint32_t log_rt_callback;
|
2011-04-19 05:21:57 -05:00
|
|
|
|
|
|
|
static const mod_entry _rt_module_map[] =
|
2011-06-10 19:31:48 -05:00
|
|
|
{{"::rt::mem", &log_rt_mem},
|
|
|
|
{"::rt::comm", &log_rt_comm},
|
|
|
|
{"::rt::task", &log_rt_task},
|
|
|
|
{"::rt::dom", &log_rt_dom},
|
|
|
|
{"::rt::trace", &log_rt_trace},
|
|
|
|
{"::rt::cache", &log_rt_cache},
|
|
|
|
{"::rt::upcall", &log_rt_upcall},
|
|
|
|
{"::rt::timer", &log_rt_timer},
|
|
|
|
{"::rt::gc", &log_rt_gc},
|
|
|
|
{"::rt::stdlib", &log_rt_stdlib},
|
|
|
|
{"::rt::kern", &log_rt_kern},
|
|
|
|
{"::rt::backtrace", &log_rt_backtrace},
|
2011-06-16 00:04:31 -05:00
|
|
|
{"::rt::callback", &log_rt_callback},
|
2011-04-19 05:21:57 -05:00
|
|
|
{NULL, NULL}};
|
|
|
|
|
2011-04-18 09:18:55 -05:00
|
|
|
void update_log_settings(void* crate_map, char* settings) {
|
|
|
|
char* buffer = NULL;
|
|
|
|
log_directive dirs[256];
|
2011-04-19 05:21:57 -05:00
|
|
|
size_t n_dirs = 0;
|
2011-06-10 19:31:48 -05:00
|
|
|
|
2011-04-18 09:18:55 -05:00
|
|
|
if (settings) {
|
2011-06-10 19:31:48 -05:00
|
|
|
|
|
|
|
if (strcmp(settings, "::help") == 0 ||
|
|
|
|
strcmp(settings, "?") == 0) {
|
|
|
|
printf("\nCrate log map:\n\n");
|
|
|
|
print_crate_log_map((const cratemap*)crate_map);
|
|
|
|
printf("\n");
|
|
|
|
exit(1);
|
|
|
|
}
|
|
|
|
|
2011-05-13 21:42:52 -05:00
|
|
|
size_t buflen = strlen(settings) + 1;
|
|
|
|
buffer = (char*)malloc(buflen);
|
|
|
|
strncpy(buffer, settings, buflen);
|
2011-04-19 05:21:57 -05:00
|
|
|
n_dirs = parse_logging_spec(buffer, &dirs[0]);
|
2011-04-18 09:18:55 -05:00
|
|
|
}
|
|
|
|
|
2011-06-10 19:31:48 -05:00
|
|
|
size_t n_matches = 0;
|
|
|
|
update_module_map(_rt_module_map, &dirs[0], n_dirs, &n_matches);
|
|
|
|
update_crate_map((const cratemap*)crate_map, &dirs[0],
|
|
|
|
n_dirs, &n_matches);
|
|
|
|
|
|
|
|
if (n_matches < n_dirs) {
|
2011-06-10 20:32:38 -05:00
|
|
|
printf("warning: got %" PRIdPTR " RUST_LOG specs, "
|
|
|
|
"enabled %" PRIdPTR " flags.",
|
|
|
|
(uintptr_t)n_dirs, (uintptr_t)n_matches);
|
2011-06-10 19:31:48 -05:00
|
|
|
}
|
2011-04-18 09:18:55 -05:00
|
|
|
|
|
|
|
free(buffer);
|
|
|
|
}
|
2011-06-10 19:31:48 -05:00
|
|
|
|
|
|
|
//
|
|
|
|
// Local Variables:
|
|
|
|
// mode: C++
|
|
|
|
// fill-column: 78;
|
|
|
|
// indent-tabs-mode: nil
|
|
|
|
// c-basic-offset: 4
|
|
|
|
// buffer-file-coding-system: utf-8-unix
|
|
|
|
// compile-command: "make -k -C $RBUILD 2>&1 | sed -e 's/\\/x\\//x:\\//g'";
|
|
|
|
// End:
|
|
|
|
//
|