Attempt to add more context to debug logs.

1 - On `unkown global property`, include the stack trace (this might be WAY too
verbose)

2 - On script get, include stack trace (when available)

3 - On script get, include referrer

4 - Stack traces will now include the script name/src when available
This commit is contained in:
Karl Seguin
2025-10-06 16:56:54 +08:00
parent 207f0655dd
commit 9cb37dc011
7 changed files with 41 additions and 49 deletions

View File

@@ -5,8 +5,8 @@
.fingerprint = 0xda130f3af836cea0,
.dependencies = .{
.v8 = .{
.url = "https://github.com/lightpanda-io/zig-v8-fork/archive/7a1beb016efcb2bd66c0b46b5fc6bcd04fa72db8.tar.gz",
.hash = "v8-0.0.0-xddH6_PFAwAqwLMWbF7S0rAZzRbN8zmf2GhLH_ThdMSR",
.url = "https://github.com/lightpanda-io/zig-v8-fork/archive/5ce9ade6c6d7f7ab9ab4582a6b1b36fdc8e246e2.tar.gz",
.hash = "v8-0.0.0-xddH6yTGAwA__kfiDozsVXL2_jnycrtDUfR8kIADQFUz",
},
//.v8 = .{ .path = "../zig-v8-fork" }
},

View File

@@ -142,7 +142,7 @@ fn clearList(_: *const ScriptManager, list: *OrderList) void {
std.debug.assert(list.first == null);
}
pub fn addFromElement(self: *ScriptManager, element: *parser.Element) !void {
pub fn addFromElement(self: *ScriptManager, element: *parser.Element, comptime ctx: []const u8) !void {
if (try parser.elementGetAttribute(element, "nomodule") != null) {
// these scripts should only be loaded if we don't support modules
// but since we do support modules, we can just skip them.
@@ -230,7 +230,11 @@ pub fn addFromElement(self: *ScriptManager, element: *parser.Element) !void {
self.scripts.append(&pending_script.node);
return;
} else {
log.debug(.http, "script queue", .{ .url = remote_url.? });
log.debug(.http, "script queue", .{
.ctx = ctx,
.url = remote_url.?,
.stack = page.js.stackTrace() catch "???",
});
}
pending_script.getList().append(&pending_script.node);
@@ -255,40 +259,7 @@ pub fn addFromElement(self: *ScriptManager, element: *parser.Element) !void {
});
}
// @TODO: Improving this would have the simplest biggest performance improvement
// for most sites.
//
// For JS imports (both static and dynamic), we currently block to get the
// result (the content of the file).
//
// For static imports, this is necessary, since v8 is expecting the compiled module
// as part of the function return. (we should try to pre-load the JavaScript
// source via module.GetModuleRequests(), but that's for a later time).
//
// For dynamic dynamic imports, this is not strictly necessary since the v8
// call returns a Promise; we could make this a normal get call, associated with
// the promise, and when done, resolve the promise.
//
// In both cases, for now at least, we just issue a "blocking" request. We block
// by ticking the http client until the script is complete.
//
// This uses the client.blockingRequest call which has a dedicated handle for
// these blocking requests. Because they are blocking, we're guaranteed to have
// only 1 at a time, thus the 1 reserved handle.
//
// You almost don't need the http client's blocking handle. In most cases, you
// should always have 1 free handle whenever you get here, because we always
// release the handle before executing the doneCallback. So, if a module does:
// import * as x from 'blah'
// And we need to load 'blah', there should always be 1 free handle - the handle
// of the http GET we just completed before executing the module.
// The exception to this, and the reason we need a special blocking handle, is
// for inline modules within the HTML page itself:
// <script type=module>import ....</script>
// Unlike external modules which can only ever be executed after releasing an
// http handle, these are executed without there necessarily being a free handle.
// Thus, Http/Client.zig maintains a dedicated handle for these calls.
pub fn getModule(self: *ScriptManager, url: [:0]const u8) !void {
pub fn getModule(self: *ScriptManager, url: [:0]const u8, referrer: []const u8) !void {
const gop = try self.sync_modules.getOrPut(self.allocator, url);
if (gop.found_existing) {
// already requested
@@ -305,6 +276,13 @@ pub fn getModule(self: *ScriptManager, url: [:0]const u8) !void {
var headers = try self.client.newHeaders();
try self.page.requestCookie(.{}).headersForRequest(self.page.arena, url, &headers);
log.debug(.http, "script queue", .{
.url = url,
.ctx = "module",
.referrer = referrer,
.stack = self.page.js.stackTrace() catch "???",
});
try self.client.request(.{
.url = url,
.ctx = sync,
@@ -355,7 +333,7 @@ pub fn waitForModule(self: *ScriptManager, url: [:0]const u8) !GetResult {
}
}
pub fn getAsyncModule(self: *ScriptManager, url: [:0]const u8, cb: AsyncModule.Callback, cb_data: *anyopaque) !void {
pub fn getAsyncModule(self: *ScriptManager, url: [:0]const u8, cb: AsyncModule.Callback, cb_data: *anyopaque, referrer: []const u8) !void {
const async = try self.async_module_pool.create();
errdefer self.async_module_pool.destroy(async);
@@ -368,6 +346,13 @@ pub fn getAsyncModule(self: *ScriptManager, url: [:0]const u8, cb: AsyncModule.C
var headers = try self.client.newHeaders();
try self.page.requestCookie(.{}).headersForRequest(self.page.arena, url, &headers);
log.debug(.http, "script queue", .{
.url = url,
.ctx = "dynamic module",
.referrer = referrer,
.stack = self.page.js.stackTrace() catch "???",
});
try self.client.request(.{
.url = url,
.method = .GET,

View File

@@ -887,7 +887,7 @@ pub const HTMLScriptElement = struct {
// s.src = '...';
// This should load the script.
// addFromElement protects against double execution.
try page.script_manager.addFromElement(@ptrCast(@alignCast(self)));
try page.script_manager.addFromElement(@ptrCast(@alignCast(self)), "dynamic");
}
}

View File

@@ -263,7 +263,7 @@ pub fn module(self: *Context, comptime want_result: bool, src: []const u8, url:
const owned_specifier = try self.context_arena.dupeZ(u8, normalized_specifier);
gop.key_ptr.* = owned_specifier;
gop.value_ptr.* = .{};
try self.script_manager.?.getModule(owned_specifier);
try self.script_manager.?.getModule(owned_specifier, src);
}
}
}
@@ -996,7 +996,10 @@ fn debugValueToString(self: *const Context, js_obj: v8.Object) ![]u8 {
}
pub fn stackTrace(self: *const Context) !?[]const u8 {
std.debug.assert(@import("builtin").mode == .Debug);
if (comptime @import("builtin").mode != .Debug) {
return "not available";
}
const isolate = self.isolate;
const separator = log.separator();
@@ -1006,6 +1009,10 @@ pub fn stackTrace(self: *const Context) !?[]const u8 {
const stack_trace = v8.StackTrace.getCurrentStackTrace(isolate, 30);
const frame_count = stack_trace.getFrameCount();
if (v8.StackTrace.getCurrentScriptNameOrSourceUrl(isolate)) |script| {
try writer.print("{s}<{s}>", .{ separator, try self.jsStringToZig(script, .{}) });
}
for (0..frame_count) |i| {
const frame = stack_trace.getFrame(isolate, @intCast(i));
if (frame.getScriptName()) |name| {
@@ -1131,7 +1138,7 @@ pub fn dynamicModuleCallback(
return @constCast(self.rejectPromise("Out of memory").handle);
};
const promise = self._dynamicModuleCallback(normalized_specifier) catch |err| blk: {
const promise = self._dynamicModuleCallback(normalized_specifier, resource) catch |err| blk: {
log.err(.js, "dynamic module callback", .{
.err = err,
});
@@ -1191,7 +1198,7 @@ fn _resolveModuleCallback(self: *Context, referrer: v8.Module, specifier: []cons
// harm in handling this case.
@branchHint(.unlikely);
gop.value_ptr.* = .{};
try self.script_manager.?.getModule(normalized_specifier);
try self.script_manager.?.getModule(normalized_specifier, referrer_path);
}
var fetch_result = try self.script_manager.?.waitForModule(normalized_specifier);
@@ -1227,7 +1234,7 @@ const DynamicModuleResolveState = struct {
resolver: v8.Persistent(v8.PromiseResolver),
};
fn _dynamicModuleCallback(self: *Context, specifier: [:0]const u8) !v8.Promise {
fn _dynamicModuleCallback(self: *Context, specifier: [:0]const u8, referrer: []const u8) !v8.Promise {
const isolate = self.isolate;
const gop = try self.module_cache.getOrPut(self.context_arena, specifier);
if (gop.found_existing and gop.value_ptr.resolver_promise != null) {
@@ -1267,7 +1274,7 @@ fn _dynamicModuleCallback(self: *Context, specifier: [:0]const u8) !v8.Promise {
};
// Next, we need to actually load it.
self.script_manager.?.getAsyncModule(specifier, dynamicModuleSourceCallback, state) catch |err| {
self.script_manager.?.getAsyncModule(specifier, dynamicModuleSourceCallback, state, referrer) catch |err| {
const error_msg = v8.String.initUtf8(isolate, @errorName(err));
_ = resolver.reject(self.v8_context, error_msg.toValue());
};

View File

@@ -785,7 +785,7 @@ pub const Page = struct {
// ignore non-js script.
continue;
}
try self.script_manager.addFromElement(@ptrCast(node));
try self.script_manager.addFromElement(@ptrCast(node), "page");
}
self.script_manager.staticScriptsDone();
@@ -1250,7 +1250,7 @@ pub export fn scriptAddedCallback(ctx: ?*anyopaque, element: ?*parser.Element) c
// here, else the script_manager will flag it as already-processed.
_ = parser.elementGetAttribute(element.?, "src") catch return orelse return;
self.script_manager.addFromElement(element.?) catch |err| {
self.script_manager.addFromElement(element.?, "dynamic") catch |err| {
log.warn(.browser, "dynamic script", .{ .err = err });
};
}

View File

@@ -69,6 +69,7 @@ pub const Loader = struct {
if (comptime builtin.mode == .Debug) {
log.debug(.unknown_prop, "unkown global property", .{
.info = "but the property can exist in pure JS",
.stack = js_context.stackTrace() catch "???",
.property = name,
});
}

View File

@@ -443,7 +443,6 @@ const LineWriter = struct {
}
};
pub fn debugCallback(_: *c.CURL, msg_type: c.curl_infotype, raw: [*c]u8, len: usize, _: *anyopaque) callconv(.c) void {
const data = raw[0..len];
switch (msg_type) {