/*
* 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);
}
