john/cell
1
0
Fork 0
Code Issues 31 Pull Requests Actions Packages Projects Releases 2 Wiki Activity

Merge branch 'improved_log'

Browse Source
This commit is contained in:
John Alanbrook
2026-02-18 12:05:10 -06:00
parent 28f5a108d8 037fdbfd2c
commit 36f054d99d
6 changed files with 171 additions and 114 deletions
Download Patch File Download Diff File Expand all files Collapse all files

36
docs/logging.md
View File

@@ -87,7 +87,7 @@ exclude = ["console"]
**json** — structured JSONL (one JSON object per line). Used for file sinks and machine consumption.
```json
{"actor_id":"a3f12...","timestamp":1702656000.5,"channel":"console","event":"server started","source":{"file":"main.ce","line":5,"column":3,"function":"init"}}
{"actor_id":"a3f12...","timestamp":1702656000.5,"channel":"console","event":"server started","source":{"file":"main.ce","line":5,"col":3,"fn":"init"}}
```
## Log Records
@@ -103,14 +103,44 @@ Every log call produces a record:
source: {
file: "main.ce",
line: 5,
column: 3,
function: "init"
col: 3,
fn: "init"
}
}
```
File sinks write one JSON-encoded record per line. Console sinks format the record according to their format setting.
## Stack Traces
Set `stack = true` at the top level of `.cell/log.toml` to capture a full call stack with every log record.
```toml
stack = true
[sink.terminal]
type = "console"
format = "pretty"
channels = ["console", "error"]
```
With pretty format, the stack is printed indented below each message:
```
[a3f12] [error] server.ce:42 connection failed
at handle_request (server.ce:42:3)
at process (router.ce:18:5)
at main (main.ce:5:1)
```
With JSON format, a `stack` array is added to the record:
```json
{"actor_id":"a3f12...","channel":"error","event":"connection failed","source":{"file":"server.ce","line":42,"col":3,"fn":"handle_request"},"stack":[{"fn":"handle_request","file":"server.ce","line":42,"col":3},{"fn":"process","file":"router.ce","line":18,"col":5},{"fn":"main","file":"main.ce","line":5,"col":1}]}
```
When `stack` is not set or `false`, no stack is captured and the `stack` field is omitted from records. Capturing stacks adds overhead — enable it for debugging, not production.
## CLI
The `pit log` command manages sinks and reads log files. See [CLI — pit log](/docs/cli/#pit-log) for the full reference.

26
internal/engine.cm
View File

@@ -324,6 +324,7 @@ var log_config = null
var channel_sinks = {}
var wildcard_sinks = []
var warned_channels = {}
var log_stack_enabled = false
function log(name, args) {
var msg = args[0]
@@ -476,15 +477,27 @@ function load_log_config() {
}
}
build_sink_routing()
log_stack_enabled = log_config.stack == true
}
function pretty_format(rec) {
var aid = text(rec.actor_id, 0, 5)
var src = ""
var ev = null
var out = null
var i = 0
var fr = null
if (rec.source && rec.source.file)
src = rec.source.file + ":" + text(rec.source.line)
var ev = is_text(rec.event) ? rec.event : json.encode(rec.event, false)
return `[${aid}] [${rec.channel}] ${src} ${ev}\n`
ev = is_text(rec.event) ? rec.event : json.encode(rec.event, false)
out = `[${aid}] [${rec.channel}] ${src} ${ev}\n`
if (rec.stack && length(rec.stack) > 0) {
for (i = 0; i < length(rec.stack); i = i + 1) {
fr = rec.stack[i]
out = out + ` at ${fr.fn} (${fr.file}:${text(fr.line)}:${text(fr.col)})\n`
}
}
return out
}
function bare_format(rec) {
@@ -523,6 +536,9 @@ load_log_config()
log = function(name, args) {
var sinks = channel_sinks[name]
var event = args[0]
var caller = null
var stack = null
var rec = null
if (!sinks && length(wildcard_sinks) == 0) {
if (!warned_channels[name]) {
@@ -532,14 +548,16 @@ log = function(name, args) {
return
}
var caller = caller_info(2)
var rec = {
caller = caller_info(2)
if (log_stack_enabled) stack = os.stack(1)
rec = {
actor_id: _cell.id,
timestamp: time.number(),
channel: name,
event: event,
source: caller
}
if (stack) rec.stack = stack
if (sinks) arrfor(sinks, function(sink) { dispatch_to_sink(sink, rec) })
arrfor(wildcard_sinks, function(sink) { dispatch_to_sink(sink, rec) })

22
internal/os.c
View File

@@ -674,6 +674,27 @@ static JSValue js_os_embedded_module(JSContext *js, JSValue self, int argc, JSVa
return js_new_blob_stoned_copy(js, (void *)entry->data, entry->size);
}
static JSValue js_os_stack(JSContext *js, JSValue self, int argc, JSValue *argv) {
(void)self;
int skip = 0;
if (argc > 0) JS_ToInt32(js, &skip, argv[0]);
JSValue full = JS_GetStack(js);
if (skip <= 0) return full;
int64_t n = 0;
JS_GetLength(js, full, &n);
if (skip >= (int)n) return JS_NewArray(js);
JS_FRAME(js);
JS_ROOT(arr, JS_NewArray(js));
for (int i = skip; i < (int)n; i++) {
JSValue item = JS_GetPropertyNumber(js, full, i);
JS_SetPropertyNumber(js, arr.val, i - skip, item);
}
JS_RETURN(arr.val);
}
static const JSCFunctionListEntry js_os_funcs[] = {
MIST_FUNC_DEF(os, platform, 0),
MIST_FUNC_DEF(os, arch, 0),
@@ -701,6 +722,7 @@ static const JSCFunctionListEntry js_os_funcs[] = {
MIST_FUNC_DEF(os, random, 0),
MIST_FUNC_DEF(os, getenv, 1),
MIST_FUNC_DEF(os, qbe, 1),
MIST_FUNC_DEF(os, stack, 1),
};
JSValue js_core_os_use(JSContext *js) {

4
source/quickjs-internal.h
View File

@@ -1427,7 +1427,7 @@ static JSValue js_cell_number_remainder (JSContext *ctx, JSValue this_val, int a
static JSValue js_cell_object (JSContext *ctx, JSValue this_val, int argc, JSValue *argv);
static JSValue js_cell_text_format (JSContext *ctx, JSValue this_val, int argc, JSValue *argv);
static JSValue js_print (JSContext *ctx, JSValue this_val, int argc, JSValue *argv);
cJSON *JS_GetStack(JSContext *ctx);
JSValue JS_GetStack(JSContext *ctx);
JSValue JS_ThrowOutOfMemory (JSContext *ctx);
@@ -1595,7 +1595,7 @@ uint64_t get_text_hash (JSText *text);
void pack_utf32_to_words (const uint32_t *utf32, uint32_t len, uint64_t *packed);
int text_equal (JSText *a, const uint64_t *packed_b, uint32_t len_b);
void print_backtrace (JSContext *ctx, const char *filename, int line_num, int col_num);
void print_backtrace (JSContext *ctx, JSValue stack, const char *filename, int line_num, int col_num);
JSValue JS_ThrowError2 (JSContext *ctx, JSErrorEnum error_num, const char *fmt, va_list ap, BOOL add_backtrace);
JSValue gc_copy_value (JSContext *ctx, JSValue v, uint8_t *from_base, uint8_t *from_end, uint8_t *to_base, uint8_t **to_free, uint8_t *to_end);
PPretext *ppretext_init (int capacity);

8
source/quickjs.h
View File

@@ -1047,10 +1047,10 @@ void JS_DumpMachBin(JSContext *ctx, const uint8_t *data, size_t size, JSValue en
/* Compile mcode JSON IR to MachCode binary. */
MachCode *mach_compile_mcode(struct cJSON *mcode_json);
/* Get stack trace as cJSON array of frame objects.
Returns NULL if no register VM frame is active.
Caller must call cJSON_Delete() on the result. */
struct cJSON *JS_GetStack (JSContext *ctx);
/* Get stack trace as JS array of {fn, file, line, col} objects.
Returns an empty array if no register VM frame is active.
Does NOT clear reg_current_frame — caller is responsible if needed. */
JSValue JS_GetStack (JSContext *ctx);
#undef js_unlikely
#undef inline

189
source/runtime.c
View File

@@ -3088,32 +3088,31 @@ static const char *const native_error_name[JS_NATIVE_ERROR_COUNT] = {
"AggregateError",
};
/* Print backtrace to stderr. Walks the register VM frame chain via
ctx->reg_current_frame, then falls back to the C stack frame chain. */
void print_backtrace (JSContext *ctx, const char *filename, int line_num, int col_num) {
/* Print backtrace to stderr from a JS array of {fn, file, line, col} objects. */
void print_backtrace (JSContext *ctx, JSValue stack, const char *filename, int line_num, int col_num) {
if (filename) {
fprintf (stderr, " at %s", filename);
if (line_num != -1) fprintf (stderr, ":%d:%d", line_num, col_num);
fputc ('\n', stderr);
}
/* Walk register VM frame chain (mach / mcode) */
if (!JS_IsNull (ctx->reg_current_frame)) {
cJSON *stack = JS_GetStack (ctx);
if (stack) {
int n = cJSON_GetArraySize (stack);
for (int i = 0; i < n; i++) {
cJSON *fr = cJSON_GetArrayItem (stack, i);
const char *fn = cJSON_GetStringValue (cJSON_GetObjectItem (fr, "function"));
const char *file = cJSON_GetStringValue (cJSON_GetObjectItem (fr, "file"));
int ln = (int)cJSON_GetNumberValue (cJSON_GetObjectItem (fr, "line"));
int cn = (int)cJSON_GetNumberValue (cJSON_GetObjectItem (fr, "column"));
fprintf (stderr, " at %s (%s:%d:%d)\n",
fn ? fn : "<anonymous>", file ? file : "<unknown>", ln, cn);
}
cJSON_Delete (stack);
}
return;
int64_t n = 0;
JS_GetLength(ctx, stack, &n);
for (int i = 0; i < (int)n; i++) {
JSValue fr = JS_GetPropertyNumber(ctx, stack, i);
JSValue fn_val = JS_GetPropertyStr(ctx, fr, "fn");
JSValue file_val = JS_GetPropertyStr(ctx, fr, "file");
const char *fn = JS_ToCString(ctx, fn_val);
const char *file = JS_ToCString(ctx, file_val);
int32_t ln = 0, cn = 0;
JSValue line_v = JS_GetPropertyStr(ctx, fr, "line");
JSValue col_v = JS_GetPropertyStr(ctx, fr, "col");
JS_ToInt32(ctx, &ln, line_v);
JS_ToInt32(ctx, &cn, col_v);
fprintf (stderr, " at %s (%s:%d:%d)\n",
fn ? fn : "<anonymous>", file ? file : "<unknown>", ln, cn);
if (fn) JS_FreeCString(ctx, fn);
if (file) JS_FreeCString(ctx, file);
}
}
@@ -3124,7 +3123,9 @@ JSValue JS_ThrowError2 (JSContext *ctx, JSErrorEnum error_num, const char *fmt,
vsnprintf (buf, sizeof (buf), fmt, ap);
fprintf (stderr, "%s: %s\n", native_error_name[error_num], buf);
if (add_backtrace) {
print_backtrace (ctx, NULL, 0, 0);
JSValue stack = JS_GetStack(ctx);
ctx->reg_current_frame = JS_NULL;
print_backtrace (ctx, stack, NULL, 0, 0);
}
return JS_Throw (ctx, JS_TRUE);
}
@@ -8127,70 +8128,44 @@ static JSValue js_print (JSContext *ctx, JSValue this_val, int argc, JSValue *ar
}
static JSValue js_stacktrace (JSContext *ctx, JSValue this_val, int argc, JSValue *argv) {
cJSON *stack = JS_GetStack(ctx);
if (stack) {
int n = cJSON_GetArraySize(stack);
for (int i = 0; i < n; i++) {
cJSON *fr = cJSON_GetArrayItem(stack, i);
const char *fn = cJSON_GetStringValue(cJSON_GetObjectItemCaseSensitive(fr, "function"));
const char *file = cJSON_GetStringValue(cJSON_GetObjectItemCaseSensitive(fr, "file"));
int line = (int)cJSON_GetNumberValue(cJSON_GetObjectItemCaseSensitive(fr, "line"));
int col = (int)cJSON_GetNumberValue(cJSON_GetObjectItemCaseSensitive(fr, "column"));
printf(" at %s (%s:%d:%d)\n", fn ? fn : "<anonymous>", file ? file : "<unknown>", line, col);
}
cJSON_Delete(stack);
(void)this_val; (void)argc; (void)argv;
JSValue stack = JS_GetStack(ctx);
int64_t n = 0;
JS_GetLength(ctx, stack, &n);
for (int i = 0; i < (int)n; i++) {
JSValue fr = JS_GetPropertyNumber(ctx, stack, i);
JSValue fn_val = JS_GetPropertyStr(ctx, fr, "fn");
JSValue file_val = JS_GetPropertyStr(ctx, fr, "file");
const char *fn = JS_ToCString(ctx, fn_val);
const char *file = JS_ToCString(ctx, file_val);
int32_t line = 0, col = 0;
JS_ToInt32(ctx, &line, JS_GetPropertyStr(ctx, fr, "line"));
JS_ToInt32(ctx, &col, JS_GetPropertyStr(ctx, fr, "col"));
printf(" at %s (%s:%d:%d)\n", fn ? fn : "<anonymous>", file ? file : "<unknown>", line, col);
if (fn) JS_FreeCString(ctx, fn);
if (file) JS_FreeCString(ctx, file);
}
return JS_NULL;
}
static JSValue js_caller_info (JSContext *ctx, JSValue this_val, int argc, JSValue *argv) {
(void)this_val;
int depth = 0;
if (argc > 0) JS_ToInt32(ctx, &depth, argv[0]);
/* Save frame pointer — JS_GetStack clears it */
JSValue saved_frame = ctx->reg_current_frame;
uint32_t saved_pc = ctx->current_register_pc;
JSValue stack = JS_GetStack(ctx);
cJSON *stack = JS_GetStack(ctx);
int64_t n = 0;
JS_GetLength(ctx, stack, &n);
/* Restore so other callers still see the frame */
ctx->reg_current_frame = saved_frame;
ctx->current_register_pc = saved_pc;
/* depth 0 = immediate caller of caller_info, which is frame index 1
(frame 0 is caller_info itself) */
int idx = depth + 1;
if (idx >= (int)n) idx = (int)n - 1;
if (idx < 0) idx = 0;
const char *fn_str = "<anonymous>";
const char *file_str = "<unknown>";
int line = 0, col = 0;
if (stack) {
int n = cJSON_GetArraySize(stack);
/* depth 0 = immediate caller of caller_info, which is frame index 1
(frame 0 is caller_info itself) */
int idx = depth + 1;
if (idx >= n) idx = n - 1;
if (idx < 0) idx = 0;
cJSON *fr = cJSON_GetArrayItem(stack, idx);
const char *v;
v = cJSON_GetStringValue(cJSON_GetObjectItemCaseSensitive(fr, "function"));
if (v) fn_str = v;
v = cJSON_GetStringValue(cJSON_GetObjectItemCaseSensitive(fr, "file"));
if (v) file_str = v;
line = (int)cJSON_GetNumberValue(cJSON_GetObjectItemCaseSensitive(fr, "line"));
col = (int)cJSON_GetNumberValue(cJSON_GetObjectItemCaseSensitive(fr, "column"));
}
JSGCRef obj;
JS_PushGCRef(ctx, &obj);
obj.val = JS_NewObject(ctx);
JS_SetPropertyStr(ctx, obj.val, "file", JS_NewString(ctx, file_str));
JS_SetPropertyStr(ctx, obj.val, "line", JS_NewInt32(ctx, line));
JS_SetPropertyStr(ctx, obj.val, "column", JS_NewInt32(ctx, col));
JS_SetPropertyStr(ctx, obj.val, "function", JS_NewString(ctx, fn_str));
JSValue result = obj.val;
JS_PopGCRef(ctx, &obj);
if (stack) cJSON_Delete(stack);
return result;
if (n > 0) return JS_GetPropertyNumber(ctx, stack, idx);
return JS_NULL;
}
/* ----------------------------------------------------------------------------
@@ -12771,49 +12746,61 @@ JSValue js_core_math_cycles_use (JSContext *ctx) {
JS_PopGCRef (ctx, &obj_ref);
return result;
}
/* Public API: get stack trace as cJSON array */
cJSON *JS_GetStack(JSContext *ctx) {
if (JS_IsNull(ctx->reg_current_frame)) return NULL;
/* Public API: get stack trace as JS array of {fn, file, line, col} objects.
Does NOT clear reg_current_frame — caller is responsible if needed.
Two-phase approach for GC safety: Phase 1 collects raw C data on the C stack
(pointers into stable JSCodeRegister fields), Phase 2 allocates JS objects. */
JSValue JS_GetStack(JSContext *ctx) {
if (JS_IsNull(ctx->reg_current_frame)) return JS_NewArray(ctx);
/* Phase 1: collect raw frame data (no JS allocations) */
struct { const char *fn; const char *file; uint16_t line, col; } frames[64];
int count = 0;
JSFrameRegister *frame = (JSFrameRegister *)JS_VALUE_GET_PTR(ctx->reg_current_frame);
uint32_t cur_pc = ctx->current_register_pc;
cJSON *arr = cJSON_CreateArray();
int is_first = 1;
while (frame) {
while (frame && count < 64) {
if (!JS_IsFunction(frame->function)) break;
JSFunction *fn = JS_VALUE_GET_FUNCTION(frame->function);
const char *func_name = NULL;
const char *file = NULL;
uint16_t line = 0, col = 0;
uint32_t pc = is_first ? cur_pc : 0;
if (fn->kind == JS_FUNC_KIND_REGISTER && fn->u.reg.code) {
JSCodeRegister *code = fn->u.reg.code;
file = code->filename_cstr;
func_name = code->name_cstr;
if (!is_first) {
pc = (uint32_t)(JS_VALUE_GET_INT(frame->address) >> 16);
}
uint32_t pc = is_first ? cur_pc : (uint32_t)(JS_VALUE_GET_INT(frame->address) >> 16);
frames[count].fn = code->name_cstr;
frames[count].file = code->filename_cstr;
frames[count].line = 0;
frames[count].col = 0;
if (code->line_table && pc < code->instr_count) {
line = code->line_table[pc].line;
col = code->line_table[pc].col;
frames[count].line = code->line_table[pc].line;
frames[count].col = code->line_table[pc].col;
}
count++;
}
cJSON *entry = cJSON_CreateObject();
cJSON_AddStringToObject(entry, "function", func_name ? func_name : "<anonymous>");
cJSON_AddStringToObject(entry, "file", file ? file : "<unknown>");
cJSON_AddNumberToObject(entry, "line", line);
cJSON_AddNumberToObject(entry, "column", col);
cJSON_AddItemToArray(arr, entry);
if (JS_IsNull(frame->caller)) break;
frame = (JSFrameRegister *)JS_VALUE_GET_PTR(frame->caller);
is_first = 0;
}
ctx->reg_current_frame = JS_NULL;
return arr;
/* Phase 2: create JS objects (frame data is on C stack, safe across GC) */
JSGCRef arr_ref;
JS_PushGCRef(ctx, &arr_ref);
arr_ref.val = JS_NewArray(ctx);
for (int i = 0; i < count; i++) {
JSGCRef item_ref;
JS_PushGCRef(ctx, &item_ref);
item_ref.val = JS_NewObject(ctx);
JS_SetPropertyStr(ctx, item_ref.val, "fn",
JS_NewString(ctx, frames[i].fn ? frames[i].fn : "<anonymous>"));
JS_SetPropertyStr(ctx, item_ref.val, "file",
JS_NewString(ctx, frames[i].file ? frames[i].file : "<unknown>"));
JS_SetPropertyStr(ctx, item_ref.val, "line", JS_NewInt32(ctx, frames[i].line));
JS_SetPropertyStr(ctx, item_ref.val, "col", JS_NewInt32(ctx, frames[i].col));
JS_SetPropertyNumber(ctx, arr_ref.val, i, item_ref.val);
JS_PopGCRef(ctx, &item_ref);
}
JSValue result = arr_ref.val;
JS_PopGCRef(ctx, &arr_ref);
return result;
}