duktape-1.5.2/src-separate/duk_bi_logger.c

Go to the documentation of this file.

/*
 *  Logging support
 */
 
#include "duk_internal.h"
 
/* 3-letter log level strings */
DUK_LOCAL const duk_uint8_t duk__log_level_strings[] = {
    (duk_uint8_t) DUK_ASC_UC_T, (duk_uint8_t) DUK_ASC_UC_R, (duk_uint8_t) DUK_ASC_UC_C,
    (duk_uint8_t) DUK_ASC_UC_D, (duk_uint8_t) DUK_ASC_UC_B, (duk_uint8_t) DUK_ASC_UC_G,
    (duk_uint8_t) DUK_ASC_UC_I, (duk_uint8_t) DUK_ASC_UC_N, (duk_uint8_t) DUK_ASC_UC_F,
    (duk_uint8_t) DUK_ASC_UC_W, (duk_uint8_t) DUK_ASC_UC_R, (duk_uint8_t) DUK_ASC_UC_N,
    (duk_uint8_t) DUK_ASC_UC_E, (duk_uint8_t) DUK_ASC_UC_R, (duk_uint8_t) DUK_ASC_UC_R,
    (duk_uint8_t) DUK_ASC_UC_F, (duk_uint8_t) DUK_ASC_UC_T, (duk_uint8_t) DUK_ASC_UC_L
};
 
/* Constructor */
DUK_INTERNAL duk_ret_t duk_bi_logger_constructor(duk_context *ctx) {
    duk_hthread *thr = (duk_hthread *) 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.
         */
 
        if (thr->callstack_top >= 2) {
            duk_activation *act_caller = thr->callstack + thr->callstack_top - 2;
            duk_hobject *func_caller;
 
            func_caller = DUK_ACT_GET_FUNC(act_caller);
            if (func_caller) {
                /* Stripping the filename might be a good idea
                 * ("/foo/bar/quux.js" -> logger name "quux"),
                 * but now used verbatim.
                 */
                duk_push_hobject(ctx, func_caller);
                duk_get_prop_stridx(ctx, -1, DUK_STRIDX_FILE_NAME);
                duk_replace(ctx, 0);
            }
        }
    }
    /* 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_stridx(ctx, 1, DUK_STRIDX_LC_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.
 */
DUK_INTERNAL duk_ret_t duk_bi_logger_prototype_fmt(duk_context *ctx) {
    if (duk_get_prop_stridx(ctx, 0, DUK_STRIDX_TO_LOG_STRING)) {
        /* [ 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 whose visible size contains the log message.
 * This function should avoid coercing the buffer to a string to avoid
 * string table traffic.
 */
DUK_INTERNAL duk_ret_t duk_bi_logger_prototype_raw(duk_context *ctx) {
    const char *data;
    duk_size_t data_len;
 
    DUK_UNREF(ctx);
    DUK_UNREF(data);
    DUK_UNREF(data_len);
 
#ifdef DUK_USE_FILE_IO
    data = (const char *) duk_require_buffer(ctx, 0, &data_len);
    DUK_FWRITE((const void *) data, 1, data_len, DUK_STDERR);
    DUK_FPUTC((int) '\n', DUK_STDERR);
    DUK_FFLUSH(DUK_STDERR);
#else
    /* nop */
#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.
 */
DUK_INTERNAL duk_ret_t duk_bi_logger_prototype_log_shared(duk_context *ctx) {
    duk_hthread *thr = (duk_hthread *) ctx;
    duk_double_t now;
    duk_small_int_t entry_lev = duk_get_current_magic(ctx);
    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[DUK_BI_DATE_ISO8601_BUFSIZE];
    duk_size_t date_len;
    duk_small_int_t rc;
 
    DUK_ASSERT(entry_lev >= 0 && entry_lev <= 5);
    DUK_UNREF(thr);
 
    /* 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 either into a
     *  pre-allocated and reused buffer (short messages) or into a
     *  newly allocated fixed buffer.  If the backend function plays
     *  nice, it won't coerce the buffer to a string (and thus
     *  intern it).
     */
 
    nargs = duk_get_top(ctx);
 
    /* [ arg1 ... argN this ] */
 
    /*
     *  Log level check
     */
 
    duk_push_this(ctx);
 
    duk_get_prop_stridx(ctx, -1, DUK_STRIDX_LC_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_USE_DATE_GET_NOW(ctx);
    duk_bi_date_format_timeval(now, date_buf);
    date_len = DUK_STRLEN((const char *) date_buf);
 
    duk_get_prop_stridx(ctx, -2, DUK_STRIDX_LC_N);
    duk_to_string(ctx, -1);
    DUK_ASSERT(duk_is_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_hstring_stridx(ctx, DUK_STRIDX_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: There used to be a shared log buffer here, but it was removed
     * when dynamic buffer spare was removed.  The problem with using
     * bufwriter is that, without the spare, the buffer gets passed on
     * as an argument to the raw() call so it'd need to be resized
     * (reallocated) anyway.  If raw() call convention is changed, this
     * could be made more efficient.
     */
 
    buf = (duk_uint8_t *) duk_push_fixed_buffer(ctx, tot_len);
    DUK_ASSERT(buf != NULL);
    p = buf;
 
    DUK_MEMCPY((void *) p, (const void *) date_buf, (size_t) date_len);
    p += date_len;
    *p++ = (duk_uint8_t) DUK_ASC_SPACE;
 
    q = duk__log_level_strings + (entry_lev * 3);
    DUK_MEMCPY((void *) p, (const void *) q, (size_t) 3);
    p += 3;
 
    *p++ = (duk_uint8_t) DUK_ASC_SPACE;
 
    arg_str = (const duk_uint8_t *) duk_get_lstring(ctx, -2, &arg_len);
    DUK_MEMCPY((void *) p, (const void *) arg_str, (size_t) arg_len);
    p += arg_len;
 
    *p++ = (duk_uint8_t) DUK_ASC_COLON;
 
    for (i = 0; i < nargs; i++) {
        *p++ = (duk_uint8_t) DUK_ASC_SPACE;
 
        arg_str = (const duk_uint8_t *) duk_get_lstring(ctx, i, &arg_len);
        DUK_ASSERT(arg_str != NULL);
        DUK_MEMCPY((void *) p, (const void *) arg_str, (size_t) arg_len);
        p += arg_len;
    }
    DUK_ASSERT(buf + tot_len == p);
 
    /* [ arg1 ... argN this loggerLevel loggerName buffer ] */
 
#if defined(DUK_USE_DEBUGGER_SUPPORT) && defined(DUK_USE_DEBUGGER_FWD_LOGGING)
    /* Do debugger forwarding before raw() because the raw() function
     * doesn't get the log level right now.
     */
    if (DUK_HEAP_IS_DEBUGGER_ATTACHED(thr->heap)) {
        const char *log_buf;
        duk_size_t sz_buf;
        log_buf = (const char *) duk_get_buffer(ctx, -1, &sz_buf);
        DUK_ASSERT(log_buf != NULL);
        duk_debug_write_notify(thr, DUK_DBG_CMD_LOG);
        duk_debug_write_int(thr, (duk_int32_t) entry_lev);
        duk_debug_write_string(thr, (const char *) log_buf, sz_buf);
        duk_debug_write_eom(thr);
    }
#endif
 
    /* 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_hstring_stridx(ctx, DUK_STRIDX_RAW);
    duk_dup(ctx, -2);
    /* [ arg1 ... argN this loggerLevel loggerName buffer 'raw' buffer ] */
    duk_call_prop(ctx, -6, 1);  /* this.raw(buffer) */
 
    return 0;
}