381 lines
11 KiB
C
381 lines
11 KiB
C
/*
|
|
* Logging support
|
|
*/
|
|
|
|
#include <stdio.h>
|
|
#include <string.h>
|
|
#include <stdarg.h>
|
|
#include "duktape.h"
|
|
#include "duk_logging.h"
|
|
|
|
/* XXX: uses stderr always for now, configurable? */
|
|
|
|
#define DUK_LOGGING_FLUSH /* Duktape 1.x: flush stderr */
|
|
|
|
/* 3-letter log level strings. */
|
|
static const char duk__log_level_strings[] = {
|
|
'T', 'R', 'C', 'D', 'B', 'G', 'I', 'N', 'F',
|
|
'W', 'R', 'N', 'E', 'R', 'R', 'F', 'T', 'L'
|
|
};
|
|
|
|
/* Log method names. */
|
|
static const char *duk__log_method_names[] = {
|
|
"trace", "debug", "info", "warn", "error", "fatal"
|
|
};
|
|
|
|
/* Constructor. */
|
|
static duk_ret_t duk__logger_constructor(duk_context *ctx) {
|
|
duk_idx_t nargs;
|
|
|
|
/* Calling as a non-constructor is not meaningful. */
|
|
if (!duk_is_constructor_call(ctx)) {
|
|
return DUK_RET_TYPE_ERROR;
|
|
}
|
|
|
|
nargs = duk_get_top(ctx);
|
|
duk_set_top(ctx, 1);
|
|
|
|
duk_push_this(ctx);
|
|
|
|
/* [ name this ] */
|
|
|
|
if (nargs == 0) {
|
|
/* Automatic defaulting of logger name from caller. This
|
|
* would work poorly with tail calls, but constructor calls
|
|
* are currently never tail calls, so tail calls are not an
|
|
* issue now.
|
|
*/
|
|
|
|
duk_inspect_callstack_entry(ctx, -2);
|
|
if (duk_is_object(ctx, -1)) {
|
|
if (duk_get_prop_string(ctx, -1, "function")) {
|
|
if (duk_get_prop_string(ctx, -1, "fileName")) {
|
|
if (duk_is_string(ctx, -1)) {
|
|
duk_replace(ctx, 0);
|
|
}
|
|
}
|
|
}
|
|
}
|
|
/* Leave values on stack on purpose, ignored below. */
|
|
|
|
/* Stripping the filename might be a good idea
|
|
* ("/foo/bar/quux.js" -> logger name "quux"),
|
|
* but now used verbatim.
|
|
*/
|
|
}
|
|
/* The stack is unbalanced here on purpose; we only rely on the
|
|
* initial two values: [ name this ].
|
|
*/
|
|
|
|
if (duk_is_string(ctx, 0)) {
|
|
duk_dup(ctx, 0);
|
|
duk_put_prop_string(ctx, 1, "n");
|
|
} else {
|
|
/* don't set 'n' at all, inherited value is used as name */
|
|
}
|
|
|
|
duk_compact(ctx, 1);
|
|
|
|
return 0; /* keep default instance */
|
|
}
|
|
|
|
/* Default function to format objects. Tries to use toLogString() but falls
|
|
* back to toString(). Any errors are propagated out without catching.
|
|
*/
|
|
static duk_ret_t duk__logger_prototype_fmt(duk_context *ctx) {
|
|
if (duk_get_prop_string(ctx, 0, "toLogString")) {
|
|
/* [ arg toLogString ] */
|
|
|
|
duk_dup(ctx, 0);
|
|
duk_call_method(ctx, 0);
|
|
|
|
/* [ arg result ] */
|
|
return 1;
|
|
}
|
|
|
|
/* [ arg undefined ] */
|
|
duk_pop(ctx);
|
|
duk_to_string(ctx, 0);
|
|
return 1;
|
|
}
|
|
|
|
/* Default function to write a formatted log line. Writes to stderr,
|
|
* appending a newline to the log line.
|
|
*
|
|
* The argument is a buffer; avoid coercing the buffer to a string to
|
|
* avoid string table traffic.
|
|
*/
|
|
static duk_ret_t duk__logger_prototype_raw(duk_context *ctx) {
|
|
const char *data;
|
|
duk_size_t data_len;
|
|
|
|
data = (const char *) duk_require_buffer(ctx, 0, &data_len);
|
|
fwrite((const void *) data, 1, data_len, stderr);
|
|
fputc((int) '\n', stderr);
|
|
#if defined(DUK_LOGGING_FLUSH)
|
|
fflush(stderr);
|
|
#endif
|
|
return 0;
|
|
}
|
|
|
|
/* Log frontend shared helper, magic value indicates log level. Provides
|
|
* frontend functions: trace(), debug(), info(), warn(), error(), fatal().
|
|
* This needs to have small footprint, reasonable performance, minimal
|
|
* memory churn, etc.
|
|
*/
|
|
static duk_ret_t duk__logger_prototype_log_shared(duk_context *ctx) {
|
|
duk_double_t now;
|
|
duk_time_components comp;
|
|
duk_small_int_t entry_lev;
|
|
duk_small_int_t logger_lev;
|
|
duk_int_t nargs;
|
|
duk_int_t i;
|
|
duk_size_t tot_len;
|
|
const duk_uint8_t *arg_str;
|
|
duk_size_t arg_len;
|
|
duk_uint8_t *buf, *p;
|
|
const duk_uint8_t *q;
|
|
duk_uint8_t date_buf[32]; /* maximum format length is 24+1 (NUL), round up. */
|
|
duk_size_t date_len;
|
|
duk_small_int_t rc;
|
|
|
|
/* XXX: sanitize to printable (and maybe ASCII) */
|
|
/* XXX: better multiline */
|
|
|
|
/*
|
|
* Logger arguments are:
|
|
*
|
|
* magic: log level (0-5)
|
|
* this: logger
|
|
* stack: plain log args
|
|
*
|
|
* We want to minimize memory churn so a two-pass approach
|
|
* is used: first pass formats arguments and computes final
|
|
* string length, second pass copies strings into a buffer
|
|
* allocated directly with the correct size. If the backend
|
|
* function plays nice, it won't coerce the buffer to a string
|
|
* (and thus intern it).
|
|
*/
|
|
|
|
entry_lev = duk_get_current_magic(ctx);
|
|
if (entry_lev < DUK_LOG_TRACE || entry_lev > DUK_LOG_FATAL) {
|
|
/* Should never happen, check just in case. */
|
|
return 0;
|
|
}
|
|
nargs = duk_get_top(ctx);
|
|
|
|
/* [ arg1 ... argN this ] */
|
|
|
|
/*
|
|
* Log level check
|
|
*/
|
|
|
|
duk_push_this(ctx);
|
|
|
|
duk_get_prop_string(ctx, -1, "l");
|
|
logger_lev = (duk_small_int_t) duk_get_int(ctx, -1);
|
|
if (entry_lev < logger_lev) {
|
|
return 0;
|
|
}
|
|
/* log level could be popped but that's not necessary */
|
|
|
|
now = duk_get_now(ctx);
|
|
duk_time_to_components(ctx, now, &comp);
|
|
sprintf((char *) date_buf, "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ",
|
|
(int) comp.year, (int) comp.month + 1, (int) comp.day,
|
|
(int) comp.hours, (int) comp.minutes, (int) comp.seconds,
|
|
(int) comp.milliseconds);
|
|
|
|
date_len = strlen((const char *) date_buf);
|
|
|
|
duk_get_prop_string(ctx, -2, "n");
|
|
duk_to_string(ctx, -1);
|
|
|
|
/* [ arg1 ... argN this loggerLevel loggerName ] */
|
|
|
|
/*
|
|
* Pass 1
|
|
*/
|
|
|
|
/* Line format: <time> <entryLev> <loggerName>: <msg> */
|
|
|
|
tot_len = 0;
|
|
tot_len += 3 + /* separators: space, space, colon */
|
|
3 + /* level string */
|
|
date_len + /* time */
|
|
duk_get_length(ctx, -1); /* loggerName */
|
|
|
|
for (i = 0; i < nargs; i++) {
|
|
/* When formatting an argument to a string, errors may happen from multiple
|
|
* causes. In general we want to catch obvious errors like a toLogString()
|
|
* throwing an error, but we don't currently try to catch every possible
|
|
* error. In particular, internal errors (like out of memory or stack) are
|
|
* not caught. Also, we expect Error toString() to not throw an error.
|
|
*/
|
|
if (duk_is_object(ctx, i)) {
|
|
/* duk_pcall_prop() may itself throw an error, but we're content
|
|
* in catching the obvious errors (like toLogString() throwing an
|
|
* error).
|
|
*/
|
|
duk_push_string(ctx, "fmt");
|
|
duk_dup(ctx, i);
|
|
/* [ arg1 ... argN this loggerLevel loggerName 'fmt' arg ] */
|
|
/* call: this.fmt(arg) */
|
|
rc = duk_pcall_prop(ctx, -5 /*obj_index*/, 1 /*nargs*/);
|
|
if (rc) {
|
|
/* Keep the error as the result (coercing it might fail below,
|
|
* but we don't catch that now).
|
|
*/
|
|
;
|
|
}
|
|
duk_replace(ctx, i);
|
|
}
|
|
(void) duk_to_lstring(ctx, i, &arg_len);
|
|
tot_len++; /* sep (even before first one) */
|
|
tot_len += arg_len;
|
|
}
|
|
|
|
/*
|
|
* Pass 2
|
|
*/
|
|
|
|
/* XXX: Here it'd be nice if we didn't need to allocate a new fixed
|
|
* buffer for every write. This would be possible if raw() took a
|
|
* buffer and a length. We could then use a preallocated buffer for
|
|
* most log writes and request raw() to write a partial buffer.
|
|
*/
|
|
|
|
buf = (duk_uint8_t *) duk_push_fixed_buffer(ctx, tot_len);
|
|
p = buf;
|
|
|
|
memcpy((void *) p, (const void *) date_buf, (size_t) date_len);
|
|
p += date_len;
|
|
*p++ = (duk_uint8_t) ' ';
|
|
|
|
q = (const duk_uint8_t *) duk__log_level_strings + (entry_lev * 3);
|
|
memcpy((void *) p, (const void *) q, (size_t) 3);
|
|
p += 3;
|
|
|
|
*p++ = (duk_uint8_t) ' ';
|
|
|
|
arg_str = (const duk_uint8_t *) duk_get_lstring(ctx, -2, &arg_len);
|
|
memcpy((void *) p, (const void *) arg_str, (size_t) arg_len);
|
|
p += arg_len;
|
|
|
|
*p++ = (duk_uint8_t) ':';
|
|
|
|
for (i = 0; i < nargs; i++) {
|
|
*p++ = (duk_uint8_t) ' ';
|
|
|
|
arg_str = (const duk_uint8_t *) duk_get_lstring(ctx, i, &arg_len);
|
|
memcpy((void *) p, (const void *) arg_str, (size_t) arg_len);
|
|
p += arg_len;
|
|
}
|
|
|
|
/* [ arg1 ... argN this loggerLevel loggerName buffer ] */
|
|
|
|
/* Call this.raw(msg); look up through the instance allows user to override
|
|
* the raw() function in the instance or in the prototype for maximum
|
|
* flexibility.
|
|
*/
|
|
duk_push_string(ctx, "raw");
|
|
duk_dup(ctx, -2);
|
|
/* [ arg1 ... argN this loggerLevel loggerName buffer 'raw' buffer ] */
|
|
duk_call_prop(ctx, -6, 1); /* this.raw(buffer) */
|
|
|
|
return 0;
|
|
}
|
|
|
|
void duk_log_va(duk_context *ctx, duk_int_t level, const char *fmt, va_list ap) {
|
|
if (level < 0) {
|
|
level = 0;
|
|
} else if (level > (int) (sizeof(duk__log_method_names) / sizeof(const char *)) - 1) {
|
|
level = (int) (sizeof(duk__log_method_names) / sizeof(const char *)) - 1;
|
|
}
|
|
|
|
duk_push_global_stash(ctx);
|
|
duk_get_prop_string(ctx, -1, "\xff" "logger:constructor"); /* fixed at init time */
|
|
duk_get_prop_string(ctx, -1, "clog");
|
|
duk_get_prop_string(ctx, -1, duk__log_method_names[level]);
|
|
duk_dup(ctx, -2);
|
|
duk_push_vsprintf(ctx, fmt, ap);
|
|
|
|
/* [ ... stash Logger clog logfunc clog(=this) msg ] */
|
|
|
|
duk_call_method(ctx, 1 /*nargs*/);
|
|
|
|
/* [ ... stash Logger clog res ] */
|
|
|
|
duk_pop_n(ctx, 4);
|
|
}
|
|
|
|
void duk_log(duk_context *ctx, duk_int_t level, const char *fmt, ...) {
|
|
va_list ap;
|
|
|
|
va_start(ap, fmt);
|
|
duk_log_va(ctx, level, fmt, ap);
|
|
va_end(ap);
|
|
}
|
|
|
|
void duk_logging_init(duk_context *ctx, duk_uint_t flags) {
|
|
/* XXX: Add .name property for logger functions (useful for stack traces if they throw). */
|
|
|
|
(void) flags;
|
|
|
|
duk_eval_string(ctx,
|
|
"(function(cons,prot){"
|
|
"Object.defineProperty(Duktape,'Logger',{value:cons,writable:true,configurable:true});"
|
|
"Object.defineProperty(cons,'prototype',{value:prot});"
|
|
"Object.defineProperty(cons,'clog',{value:new Duktape.Logger('C'),writable:true,configurable:true});"
|
|
"});");
|
|
|
|
duk_push_c_function(ctx, duk__logger_constructor, DUK_VARARGS /*nargs*/); /* Duktape.Logger */
|
|
duk_push_object(ctx); /* Duktape.Logger.prototype */
|
|
|
|
/* [ ... func Duktape.Logger Duktape.Logger.prototype ] */
|
|
|
|
duk_push_string(ctx, "name");
|
|
duk_push_string(ctx, "Logger");
|
|
duk_def_prop(ctx, -4, DUK_DEFPROP_HAVE_VALUE | DUK_DEFPROP_FORCE);
|
|
|
|
duk_dup_top(ctx);
|
|
duk_put_prop_string(ctx, -2, "constructor");
|
|
duk_push_int(ctx, 2);
|
|
duk_put_prop_string(ctx, -2, "l");
|
|
duk_push_string(ctx, "anon");
|
|
duk_put_prop_string(ctx, -2, "n");
|
|
duk_push_c_function(ctx, duk__logger_prototype_fmt, 1 /*nargs*/);
|
|
duk_put_prop_string(ctx, -2, "fmt");
|
|
duk_push_c_function(ctx, duk__logger_prototype_raw, 1 /*nargs*/);
|
|
duk_put_prop_string(ctx, -2, "raw");
|
|
duk_push_c_function(ctx, duk__logger_prototype_log_shared, DUK_VARARGS /*nargs*/);
|
|
duk_set_magic(ctx, -1, 0); /* magic=0: trace */
|
|
duk_put_prop_string(ctx, -2, "trace");
|
|
duk_push_c_function(ctx, duk__logger_prototype_log_shared, DUK_VARARGS /*nargs*/);
|
|
duk_set_magic(ctx, -1, 1); /* magic=1: debug */
|
|
duk_put_prop_string(ctx, -2, "debug");
|
|
duk_push_c_function(ctx, duk__logger_prototype_log_shared, DUK_VARARGS /*nargs*/);
|
|
duk_set_magic(ctx, -1, 2); /* magic=2: info */
|
|
duk_put_prop_string(ctx, -2, "info");
|
|
duk_push_c_function(ctx, duk__logger_prototype_log_shared, DUK_VARARGS /*nargs*/);
|
|
duk_set_magic(ctx, -1, 3); /* magic=3: warn */
|
|
duk_put_prop_string(ctx, -2, "warn");
|
|
duk_push_c_function(ctx, duk__logger_prototype_log_shared, DUK_VARARGS /*nargs*/);
|
|
duk_set_magic(ctx, -1, 4); /* magic=4: error */
|
|
duk_put_prop_string(ctx, -2, "error");
|
|
duk_push_c_function(ctx, duk__logger_prototype_log_shared, DUK_VARARGS /*nargs*/);
|
|
duk_set_magic(ctx, -1, 5); /* magic=5: fatal */
|
|
duk_put_prop_string(ctx, -2, "fatal");
|
|
|
|
/* [ ... func Duktape.Logger Duktape.Logger.prototype ] */
|
|
|
|
/* XXX: when using ROM built-ins, "Duktape" is read-only by default so
|
|
* setting Duktape.Logger will now fail.
|
|
*/
|
|
|
|
/* [ ... func Duktape.Logger Duktape.Logger.prototype ] */
|
|
|
|
duk_call(ctx, 2);
|
|
duk_pop(ctx);
|
|
}
|