Improve script logging

1 - Add a custom console.lp function to make our debug logs stand out from
    script logs.

2 - In some cases, significantly improve how JavaScript values are serialized
    in debug logs and in console.log.
This commit is contained in:
Karl Seguin
2025-05-31 21:23:02 +08:00
parent c3f3eea7fb
commit 6e80b03faa
3 changed files with 66 additions and 26 deletions

View File

@@ -19,8 +19,9 @@
const std = @import("std");
const builtin = @import("builtin");
const JsObject = @import("../env.zig").Env.JsObject;
const Allocator = std.mem.Allocator;
const Page = @import("../page.zig").Page;
const JsObject = @import("../env.zig").Env.JsObject;
const log = if (builtin.is_test) &test_capture else @import("../../log.zig");
@@ -29,6 +30,13 @@ pub const Console = struct {
timers: std.StringHashMapUnmanaged(u32) = .{},
counts: std.StringHashMapUnmanaged(u32) = .{},
pub fn _lp(_: *const Console, values: []JsObject, page: *Page) !void {
if (values.len == 0) {
return;
}
log.fatal(.console, "lightpanda", .{ .args = try serializeValues(values, page) });
}
pub fn _log(_: *const Console, values: []JsObject, page: *Page) !void {
if (values.len == 0) {
return;
@@ -134,12 +142,19 @@ pub const Console = struct {
}
fn serializeValues(values: []JsObject, page: *Page) ![]const u8 {
if (values.len == 0) {
return "";
}
const arena = page.call_arena;
const separator = log.separator();
var arr: std.ArrayListUnmanaged(u8) = .{};
try arr.appendSlice(arena, try values[0].toString());
for (values[1..]) |value| {
try arr.append(arena, ' ');
try arr.appendSlice(arena, try value.toString());
for (values, 1..) |value, i| {
try arr.appendSlice(arena, separator);
try arr.writer(arena).print("{d}: ", .{i});
const serialized = if (builtin.mode == .Debug) value.toDetailString() else value.toString();
try arr.appendSlice(arena, try serialized);
}
return arr.items;
}

View File

@@ -173,13 +173,17 @@ fn logLogfmt(comptime scope: Scope, level: Level, comptime msg: []const u8, data
}
fn logPretty(comptime scope: Scope, level: Level, comptime msg: []const u8, data: anytype, writer: anytype) !void {
if (scope == .console and level == .fatal and comptime std.mem.eql(u8, msg, "lightpanda")) {
try writer.writeAll("\x1b[0;104mWARN ");
} else {
try writer.writeAll(switch (level) {
.debug => "\x1b[0;36mDEBUG\x1b[0m ",
.info => "\x1b[0;32mINFO\x1b[0m ",
.warn => "\x1b[0;33mWARN\x1b[0m ",
.err => "\x1b[0;31mERROR\x1b[0m ",
.fatal => "\x1b[0;35mFATAL\x1b[0m ",
.err => "\x1b[0;31mERROR ",
.fatal => "\x1b[0;35mFATAL ",
});
}
const prefix = @tagName(scope) ++ " : " ++ msg;
try writer.writeAll(prefix);
@@ -194,7 +198,7 @@ fn logPretty(comptime scope: Scope, level: Level, comptime msg: []const u8, data
if (@mod(padding, 2) == 1) {
try writer.writeByte(' ');
}
try writer.print(" [+{d}ms]", .{elapsed()});
try writer.print(" \x1b[0m[+{d}ms]", .{elapsed()});
try writer.writeByte('\n');
}

View File

@@ -1373,6 +1373,12 @@ pub fn Env(comptime State: type, comptime WebApis: type) type {
return valueToString(scope.call_arena, js_value, scope.isolate, scope.context);
}
pub fn toDetailString(self: JsObject) ![]const u8 {
const scope = self.scope;
const js_value = self.js_obj.toValue();
return valueToDetailString(scope.call_arena, js_value, scope.isolate, scope.context);
}
pub fn format(self: JsObject, comptime _: []const u8, _: std.fmt.FormatOptions, writer: anytype) !void {
return writer.writeAll(try self.toString());
}
@@ -2493,6 +2499,15 @@ fn Caller(comptime E: type, comptime State: type) type {
}
fn handleError(self: *Self, comptime Struct: type, comptime named_function: NamedFunction, err: anyerror, info: anytype) void {
if (builtin.mode == .Debug and log.enabled(.js, .warn) and @hasDecl(@TypeOf(info), "length")) {
const args_dump = self.serializeFunctionArgs(info) catch "failed to serialize args";
log.warn(.js, "function call error", .{
.name = named_function.full_name,
.err = err,
.args = args_dump,
});
}
const isolate = self.isolate;
var js_err: ?v8.Value = switch (err) {
error.InvalidArgument => createTypeException(isolate, "invalid argument"),
@@ -2635,15 +2650,6 @@ fn Caller(comptime E: type, comptime State: type) type {
const last_js_parameter = params_to_map.len - 1;
var is_variadic = false;
errdefer |err| if (builtin.mode == .Debug and log.enabled(.js, .warn)) {
const args_dump = self.serializeFunctionArgs(info) catch "failed to serialize args";
log.warn(.js, "function call error", .{
.name = named_function.full_name,
.err = err,
.args = args_dump,
});
};
{
// This is going to get complicated. If the last Zig paremeter
// is a slice AND the corresponding javascript parameter is
@@ -2710,6 +2716,7 @@ fn Caller(comptime E: type, comptime State: type) type {
const isolate = self.isolate;
const context = self.context;
const arena = self.call_arena;
const separator = log.separator();
const js_parameter_count = info.length();
var arr: std.ArrayListUnmanaged(u8) = .{};
@@ -2718,7 +2725,7 @@ fn Caller(comptime E: type, comptime State: type) type {
const value_string = try valueToDetailString(arena, js_value, isolate, context);
const value_type = try jsStringToZig(arena, try js_value.typeOf(isolate), isolate);
try std.fmt.format(arr.writer(arena), "{s}{d}: {s} ({s})", .{
log.separator(),
separator,
i + 1,
value_string,
value_type,
@@ -3057,9 +3064,23 @@ const TaggedAnyOpaque = struct {
subtype: ?SubType,
};
fn valueToDetailString(allocator: Allocator, value: v8.Value, isolate: v8.Isolate, context: v8.Context) ![]u8 {
const str = try value.toDetailString(context);
return jsStringToZig(allocator, str, isolate);
fn valueToDetailString(arena: Allocator, value: v8.Value, isolate: v8.Isolate, context: v8.Context) ![]u8 {
var str: ?v8.String = null;
if (value.isObject() and !value.isFunction()) {
str = try v8.Json.stringify(context, value, null);
if (str.?.lenUtf8(isolate) == 2) {
// {} isn't useful, null this so that we can get the toDetailString
// (which might also be useless, but maybe not)
str = null;
}
}
if (str == null) {
str = try value.toDetailString(context);
}
return jsStringToZig(arena, str.?, isolate);
}
fn valueToString(allocator: Allocator, value: v8.Value, isolate: v8.Isolate, context: v8.Context) ![]u8 {