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.

Author: karlseguin

src/browser/console/console.zig

@@ -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;
     }

src/log.zig

@@ -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 {
-    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 ",
-    });
+    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 ",
+            .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');
     }
 

src/runtime/js.zig

@@ -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 {