Improve logging

1 - Make log_level a runtime option (not a build-time)
2 - Make log_format a runtime option
3 - In Debug mode, allow for log scope filtering

Improve the general usability of scopes. Previously, the scope was more or less
based on the file that the log was in. Now they are more logically grouped.
Consider the case where you want to silence HTTP request information, previously
you'd have to filter out the `page`, `xhr` and `http_client` scopes, but that
would also elimiate other page, xhr and http_client logs. Now, you can just
filter out the `http` scope.
This commit is contained in:
Karl Seguin
2025-05-31 20:02:23 +08:00
parent 47da5e0338
commit c3f3eea7fb
23 changed files with 371 additions and 199 deletions

View File

@@ -44,21 +44,6 @@ pub fn build(b: *std.Build) !void {
b.option([]const u8, "git_commit", "Current git commit") orelse "dev", b.option([]const u8, "git_commit", "Current git commit") orelse "dev",
); );
{
const log = @import("src/log.zig");
opts.addOption(
log.Level,
"log_level",
b.option(log.Level, "log_level", "The log level") orelse .info,
);
}
opts.addOption(
bool,
"log_unknown_properties",
b.option(bool, "log_unknown_properties", "Log access to unknown properties") orelse false,
);
const target = b.standardTargetOptions(.{}); const target = b.standardTargetOptions(.{});
const optimize = b.standardOptimizeOption(.{}); const optimize = b.standardOptimizeOption(.{});

View File

@@ -278,7 +278,7 @@ const TestCapture = struct {
inline for (@typeInfo(@TypeOf(args)).@"struct".fields) |f| { inline for (@typeInfo(@TypeOf(args)).@"struct".fields) |f| {
try buf.appendSlice(allocator, f.name); try buf.appendSlice(allocator, f.name);
try buf.append(allocator, '='); try buf.append(allocator, '=');
try @import("../../log.zig").writeValue(false, @field(args, f.name), buf.writer(allocator)); try @import("../../log.zig").writeValue(.pretty, @field(args, f.name), buf.writer(allocator));
try buf.append(allocator, ' '); try buf.append(allocator, ' ');
} }
self.captured.append(testing.arena_allocator, std.mem.trimRight(u8, buf.items, " ")) catch unreachable; self.captured.append(testing.arena_allocator, std.mem.trimRight(u8, buf.items, " ")) catch unreachable;

View File

@@ -147,7 +147,7 @@ pub const Element = struct {
while (true) { while (true) {
if (try select.match(current)) { if (try select.match(current)) {
if (!current.isElement()) { if (!current.isElement()) {
log.err(.element, "closest invalid type", .{ .type = try current.tag() }); log.err(.browser, "closest invalid type", .{ .type = try current.tag() });
return null; return null;
} }
return parser.nodeToElement(current.node); return parser.nodeToElement(current.node);

View File

@@ -86,7 +86,11 @@ pub const IntersectionObserver = struct {
var result: Env.Function.Result = undefined; var result: Env.Function.Result = undefined;
self.callback.tryCall(void, .{self.observed_entries.items}, &result) catch { self.callback.tryCall(void, .{self.observed_entries.items}, &result) catch {
log.debug(.int_obs, "callback error", .{ .err = result.exception, .stack = result.stack }); log.debug(.user_script, "callback error", .{
.err = result.exception,
.stack = result.stack,
.source = "intersection observer",
});
}; };
} }

View File

@@ -114,7 +114,11 @@ pub const MutationObserver = struct {
const records = [_]MutationRecord{r.*}; const records = [_]MutationRecord{r.*};
var result: Env.Function.Result = undefined; var result: Env.Function.Result = undefined;
self.cbk.tryCall(void, .{records}, &result) catch { self.cbk.tryCall(void, .{records}, &result) catch {
log.debug(.mut_obs, "callback error", .{ .err = result.exception, .stack = result.stack }); log.debug(.user_script, "callback error", .{
.err = result.exception,
.stack = result.stack,
.source = "mutation observer",
});
}; };
} }
} }
@@ -242,7 +246,7 @@ const Observer = struct {
fn handle(en: *parser.EventNode, event: *parser.Event) void { fn handle(en: *parser.EventNode, event: *parser.Event) void {
const self: *Observer = @fieldParentPtr("event_node", en); const self: *Observer = @fieldParentPtr("event_node", en);
self._handle(event) catch |err| { self._handle(event) catch |err| {
log.err(.mut_obs, "handle error", .{ .err = err }); log.err(.web_api, "handle error", .{ .err = err, .source = "mutation observer" });
}; };
} }

View File

@@ -269,7 +269,7 @@ pub const Node = struct {
// - An Element that is not attached to a document or a shadow tree will return the root of the DOM tree it belongs to // - An Element that is not attached to a document or a shadow tree will return the root of the DOM tree it belongs to
pub fn _getRootNode(self: *parser.Node, options: ?struct { composed: bool = false }) !Union { pub fn _getRootNode(self: *parser.Node, options: ?struct { composed: bool = false }) !Union {
if (options) |options_| if (options_.composed) { if (options) |options_| if (options_.composed) {
log.warn(.node, "not implemented", .{ .feature = "getRootNode composed" }); log.warn(.web_api, "not implemented", .{ .feature = "getRootNode composed" });
}; };
return try Node.toInterface(try parser.nodeGetRootNode(self)); return try Node.toInterface(try parser.nodeGetRootNode(self));
} }

View File

@@ -145,7 +145,7 @@ pub const NodeList = struct {
const ii: u32 = @intCast(i); const ii: u32 = @intCast(i);
var result: Function.Result = undefined; var result: Function.Result = undefined;
cbk.tryCall(void, .{ n, ii, self }, &result) catch { cbk.tryCall(void, .{ n, ii, self }, &result) catch {
log.debug(.node_list, "forEach callback", .{ .err = result.exception, .stack = result.stack }); log.debug(.user_script, "forEach callback", .{ .err = result.exception, .stack = result.stack });
}; };
} }
} }

View File

@@ -142,7 +142,11 @@ pub const DOMTokenList = struct {
while (try entries._next()) |entry| { while (try entries._next()) |entry| {
var result: Function.Result = undefined; var result: Function.Result = undefined;
cbk.tryCallWithThis(void, this_arg, .{ entry.@"1", entry.@"0", self }, &result) catch { cbk.tryCallWithThis(void, this_arg, .{ entry.@"1", entry.@"0", self }, &result) catch {
log.debug(.token_list, "foreach callback error", .{ .err = result.exception, .stack = result.stack }); log.debug(.user_script, "callback error", .{
.err = result.exception,
.stack = result.stack,
.soure = "tokenList foreach",
});
}; };
} }
} }

View File

@@ -237,14 +237,18 @@ pub const EventHandler = struct {
fn handle(node: *parser.EventNode, event: *parser.Event) void { fn handle(node: *parser.EventNode, event: *parser.Event) void {
const ievent = Event.toInterface(event) catch |err| { const ievent = Event.toInterface(event) catch |err| {
log.err(.event, "toInterface error", .{ .err = err }); log.err(.app, "toInterface error", .{ .err = err });
return; return;
}; };
const self: *EventHandler = @fieldParentPtr("node", node); const self: *EventHandler = @fieldParentPtr("node", node);
var result: Function.Result = undefined; var result: Function.Result = undefined;
self.callback.tryCall(void, .{ievent}, &result) catch { self.callback.tryCall(void, .{ievent}, &result) catch {
log.debug(.event, "handle callback error", .{ .err = result.exception, .stack = result.stack }); log.debug(.user_script, "callback error", .{
.err = result.exception,
.stack = result.stack,
.source = "event handler",
});
}; };
if (self.once) { if (self.once) {

View File

@@ -18,6 +18,7 @@
const std = @import("std"); const std = @import("std");
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig"); const parser = @import("../netsurf.zig");
const Page = @import("../page.zig").Page; const Page = @import("../page.zig").Page;
@@ -276,6 +277,10 @@ pub const HTMLDocument = struct {
const evt = try parser.eventCreate(); const evt = try parser.eventCreate();
defer parser.eventDestroy(evt); defer parser.eventDestroy(evt);
log.debug(.script_event, "dispatch event", .{
.type = "DOMContentLoaded",
.source = "document",
});
try parser.eventInit(evt, "DOMContentLoaded", .{ .bubbles = true, .cancelable = true }); try parser.eventInit(evt, "DOMContentLoaded", .{ .bubbles = true, .cancelable = true });
_ = try parser.eventTargetDispatchEvent(parser.toEventTarget(parser.DocumentHTML, html_doc), evt); _ = try parser.eventTargetDispatchEvent(parser.toEventTarget(parser.DocumentHTML, html_doc), evt);
} }

View File

@@ -174,7 +174,11 @@ pub const Window = struct {
// Since: When multiple callbacks queued by requestAnimationFrame() begin to fire in a single frame, each receives the same timestamp even though time has passed during the computation of every previous callback's workload. // Since: When multiple callbacks queued by requestAnimationFrame() begin to fire in a single frame, each receives the same timestamp even though time has passed during the computation of every previous callback's workload.
var result: Function.Result = undefined; var result: Function.Result = undefined;
callback.tryCall(void, .{self.performance._now()}, &result) catch { callback.tryCall(void, .{self.performance._now()}, &result) catch {
log.debug(.window, "requestAnimationFrame error", .{ .err = result.exception, .stack = result.stack }); log.debug(.user_script, "callback error", .{
.err = result.exception,
.stack = result.stack,
.source = "requestAnimationFrame",
});
}; };
return 99; // not unique, but user cannot make assumptions about it. cancelAnimationFrame will be too late anyway. return 99; // not unique, but user cannot make assumptions about it. cancelAnimationFrame will be too late anyway.
} }
@@ -215,7 +219,7 @@ pub const Window = struct {
fn createTimeout(self: *Window, cbk: Function, delay_: ?u32, page: *Page, comptime repeat: bool) !u32 { fn createTimeout(self: *Window, cbk: Function, delay_: ?u32, page: *Page, comptime repeat: bool) !u32 {
const delay = delay_ orelse 0; const delay = delay_ orelse 0;
if (delay > 5000) { if (delay > 5000) {
log.warn(.window, "long timeout ignored", .{ .delay = delay, .interval = repeat }); log.warn(.user_script, "long timeout ignored", .{ .delay = delay, .interval = repeat });
// self.timer_id is u30, so the largest value we can generate is // self.timer_id is u30, so the largest value we can generate is
// 1_073_741_824. Returning 2_000_000_000 makes sure that clients // 1_073_741_824. Returning 2_000_000_000 makes sure that clients
// can call cancelTimer/cancelInterval without breaking anything. // can call cancelTimer/cancelInterval without breaking anything.
@@ -288,7 +292,11 @@ const TimerCallback = struct {
var result: Function.Result = undefined; var result: Function.Result = undefined;
self.cbk.tryCall(void, .{}, &result) catch { self.cbk.tryCall(void, .{}, &result) catch {
log.debug(.window, "timeout callback error", .{ .err = result.exception, .stack = result.stack }); log.debug(.user_script, "callback error", .{
.err = result.exception,
.stack = result.stack,
.source = "window timeout",
});
}; };
if (self.repeat) |r| { if (self.repeat) |r| {

View File

@@ -164,12 +164,12 @@ pub const Page = struct {
try self.session.browser.app.loop.run(); try self.session.browser.app.loop.run();
if (try_catch.hasCaught() == false) { if (try_catch.hasCaught() == false) {
log.debug(.page, "wait complete", .{}); log.debug(.browser, "page wait complete", .{});
return; return;
} }
const msg = (try try_catch.err(self.arena)) orelse "unknown"; const msg = (try try_catch.err(self.arena)) orelse "unknown";
log.err(.page, "wait error", .{ .err = msg }); log.err(.browser, "page wait error", .{ .err = msg });
} }
pub fn origin(self: *const Page, arena: Allocator) ![]const u8 { pub fn origin(self: *const Page, arena: Allocator) ![]const u8 {
@@ -184,7 +184,7 @@ pub const Page = struct {
const session = self.session; const session = self.session;
const notification = session.browser.notification; const notification = session.browser.notification;
log.debug(.page, "navigate", .{ .url = request_url, .reason = opts.reason }); log.debug(.http, "navigate", .{ .url = request_url, .reason = opts.reason });
// if the url is about:blank, nothing to do. // if the url is about:blank, nothing to do.
if (std.mem.eql(u8, "about:blank", request_url.raw)) { if (std.mem.eql(u8, "about:blank", request_url.raw)) {
@@ -233,7 +233,7 @@ pub const Page = struct {
break :blk Mime.sniff(try response.peek()); break :blk Mime.sniff(try response.peek());
} orelse .unknown; } orelse .unknown;
log.info(.page, "navigation", .{ log.info(.http, "navigation", .{
.status = header.status, .status = header.status,
.content_type = content_type, .content_type = content_type,
.charset = mime.charset, .charset = mime.charset,
@@ -257,7 +257,9 @@ pub const Page = struct {
.url = &self.url, .url = &self.url,
.timestamp = timestamp(), .timestamp = timestamp(),
}); });
log.debug(.page, "navigation complete", .{}); log.debug(.http, "navigation complete", .{
.url = request_url,
});
} }
// https://html.spec.whatwg.org/#read-html // https://html.spec.whatwg.org/#read-html
@@ -383,6 +385,7 @@ pub const Page = struct {
const loadevt = try parser.eventCreate(); const loadevt = try parser.eventCreate();
defer parser.eventDestroy(loadevt); defer parser.eventDestroy(loadevt);
log.debug(.script_event, "dispatch event", .{ .type = "load", .source = "page" });
try parser.eventInit(loadevt, "load", .{}); try parser.eventInit(loadevt, "load", .{});
_ = try parser.eventTargetDispatchEvent( _ = try parser.eventTargetDispatchEvent(
parser.toEventTarget(Window, &self.window), parser.toEventTarget(Window, &self.window),
@@ -392,7 +395,7 @@ pub const Page = struct {
fn evalScript(self: *Page, script: *const Script) void { fn evalScript(self: *Page, script: *const Script) void {
self.tryEvalScript(script) catch |err| { self.tryEvalScript(script) catch |err| {
log.err(.page, "eval script error", .{ .err = err }); log.err(.js, "eval script error", .{ .err = err, .src = script.src });
}; };
} }
@@ -404,7 +407,7 @@ pub const Page = struct {
try parser.documentHTMLSetCurrentScript(html_doc, @ptrCast(script.element)); try parser.documentHTMLSetCurrentScript(html_doc, @ptrCast(script.element));
defer parser.documentHTMLSetCurrentScript(html_doc, null) catch |err| { defer parser.documentHTMLSetCurrentScript(html_doc, null) catch |err| {
log.err(.page, "clear document script", .{ .err = err }); log.err(.browser, "clear document script", .{ .err = err });
}; };
const src = script.src orelse { const src = script.src orelse {
@@ -457,8 +460,8 @@ pub const Page = struct {
var origin_url = &self.url; var origin_url = &self.url;
const url = try origin_url.resolve(arena, res_src); const url = try origin_url.resolve(arena, res_src);
log.debug(.page, "fetching script", .{ .url = url }); log.debug(.http, "fetching script", .{ .url = url });
errdefer |err| log.err(.page, "fetch error", .{ .err = err, .url = url }); errdefer |err| log.err(.http, "fetch error", .{ .err = err, .url = url });
var request = try self.newHTTPRequest(.GET, &url, .{ var request = try self.newHTTPRequest(.GET, &url, .{
.origin_uri = &origin_url.uri, .origin_uri = &origin_url.uri,
@@ -486,7 +489,7 @@ pub const Page = struct {
return null; return null;
} }
log.info(.page, "fetch complete", .{ log.info(.http, "fetch complete", .{
.url = url, .url = url,
.status = header.status, .status = header.status,
.content_length = arr.items.len, .content_length = arr.items.len,
@@ -542,7 +545,7 @@ pub const Page = struct {
fn windowClicked(node: *parser.EventNode, event: *parser.Event) void { fn windowClicked(node: *parser.EventNode, event: *parser.Event) void {
const self: *Page = @fieldParentPtr("window_clicked_event_node", node); const self: *Page = @fieldParentPtr("window_clicked_event_node", node);
self._windowClicked(event) catch |err| { self._windowClicked(event) catch |err| {
log.err(.page, "click handler error", .{ .err = err }); log.err(.browser, "click handler error", .{ .err = err });
}; };
} }
@@ -675,7 +678,7 @@ const DelayedNavigation = struct {
_ = repeat_delay; _ = repeat_delay;
const self: *DelayedNavigation = @fieldParentPtr("navigate_node", node); const self: *DelayedNavigation = @fieldParentPtr("navigate_node", node);
self.session.pageNavigate(self.url, self.opts) catch |err| { self.session.pageNavigate(self.url, self.opts) catch |err| {
log.err(.page, "delayed navigation error", .{ .err = err, .url = self.url }); log.err(.browser, "delayed navigation error", .{ .err = err, .url = self.url });
}; };
} }
}; };
@@ -787,14 +790,17 @@ const Script = struct {
switch (try page.scope.module(body, src)) { switch (try page.scope.module(body, src)) {
.value => |v| break :blk v, .value => |v| break :blk v,
.exception => |e| { .exception => |e| {
log.warn(.page, "eval module", .{ .src = src, .err = try e.exception(page.arena) }); log.warn(.user_script, "eval module", .{
.src = src,
.err = try e.exception(page.arena),
});
return error.JsErr; return error.JsErr;
}, },
} }
}, },
} catch { } catch {
if (try try_catch.err(page.arena)) |msg| { if (try try_catch.err(page.arena)) |msg| {
log.warn(.page, "eval script", .{ .src = src, .err = msg }); log.warn(.user_script, "eval script", .{ .src = src, .err = msg });
} }
try self.executeCallback("onerror", page); try self.executeCallback("onerror", page);
return error.JsErr; return error.JsErr;
@@ -811,7 +817,7 @@ const Script = struct {
defer try_catch.deinit(); defer try_catch.deinit();
_ = page.scope.exec(str, typ) catch { _ = page.scope.exec(str, typ) catch {
if (try try_catch.err(page.arena)) |msg| { if (try try_catch.err(page.arena)) |msg| {
log.warn(.page, "script callback", .{ log.warn(.user_script, "script callback", .{
.src = self.src, .src = self.src,
.err = msg, .err = msg,
.type = typ, .type = typ,
@@ -827,7 +833,7 @@ const Script = struct {
var result: Env.Function.Result = undefined; var result: Env.Function.Result = undefined;
f.tryCall(void, .{try Event.toInterface(loadevt)}, &result) catch { f.tryCall(void, .{try Event.toInterface(loadevt)}, &result) catch {
log.warn(.page, "script callback", .{ log.warn(.user_script, "script callback", .{
.src = self.src, .src = self.src,
.type = typ, .type = typ,
.err = result.exception, .err = result.exception,
@@ -869,7 +875,7 @@ fn timestamp() u32 {
pub export fn scriptAddedCallback(ctx: ?*anyopaque, element: ?*parser.Element) callconv(.C) void { pub export fn scriptAddedCallback(ctx: ?*anyopaque, element: ?*parser.Element) callconv(.C) void {
const self: *Page = @alignCast(@ptrCast(ctx.?)); const self: *Page = @alignCast(@ptrCast(ctx.?));
var script = Script.init(element.?, self) catch |err| { var script = Script.init(element.?, self) catch |err| {
log.warn(.page, "script added init error", .{ .err = err }); log.warn(.browser, "script added init error", .{ .err = err });
return; return;
} orelse return; } orelse return;

View File

@@ -39,7 +39,7 @@ pub fn load(allocator: Allocator, scope: *Env.Scope) !void {
_ = scope.exec(m.source, m.name) catch |err| { _ = scope.exec(m.source, m.name) catch |err| {
if (try try_catch.err(allocator)) |msg| { if (try try_catch.err(allocator)) |msg| {
defer allocator.free(msg); defer allocator.free(msg);
log.err(.polyfill, "exec error", .{ .name = m.name, .err = msg }); log.fatal(.app, "polyfill error", .{ .name = m.name, .err = msg });
} }
return err; return err;
}; };

View File

@@ -95,7 +95,7 @@ pub const Session = struct {
const page = &self.page.?; const page = &self.page.?;
try Page.init(page, page_arena.allocator(), self); try Page.init(page, page_arena.allocator(), self);
log.debug(.session, "create page", .{}); log.debug(.browser, "create page", .{});
// start JS env // start JS env
// Inform CDP the main page has been created such that additional context for other Worlds can be created as well // Inform CDP the main page has been created such that additional context for other Worlds can be created as well
self.browser.notification.dispatch(.page_created, page); self.browser.notification.dispatch(.page_created, page);
@@ -116,7 +116,7 @@ pub const Session = struct {
// clear netsurf memory arena. // clear netsurf memory arena.
parser.deinit(); parser.deinit();
log.debug(.session, "remove page", .{}); log.debug(.browser, "remove page", .{});
} }
pub fn currentPage(self: *Session) ?*Page { pub fn currentPage(self: *Session) ?*Page {

View File

@@ -155,7 +155,7 @@ pub const Jar = struct {
var it = header.iterate("set-cookie"); var it = header.iterate("set-cookie");
while (it.next()) |set_cookie| { while (it.next()) |set_cookie| {
const c = Cookie.parse(self.allocator, uri, set_cookie) catch |err| { const c = Cookie.parse(self.allocator, uri, set_cookie) catch |err| {
log.warn(.cookie, "parse failed", .{ .raw = set_cookie, .err = err }); log.warn(.web_api, "cookie parse failed", .{ .raw = set_cookie, .err = err });
continue; continue;
}; };
try self.add(c, now); try self.add(c, now);

View File

@@ -148,7 +148,7 @@ pub const FormData = struct {
return urlEncode(self, writer); return urlEncode(self, writer);
} }
log.warn(.form_data, "encoding not supported", .{ .encoding = encoding }); log.warn(.web_api, "not implemented", .{ .feature = "form data encoding", .encoding = encoding });
return error.EncodingNotSupported; return error.EncodingNotSupported;
} }
}; };
@@ -334,7 +334,7 @@ fn collectForm(form: *parser.Form, submitter_: ?*parser.ElementHTML, page: *Page
} }
}, },
else => { else => {
log.warn(.form_data, "unsupported element", .{ .tag = @tagName(tag) }); log.warn(.web_api, "unsupported form element", .{ .tag = @tagName(tag) });
continue; continue;
}, },
} }

View File

@@ -334,9 +334,9 @@ pub const XMLHttpRequest = struct {
// dispatch request event. // dispatch request event.
// errors are logged only. // errors are logged only.
fn dispatchEvt(self: *XMLHttpRequest, typ: []const u8) void { fn dispatchEvt(self: *XMLHttpRequest, typ: []const u8) void {
log.debug(.xhr, "dispatch event", .{ .type = typ }); log.debug(.script_event, "dispatch event", .{ .type = typ, .source = "xhr" });
self._dispatchEvt(typ) catch |err| { self._dispatchEvt(typ) catch |err| {
log.err(.xhr, "dispatch event error", .{ .err = err, .type = typ }); log.err(.app, "dispatch event error", .{ .err = err, .type = typ, .source = "xhr" });
}; };
} }
@@ -354,9 +354,9 @@ pub const XMLHttpRequest = struct {
typ: []const u8, typ: []const u8,
opts: ProgressEvent.EventInit, opts: ProgressEvent.EventInit,
) void { ) void {
log.debug(.xhr, "dispatch progress event", .{ .type = typ }); log.debug(.script_event, "dispatch progress event", .{ .type = typ, .source = "xhr" });
self._dispatchProgressEvent(typ, opts) catch |err| { self._dispatchProgressEvent(typ, opts) catch |err| {
log.err(.xhr, "dispatch progress event error", .{ .err = err, .type = typ }); log.err(.app, "dispatch progress event error", .{ .err = err, .type = typ, .source = "xhr" });
}; };
} }
@@ -419,7 +419,7 @@ pub const XMLHttpRequest = struct {
if (self.state != .opened) return DOMError.InvalidState; if (self.state != .opened) return DOMError.InvalidState;
if (self.send_flag) return DOMError.InvalidState; if (self.send_flag) return DOMError.InvalidState;
log.debug(.xhr, "request", .{ .method = self.method, .url = self.url }); log.debug(.http, "request", .{ .method = self.method, .url = self.url, .source = "xhr" });
self.send_flag = true; self.send_flag = true;
@@ -469,7 +469,11 @@ pub const XMLHttpRequest = struct {
if (progress.first) { if (progress.first) {
const header = progress.header; const header = progress.header;
log.debug(.xhr, "request header", .{ .status = header.status }); log.debug(.http, "request header", .{
.source = "xhr",
.url = self.url,
.status = header.status,
});
for (header.headers.items) |hdr| { for (header.headers.items) |hdr| {
try self.response_headers.append(hdr.name, hdr.value); try self.response_headers.append(hdr.name, hdr.value);
} }
@@ -515,7 +519,8 @@ pub const XMLHttpRequest = struct {
return; return;
} }
log.info(.xhr, "request complete", .{ log.info(.http, "request complete", .{
.source = "xhr",
.url = self.url, .url = self.url,
.status = progress.header.status, .status = progress.header.status,
}); });
@@ -541,7 +546,12 @@ pub const XMLHttpRequest = struct {
self.dispatchProgressEvent("error", .{}); self.dispatchProgressEvent("error", .{});
self.dispatchProgressEvent("loadend", .{}); self.dispatchProgressEvent("loadend", .{});
log.warn(.xhr, "error", .{ .method = self.method, .url = self.url, .err = err }); const level: log.Level = if (err == DOMError.Abort) .debug else .err;
log.log(.http, level, "error", .{
.url = self.url,
.err = err,
.source = "xhr",
});
} }
pub fn _abort(self: *XMLHttpRequest) void { pub fn _abort(self: *XMLHttpRequest) void {
@@ -646,7 +656,7 @@ pub const XMLHttpRequest = struct {
// response object to a new ArrayBuffer object representing thiss // response object to a new ArrayBuffer object representing thiss
// received bytes. If this throws an exception, then set thiss // received bytes. If this throws an exception, then set thiss
// response object to failure and return null. // response object to failure and return null.
log.err(.xhr, "not implemented", .{ .feature = "ArrayBuffer resposne type" }); log.err(.web_api, "not implemented", .{ .feature = "XHR ArrayBuffer resposne type" });
return null; return null;
} }
@@ -655,7 +665,7 @@ pub const XMLHttpRequest = struct {
// response object to a new Blob object representing thiss // response object to a new Blob object representing thiss
// received bytes with type set to the result of get a final MIME // received bytes with type set to the result of get a final MIME
// type for this. // type for this.
log.err(.xhr, "not implemented", .{ .feature = "Blog resposne type" }); log.err(.web_api, "not implemented", .{ .feature = "XHR Blob resposne type" });
return null; return null;
} }
@@ -730,7 +740,7 @@ pub const XMLHttpRequest = struct {
self.response_bytes.items, self.response_bytes.items,
.{}, .{},
) catch |e| { ) catch |e| {
log.warn(.xhr, "invalid json", .{ .err = e }); log.warn(.http, "invalid json", .{ .err = e, .url = self.url, .source = "xhr" });
self.response_obj = .{ .Failure = {} }; self.response_obj = .{ .Failure = {} };
return; return;
}; };

View File

@@ -647,7 +647,7 @@ pub const Request = struct {
// to a GET. // to a GET.
self.method = .GET; self.method = .GET;
} }
log.debug(.http_client, "redirecting", .{ .method = self.method, .url = self.request_uri }); log.debug(.http, "redirecting", .{ .method = self.method, .url = self.request_uri });
if (self.body != null and self.method == .GET) { if (self.body != null and self.method == .GET) {
// If we have a body and the method is a GET, then we must be following // If we have a body and the method is a GET, then we must be following

View File

@@ -18,30 +18,64 @@
const std = @import("std"); const std = @import("std");
const builtin = @import("builtin"); const builtin = @import("builtin");
const build_config = @import("build_config");
const Thread = std.Thread; const Thread = std.Thread;
const Allocator = std.mem.Allocator; const Allocator = std.mem.Allocator;
const log_evel: Level = blk: { const is_debug = builtin.mode == .Debug;
if (builtin.is_test) break :blk .err;
break :blk @enumFromInt(@intFromEnum(build_config.log_level)); pub const Scope = enum {
app,
browser,
cdp,
console,
http,
http_client,
js,
loop,
script_event,
telemetry,
user_script,
unknown_prop,
web_api,
xhr,
}; };
const format: Format = blk: {
if (builtin.is_test or builtin.mode != .Debug) break :blk .logfmt; const Opts = struct {
break :blk .pretty; format: Format = if (is_debug) .pretty else .logfmt,
level: Level = if (is_debug) .info else .warn,
filter_scopes: []const Scope = &.{.unknown_prop},
}; };
pub var opts = Opts{};
// synchronizes writes to the output // synchronizes writes to the output
var out_lock: Thread.Mutex = .{}; var out_lock: Thread.Mutex = .{};
// synchronizes access to last_log // synchronizes access to last_log
var last_log_lock: Thread.Mutex = .{}; var last_log_lock: Thread.Mutex = .{};
pub fn enabled(comptime scope: @Type(.enum_literal), comptime level: Level) bool { pub fn enabled(comptime scope: Scope, level: Level) bool {
// TODO scope disabling if (@intFromEnum(level) < @intFromEnum(opts.level)) {
_ = scope; return false;
return @intFromEnum(level) >= @intFromEnum(log_evel); }
if (comptime builtin.mode == .Debug) {
for (opts.filter_scopes) |fs| {
if (fs == scope) {
return false;
}
}
}
return true;
}
// Ugliness to support complex debug parameters. Could add better support for
// this directly in writeValue, but we [currently] only need this in one place
// and I kind of don't want to encourage / make this easy.
pub fn separator() []const u8 {
return if (opts.format == .pretty) "\n " else "; ";
} }
pub const Level = enum { pub const Level = enum {
@@ -57,28 +91,28 @@ pub const Format = enum {
pretty, pretty,
}; };
pub fn debug(comptime scope: @Type(.enum_literal), comptime msg: []const u8, data: anytype) void { pub fn debug(comptime scope: Scope, comptime msg: []const u8, data: anytype) void {
log(scope, .debug, msg, data); log(scope, .debug, msg, data);
} }
pub fn info(comptime scope: @Type(.enum_literal), comptime msg: []const u8, data: anytype) void { pub fn info(comptime scope: Scope, comptime msg: []const u8, data: anytype) void {
log(scope, .info, msg, data); log(scope, .info, msg, data);
} }
pub fn warn(comptime scope: @Type(.enum_literal), comptime msg: []const u8, data: anytype) void { pub fn warn(comptime scope: Scope, comptime msg: []const u8, data: anytype) void {
log(scope, .warn, msg, data); log(scope, .warn, msg, data);
} }
pub fn err(comptime scope: @Type(.enum_literal), comptime msg: []const u8, data: anytype) void { pub fn err(comptime scope: Scope, comptime msg: []const u8, data: anytype) void {
log(scope, .err, msg, data); log(scope, .err, msg, data);
} }
pub fn fatal(comptime scope: @Type(.enum_literal), comptime msg: []const u8, data: anytype) void { pub fn fatal(comptime scope: Scope, comptime msg: []const u8, data: anytype) void {
log(scope, .fatal, msg, data); log(scope, .fatal, msg, data);
} }
pub fn log(comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: anytype) void { pub fn log(comptime scope: Scope, level: Level, comptime msg: []const u8, data: anytype) void {
if (comptime enabled(scope, level) == false) { if (enabled(scope, level) == false) {
return; return;
} }
@@ -90,14 +124,11 @@ pub fn log(comptime scope: @Type(.enum_literal), comptime level: Level, comptime
}; };
} }
fn logTo(comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: anytype, out: anytype) !void { fn logTo(comptime scope: Scope, level: Level, comptime msg: []const u8, data: anytype, out: anytype) !void {
comptime { comptime {
if (msg.len > 30) { if (msg.len > 30) {
@compileError("log msg cannot be more than 30 characters: '" ++ msg ++ "'"); @compileError("log msg cannot be more than 30 characters: '" ++ msg ++ "'");
} }
if (@tagName(scope).len > 15) {
@compileError("log scope cannot be more than 15 characters: '" ++ @tagName(scope) ++ "'");
}
for (msg) |b| { for (msg) |b| {
switch (b) { switch (b) {
'A'...'Z', 'a'...'z', ' ', '0'...'9', '_', '-', '.', '{', '}' => {}, 'A'...'Z', 'a'...'z', ' ', '0'...'9', '_', '-', '.', '{', '}' => {},
@@ -107,39 +138,41 @@ fn logTo(comptime scope: @Type(.enum_literal), comptime level: Level, comptime m
} }
var bw = std.io.bufferedWriter(out); var bw = std.io.bufferedWriter(out);
switch (format) { switch (opts.format) {
.logfmt => try logLogfmt(scope, level, msg, data, bw.writer()), .logfmt => try logLogfmt(scope, level, msg, data, bw.writer()),
.pretty => try logPretty(scope, level, msg, data, bw.writer()), .pretty => try logPretty(scope, level, msg, data, bw.writer()),
} }
bw.flush() catch return; bw.flush() catch return;
} }
fn logLogfmt(comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: anytype, writer: anytype) !void { fn logLogfmt(comptime scope: Scope, level: Level, comptime msg: []const u8, data: anytype, writer: anytype) !void {
try writer.writeAll("$time="); try writer.writeAll("$time=");
try writer.print("{d}", .{timestamp()}); try writer.print("{d}", .{timestamp()});
try writer.writeAll(" $scope="); try writer.writeAll(" $scope=");
try writer.writeAll(@tagName(scope)); try writer.writeAll(@tagName(scope));
const level_and_msg = comptime blk: { try writer.writeAll(" $level=");
const l = if (level == .err) "error" else @tagName(level); try writer.writeAll(if (level == .err) "error" else @tagName(level));
const full_msg = comptime blk: {
// only wrap msg in quotes if it contains a space // only wrap msg in quotes if it contains a space
const lm = " $level=" ++ l ++ " $msg="; const prefix = " $msg=";
if (std.mem.indexOfScalar(u8, msg, ' ') == null) { if (std.mem.indexOfScalar(u8, msg, ' ') == null) {
break :blk lm ++ msg; break :blk prefix ++ msg;
} }
break :blk lm ++ "\"" ++ msg ++ "\""; break :blk prefix ++ "\"" ++ msg ++ "\"";
}; };
try writer.writeAll(level_and_msg); try writer.writeAll(full_msg);
inline for (@typeInfo(@TypeOf(data)).@"struct".fields) |f| { inline for (@typeInfo(@TypeOf(data)).@"struct".fields) |f| {
const key = " " ++ f.name ++ "="; const key = " " ++ f.name ++ "=";
try writer.writeAll(key); try writer.writeAll(key);
try writeValue(true, @field(data, f.name), writer); try writeValue(.logfmt, @field(data, f.name), writer);
} }
try writer.writeByte('\n'); try writer.writeByte('\n');
} }
fn logPretty(comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: anytype, writer: anytype) !void { fn logPretty(comptime scope: Scope, level: Level, comptime msg: []const u8, data: anytype, writer: anytype) !void {
try writer.writeAll(switch (level) { try writer.writeAll(switch (level) {
.debug => "\x1b[0;36mDEBUG\x1b[0m ", .debug => "\x1b[0;36mDEBUG\x1b[0m ",
.info => "\x1b[0;32mINFO\x1b[0m ", .info => "\x1b[0;32mINFO\x1b[0m ",
@@ -168,18 +201,18 @@ fn logPretty(comptime scope: @Type(.enum_literal), comptime level: Level, compti
inline for (@typeInfo(@TypeOf(data)).@"struct".fields) |f| { inline for (@typeInfo(@TypeOf(data)).@"struct".fields) |f| {
const key = " " ++ f.name ++ " = "; const key = " " ++ f.name ++ " = ";
try writer.writeAll(key); try writer.writeAll(key);
try writeValue(false, @field(data, f.name), writer); try writeValue(.pretty, @field(data, f.name), writer);
try writer.writeByte('\n'); try writer.writeByte('\n');
} }
try writer.writeByte('\n'); try writer.writeByte('\n');
} }
pub fn writeValue(escape_string: bool, value: anytype, writer: anytype) !void { pub fn writeValue(comptime format: Format, value: anytype, writer: anytype) !void {
const T = @TypeOf(value); const T = @TypeOf(value);
switch (@typeInfo(T)) { switch (@typeInfo(T)) {
.optional => { .optional => {
if (value) |v| { if (value) |v| {
return writeValue(escape_string, v, writer); return writeValue(format, v, writer);
} }
return writer.writeAll("null"); return writer.writeAll("null");
}, },
@@ -191,15 +224,15 @@ pub fn writeValue(escape_string: bool, value: anytype, writer: anytype) !void {
}, },
.error_set => return writer.writeAll(@errorName(value)), .error_set => return writer.writeAll(@errorName(value)),
.@"enum" => return writer.writeAll(@tagName(value)), .@"enum" => return writer.writeAll(@tagName(value)),
.array => return writeValue(escape_string, &value, writer), .array => return writeValue(format, &value, writer),
.pointer => |ptr| switch (ptr.size) { .pointer => |ptr| switch (ptr.size) {
.slice => switch (ptr.child) { .slice => switch (ptr.child) {
u8 => return writeString(escape_string, value, writer), u8 => return writeString(format, value, writer),
else => {}, else => {},
}, },
.one => switch (@typeInfo(ptr.child)) { .one => switch (@typeInfo(ptr.child)) {
.array => |arr| if (arr.child == u8) { .array => |arr| if (arr.child == u8) {
return writeString(escape_string, value, writer); return writeString(format, value, writer);
}, },
else => return writer.print("{}", .{value}), else => return writer.print("{}", .{value}),
}, },
@@ -209,11 +242,12 @@ pub fn writeValue(escape_string: bool, value: anytype, writer: anytype) !void {
.@"struct" => return writer.print("{}", .{value}), .@"struct" => return writer.print("{}", .{value}),
else => {}, else => {},
} }
@compileError("cannot log a: " ++ @typeName(T)); @compileError("cannot log a: " ++ @typeName(T));
} }
fn writeString(escape: bool, value: []const u8, writer: anytype) !void { fn writeString(comptime format: Format, value: []const u8, writer: anytype) !void {
if (escape == false) { if (format == .pretty) {
return writer.writeAll(value); return writer.writeAll(value);
} }
@@ -297,8 +331,8 @@ test "log: data" {
defer buf.deinit(testing.allocator); defer buf.deinit(testing.allocator);
{ {
try logTo(.t_scope, .err, "nope", .{}, buf.writer(testing.allocator)); try logTo(.browser, .err, "nope", .{}, buf.writer(testing.allocator));
try testing.expectEqual("$time=1739795092929 $scope=t_scope $level=error $msg=nope\n", buf.items); try testing.expectEqual("$time=1739795092929 $scope=browser $level=error $msg=nope\n", buf.items);
} }
{ {
@@ -306,7 +340,7 @@ test "log: data" {
const string = try testing.allocator.dupe(u8, "spice_must_flow"); const string = try testing.allocator.dupe(u8, "spice_must_flow");
defer testing.allocator.free(string); defer testing.allocator.free(string);
try logTo(.scope_2, .warn, "a msg", .{ try logTo(.http, .warn, "a msg", .{
.cint = 5, .cint = 5,
.cfloat = 3.43, .cfloat = 3.43,
.int = @as(i16, -49), .int = @as(i16, -49),
@@ -321,7 +355,7 @@ test "log: data" {
.level = Level.warn, .level = Level.warn,
}, buf.writer(testing.allocator)); }, buf.writer(testing.allocator));
try testing.expectEqual("$time=1739795092929 $scope=scope_2 $level=warn $msg=\"a msg\" " ++ try testing.expectEqual("$time=1739795092929 $scope=http $level=warn $msg=\"a msg\" " ++
"cint=5 cfloat=3.43 int=-49 float=0.0003232 bt=true bf=false " ++ "cint=5 cfloat=3.43 int=-49 float=0.0003232 bt=true bf=false " ++
"nn=33 n=null lit=over9000! slice=spice_must_flow " ++ "nn=33 n=null lit=over9000! slice=spice_must_flow " ++
"err=Nope level=warn\n", buf.items); "err=Nope level=warn\n", buf.items);
@@ -332,15 +366,15 @@ test "log: string escape" {
var buf: std.ArrayListUnmanaged(u8) = .{}; var buf: std.ArrayListUnmanaged(u8) = .{};
defer buf.deinit(testing.allocator); defer buf.deinit(testing.allocator);
const prefix = "$time=1739795092929 $scope=scope $level=error $msg=test "; const prefix = "$time=1739795092929 $scope=app $level=error $msg=test ";
{ {
try logTo(.scope, .err, "test", .{ .string = "hello world" }, buf.writer(testing.allocator)); try logTo(.app, .err, "test", .{ .string = "hello world" }, buf.writer(testing.allocator));
try testing.expectEqual(prefix ++ "string=\"hello world\"\n", buf.items); try testing.expectEqual(prefix ++ "string=\"hello world\"\n", buf.items);
} }
{ {
buf.clearRetainingCapacity(); buf.clearRetainingCapacity();
try logTo(.scope, .err, "test", .{ .string = "\n \thi \" \" " }, buf.writer(testing.allocator)); try logTo(.app, .err, "test", .{ .string = "\n \thi \" \" " }, buf.writer(testing.allocator));
try testing.expectEqual(prefix ++ "string=\"\\n \thi \\\" \\\" \"\n", buf.items); try testing.expectEqual(prefix ++ "string=\"\\n \thi \\\" \\\" \"\n", buf.items);
} }
} }

View File

@@ -33,7 +33,7 @@ pub fn main() !void {
// allocator // allocator
// - in Debug mode we use the General Purpose Allocator to detect memory leaks // - in Debug mode we use the General Purpose Allocator to detect memory leaks
// - in Release mode we use the c allocator // - in Release mode we use the c allocator
var gpa = std.heap.GeneralPurposeAllocator(.{}){}; var gpa: std.heap.DebugAllocator(.{}) = .init;
const alloc = if (builtin.mode == .Debug) gpa.allocator() else std.heap.c_allocator; const alloc = if (builtin.mode == .Debug) gpa.allocator() else std.heap.c_allocator;
defer if (builtin.mode == .Debug) { defer if (builtin.mode == .Debug) {
@@ -41,7 +41,7 @@ pub fn main() !void {
}; };
run(alloc) catch |err| { run(alloc) catch |err| {
log.fatal(.main, "exit", .{ .err = err }); log.fatal(.app, "exit", .{ .err = err });
std.posix.exit(1); std.posix.exit(1);
}; };
} }
@@ -63,6 +63,16 @@ fn run(alloc: Allocator) !void {
else => {}, else => {},
} }
if (args.logLevel()) |ll| {
log.opts.level = ll;
}
if (args.logFormat()) |lf| {
log.opts.format = lf;
}
if (args.logFilterScopes()) |lfs| {
log.opts.filter_scopes = lfs;
}
const platform = try Platform.init(); const platform = try Platform.init();
defer platform.deinit(); defer platform.deinit();
@@ -76,20 +86,20 @@ fn run(alloc: Allocator) !void {
switch (args.mode) { switch (args.mode) {
.serve => |opts| { .serve => |opts| {
log.debug(.main, "startup", .{ .mode = "serve" }); log.debug(.app, "startup", .{ .mode = "serve" });
const address = std.net.Address.parseIp4(opts.host, opts.port) catch |err| { const address = std.net.Address.parseIp4(opts.host, opts.port) catch |err| {
log.fatal(.main, "server address", .{ .err = err, .host = opts.host, .port = opts.port }); log.fatal(.app, "invalid server address", .{ .err = err, .host = opts.host, .port = opts.port });
return args.printUsageAndExit(false); return args.printUsageAndExit(false);
}; };
const timeout = std.time.ns_per_s * @as(u64, opts.timeout); const timeout = std.time.ns_per_s * @as(u64, opts.timeout);
server.run(app, address, timeout) catch |err| { server.run(app, address, timeout) catch |err| {
log.fatal(.main, "server run", .{ .err = err }); log.fatal(.app, "server run error", .{ .err = err });
return err; return err;
}; };
}, },
.fetch => |opts| { .fetch => |opts| {
log.debug(.main, "startup", .{ .mode = "fetch", .dump = opts.dump, .url = opts.url }); log.debug(.app, "startup", .{ .mode = "fetch", .dump = opts.dump, .url = opts.url });
const url = try @import("url.zig").URL.parse(opts.url, null); const url = try @import("url.zig").URL.parse(opts.url, null);
// browser // browser
@@ -103,11 +113,11 @@ fn run(alloc: Allocator) !void {
_ = page.navigate(url, .{}) catch |err| switch (err) { _ = page.navigate(url, .{}) catch |err| switch (err) {
error.UnsupportedUriScheme, error.UriMissingHost => { error.UnsupportedUriScheme, error.UriMissingHost => {
log.fatal(.main, "fetch invalid URL", .{ .err = err, .url = url }); log.fatal(.app, "invalid fetch URL", .{ .err = err, .url = url });
return args.printUsageAndExit(false); return args.printUsageAndExit(false);
}, },
else => { else => {
log.fatal(.main, "fetch error", .{ .err = err, .url = url }); log.fatal(.app, "fetch error", .{ .err = err, .url = url });
return err; return err;
}, },
}; };
@@ -129,15 +139,36 @@ const Command = struct {
fn tlsVerifyHost(self: *const Command) bool { fn tlsVerifyHost(self: *const Command) bool {
return switch (self.mode) { return switch (self.mode) {
inline .serve, .fetch => |opts| opts.tls_verify_host, inline .serve, .fetch => |opts| opts.common.tls_verify_host,
else => true, else => unreachable,
}; };
} }
fn httpProxy(self: *const Command) ?std.Uri { fn httpProxy(self: *const Command) ?std.Uri {
return switch (self.mode) { return switch (self.mode) {
inline .serve, .fetch => |opts| opts.http_proxy, inline .serve, .fetch => |opts| opts.common.http_proxy,
else => null, else => unreachable,
};
}
fn logLevel(self: *const Command) ?log.Level {
return switch (self.mode) {
inline .serve, .fetch => |opts| opts.common.log_level,
else => unreachable,
};
}
fn logFormat(self: *const Command) ?log.Format {
return switch (self.mode) {
inline .serve, .fetch => |opts| opts.common.log_format,
else => unreachable,
};
}
fn logFilterScopes(self: *const Command) ?[]const log.Scope {
return switch (self.mode) {
inline .serve, .fetch => |opts| opts.common.log_filter_scopes,
else => unreachable,
}; };
} }
@@ -152,18 +183,47 @@ const Command = struct {
host: []const u8, host: []const u8,
port: u16, port: u16,
timeout: u16, timeout: u16,
tls_verify_host: bool, common: Common,
http_proxy: ?std.Uri,
}; };
const Fetch = struct { const Fetch = struct {
url: []const u8, url: []const u8,
dump: bool = false, dump: bool = false,
tls_verify_host: bool, common: Common,
http_proxy: ?std.Uri, };
const Common = struct {
http_proxy: ?std.Uri = null,
tls_verify_host: bool = true,
log_level: ?log.Level = null,
log_format: ?log.Format = null,
log_filter_scopes: ?[]log.Scope = null,
}; };
fn printUsageAndExit(self: *const Command, success: bool) void { fn printUsageAndExit(self: *const Command, success: bool) void {
const common_options =
\\
\\--insecure_disable_tls_host_verification
\\ Disables host verification on all HTTP requests.
\\ This is an advanced option which should only be
\\ set if you understand and accept the risk of
\\ disabling host verification.
\\
\\--http_proxy The HTTP proxy to use for all HTTP requests.
\\ Defaults to none.
\\
\\--log_level The log level: debug, info, warn, error or fatal.
\\ Defaults to
++ (if (builtin.mode == .Debug) " info." else "warn.") ++
\\
\\
\\--log_format The log format: pretty or logfmt.
\\ Defaults to
++ (if (builtin.mode == .Debug) " pretty." else " logfmt.") ++
\\
\\
;
const usage = const usage =
\\usage: {s} command [options] [URL] \\usage: {s} command [options] [URL]
\\ \\
@@ -177,14 +237,7 @@ const Command = struct {
\\--dump Dumps document to stdout. \\--dump Dumps document to stdout.
\\ Defaults to false. \\ Defaults to false.
\\ \\
\\--insecure_disable_tls_host_verification ++ common_options ++
\\ Disables host verification on all HTTP requests.
\\ This is an advanced option which should only be
\\ set if you understand and accept the risk of
\\ disabling host verification.
\\
\\--http_proxy The HTTP proxy to use for all HTTP requests.
\\ Defaults to none.
\\ \\
\\serve command \\serve command
\\Starts a websocket CDP server \\Starts a websocket CDP server
@@ -200,14 +253,7 @@ const Command = struct {
\\--timeout Inactivity timeout in seconds before disconnecting clients \\--timeout Inactivity timeout in seconds before disconnecting clients
\\ Defaults to 3 (seconds) \\ Defaults to 3 (seconds)
\\ \\
\\--insecure_disable_tls_host_verification ++ common_options ++
\\ Disables host verification on all HTTP requests.
\\ This is an advanced option which should only be
\\ set if you understand and accept the risk of
\\ disabling host verification.
\\
\\--http_proxy The HTTP proxy to use for all HTTP requests.
\\ Defaults to none.
\\ \\
\\version command \\version command
\\Displays the version of {s} \\Displays the version of {s}
@@ -293,13 +339,12 @@ fn parseServeArgs(
var host: []const u8 = "127.0.0.1"; var host: []const u8 = "127.0.0.1";
var port: u16 = 9222; var port: u16 = 9222;
var timeout: u16 = 3; var timeout: u16 = 3;
var tls_verify_host = true; var common: Command.Common = .{};
var http_proxy: ?std.Uri = null;
while (args.next()) |opt| { while (args.next()) |opt| {
if (std.mem.eql(u8, "--host", opt)) { if (std.mem.eql(u8, "--host", opt)) {
const str = args.next() orelse { const str = args.next() orelse {
log.fatal(.main, "missing argument value", .{ .arg = "--host" }); log.fatal(.app, "missing argument value", .{ .arg = "--host" });
return error.InvalidArgument; return error.InvalidArgument;
}; };
host = try allocator.dupe(u8, str); host = try allocator.dupe(u8, str);
@@ -308,12 +353,12 @@ fn parseServeArgs(
if (std.mem.eql(u8, "--port", opt)) { if (std.mem.eql(u8, "--port", opt)) {
const str = args.next() orelse { const str = args.next() orelse {
log.fatal(.main, "missing argument value", .{ .arg = "--port" }); log.fatal(.app, "missing argument value", .{ .arg = "--port" });
return error.InvalidArgument; return error.InvalidArgument;
}; };
port = std.fmt.parseInt(u16, str, 10) catch |err| { port = std.fmt.parseInt(u16, str, 10) catch |err| {
log.fatal(.main, "invalid argument value", .{ .arg = "--port", .err = err }); log.fatal(.app, "invalid argument value", .{ .arg = "--port", .err = err });
return error.InvalidArgument; return error.InvalidArgument;
}; };
continue; continue;
@@ -321,40 +366,30 @@ fn parseServeArgs(
if (std.mem.eql(u8, "--timeout", opt)) { if (std.mem.eql(u8, "--timeout", opt)) {
const str = args.next() orelse { const str = args.next() orelse {
log.fatal(.main, "missing argument value", .{ .arg = "--timeout" }); log.fatal(.app, "missing argument value", .{ .arg = "--timeout" });
return error.InvalidArgument; return error.InvalidArgument;
}; };
timeout = std.fmt.parseInt(u16, str, 10) catch |err| { timeout = std.fmt.parseInt(u16, str, 10) catch |err| {
log.fatal(.main, "invalid argument value", .{ .arg = "--timeout", .err = err }); log.fatal(.app, "invalid argument value", .{ .arg = "--timeout", .err = err });
return error.InvalidArgument; return error.InvalidArgument;
}; };
continue; continue;
} }
if (std.mem.eql(u8, "--insecure_disable_tls_host_verification", opt)) { if (try parseCommonArg(allocator, opt, args, &common)) {
tls_verify_host = false;
continue; continue;
} }
if (std.mem.eql(u8, "--http_proxy", opt)) { log.fatal(.app, "unknown argument", .{ .mode = "serve", .arg = opt });
const str = args.next() orelse {
log.fatal(.main, "missing argument value", .{ .arg = "--http_proxy" });
return error.InvalidArgument;
};
http_proxy = try std.Uri.parse(try allocator.dupe(u8, str));
continue;
}
log.fatal(.main, "unknown argument", .{ .mode = "serve", .arg = opt });
return error.UnkownOption; return error.UnkownOption;
} }
return .{ return .{
.host = host, .host = host,
.port = port, .port = port,
.common = common,
.timeout = timeout, .timeout = timeout,
.http_proxy = http_proxy,
.tls_verify_host = tls_verify_host,
}; };
} }
@@ -364,8 +399,7 @@ fn parseFetchArgs(
) !Command.Fetch { ) !Command.Fetch {
var dump: bool = false; var dump: bool = false;
var url: ?[]const u8 = null; var url: ?[]const u8 = null;
var tls_verify_host = true; var common: Command.Common = .{};
var http_proxy: ?std.Uri = null;
while (args.next()) |opt| { while (args.next()) |opt| {
if (std.mem.eql(u8, "--dump", opt)) { if (std.mem.eql(u8, "--dump", opt)) {
@@ -373,45 +407,111 @@ fn parseFetchArgs(
continue; continue;
} }
if (std.mem.eql(u8, "--insecure_disable_tls_host_verification", opt)) { if (try parseCommonArg(allocator, opt, args, &common)) {
tls_verify_host = false;
continue;
}
if (std.mem.eql(u8, "--http_proxy", opt)) {
const str = args.next() orelse {
log.fatal(.main, "missing argument value", .{ .arg = "--http_proxy" });
return error.InvalidArgument;
};
http_proxy = try std.Uri.parse(try allocator.dupe(u8, str));
continue; continue;
} }
if (std.mem.startsWith(u8, opt, "--")) { if (std.mem.startsWith(u8, opt, "--")) {
log.fatal(.main, "unknown argument", .{ .mode = "fetch", .arg = opt }); log.fatal(.app, "unknown argument", .{ .mode = "fetch", .arg = opt });
return error.UnkownOption; return error.UnkownOption;
} }
if (url != null) { if (url != null) {
log.fatal(.main, "duplicate fetch url", .{ .help = "only 1 URL can be specified" }); log.fatal(.app, "duplicate fetch url", .{ .help = "only 1 URL can be specified" });
return error.TooManyURLs; return error.TooManyURLs;
} }
url = try allocator.dupe(u8, opt); url = try allocator.dupe(u8, opt);
} }
if (url == null) { if (url == null) {
log.fatal(.main, "duplicate fetch url", .{ .help = "URL to fetch must be provided" }); log.fatal(.app, "missing fetch url", .{ .help = "URL to fetch must be provided" });
return error.MissingURL; return error.MissingURL;
} }
return .{ return .{
.url = url.?, .url = url.?,
.dump = dump, .dump = dump,
.http_proxy = http_proxy, .common = common,
.tls_verify_host = tls_verify_host,
}; };
} }
fn parseCommonArg(
allocator: Allocator,
opt: []const u8,
args: *std.process.ArgIterator,
common: *Command.Common,
) !bool {
if (std.mem.eql(u8, "--insecure_disable_tls_host_verification", opt)) {
common.tls_verify_host = false;
return true;
}
if (std.mem.eql(u8, "--http_proxy", opt)) {
const str = args.next() orelse {
log.fatal(.app, "missing argument value", .{ .arg = "--http_proxy" });
return error.InvalidArgument;
};
common.http_proxy = try std.Uri.parse(try allocator.dupe(u8, str));
return true;
}
if (std.mem.eql(u8, "--log_level", opt)) {
const str = args.next() orelse {
log.fatal(.app, "missing argument value", .{ .arg = "--log_level" });
return error.InvalidArgument;
};
common.log_level = std.meta.stringToEnum(log.Level, str) orelse blk: {
if (std.mem.eql(u8, str, "error")) {
break :blk .err;
}
log.fatal(.app, "invalid option choice", .{ .arg = "--log_level", .value = str });
return error.InvalidArgument;
};
return true;
}
if (std.mem.eql(u8, "--log_format", opt)) {
const str = args.next() orelse {
log.fatal(.app, "missing argument value", .{ .arg = "--log_format" });
return error.InvalidArgument;
};
common.log_format = std.meta.stringToEnum(log.Format, str) orelse {
log.fatal(.app, "invalid option choice", .{ .arg = "--log_format", .value = str });
return error.InvalidArgument;
};
return true;
}
if (std.mem.eql(u8, "--log_filter_scopes", opt)) {
if (builtin.mode != .Debug) {
log.fatal(.app, "experimental", .{ .help = "log scope filtering is only available in debug builds" });
return false;
}
const str = args.next() orelse {
// disables the default filters
common.log_filter_scopes = &.{};
return true;
};
var arr: std.ArrayListUnmanaged(log.Scope) = .empty;
var it = std.mem.splitScalar(u8, str, ',');
while (it.next()) |part| {
try arr.append(allocator, std.meta.stringToEnum(log.Scope, part) orelse {
log.fatal(.app, "invalid option choice", .{ .arg = "--log_scope_filter", .value = part });
return false;
});
}
common.log_filter_scopes = arr.items;
return true;
}
return false;
}
test { test {
std.testing.refAllDecls(@This()); std.testing.refAllDecls(@This());
} }
@@ -419,6 +519,8 @@ test {
var test_wg: std.Thread.WaitGroup = .{}; var test_wg: std.Thread.WaitGroup = .{};
test "tests:beforeAll" { test "tests:beforeAll" {
try parser.init(); try parser.init();
log.opts.level = .err;
log.opts.format = .logfmt;
test_wg.startMany(3); test_wg.startMany(3);
_ = try Platform.init(); _ = try Platform.init();

View File

@@ -206,9 +206,10 @@ pub const Notification = struct {
const listener = n.data; const listener = n.data;
const func: EventFunc(event) = @alignCast(@ptrCast(listener.func)); const func: EventFunc(event) = @alignCast(@ptrCast(listener.func));
func(listener.receiver, data) catch |err| { func(listener.receiver, data) catch |err| {
log.err(.notification, "dispatch error", .{ log.err(.app, "dispatch error", .{
.err = err, .err = err,
.event = event, .event = event,
.source = "notification",
.listener = listener.struct_name, .listener = listener.struct_name,
}); });
}; };

View File

@@ -1851,7 +1851,7 @@ pub fn Env(comptime State: type, comptime WebApis: type) type {
fn generateNamedIndexer(comptime Struct: type, template_proto: v8.ObjectTemplate) void { fn generateNamedIndexer(comptime Struct: type, template_proto: v8.ObjectTemplate) void {
if (@hasDecl(Struct, "named_get") == false) { if (@hasDecl(Struct, "named_get") == false) {
if (comptime @import("build_config").log_unknown_properties) { if (builtin.mode == .Debug and log.enabled(.unknown_prop, .debug)) {
generateDebugNamedIndexer(Struct, template_proto); generateDebugNamedIndexer(Struct, template_proto);
} }
return; return;
@@ -1899,7 +1899,7 @@ pub fn Env(comptime State: type, comptime WebApis: type) type {
const scope: *Scope = @ptrFromInt(context.getEmbedderData(1).castTo(v8.BigInt).getUint64()); const scope: *Scope = @ptrFromInt(context.getEmbedderData(1).castTo(v8.BigInt).getUint64());
const property = valueToString(scope.call_arena, .{ .handle = c_name.? }, isolate, context) catch "???"; const property = valueToString(scope.call_arena, .{ .handle = c_name.? }, isolate, context) catch "???";
log.debug(.js, "unkown named property", .{ .@"struct" = @typeName(Struct), .property = property }); log.debug(.unknown_prop, "unkown property", .{ .@"struct" = @typeName(Struct), .property = property });
return v8.Intercepted.No; return v8.Intercepted.No;
} }
}.callback, }.callback,
@@ -2635,9 +2635,9 @@ fn Caller(comptime E: type, comptime State: type) type {
const last_js_parameter = params_to_map.len - 1; const last_js_parameter = params_to_map.len - 1;
var is_variadic = false; var is_variadic = false;
errdefer |err| if (log.enabled(.js, .debug)) { errdefer |err| if (builtin.mode == .Debug and log.enabled(.js, .warn)) {
const args_dump = self.dumpFunctionArgs(info) catch "failed to serialize args"; const args_dump = self.serializeFunctionArgs(info) catch "failed to serialize args";
log.debug(.js, "function call error", .{ log.warn(.js, "function call error", .{
.name = named_function.full_name, .name = named_function.full_name,
.err = err, .err = err,
.args = args_dump, .args = args_dump,
@@ -2706,7 +2706,7 @@ fn Caller(comptime E: type, comptime State: type) type {
return T == State or T == Const_State; return T == State or T == Const_State;
} }
fn dumpFunctionArgs(self: *const Self, info: anytype) ![]const u8 { fn serializeFunctionArgs(self: *const Self, info: anytype) ![]const u8 {
const isolate = self.isolate; const isolate = self.isolate;
const context = self.context; const context = self.context;
const arena = self.call_arena; const arena = self.call_arena;
@@ -2717,7 +2717,12 @@ fn Caller(comptime E: type, comptime State: type) type {
const js_value = info.getArg(@intCast(i)); const js_value = info.getArg(@intCast(i));
const value_string = try valueToDetailString(arena, js_value, isolate, context); const value_string = try valueToDetailString(arena, js_value, isolate, context);
const value_type = try jsStringToZig(arena, try js_value.typeOf(isolate), isolate); const value_type = try jsStringToZig(arena, try js_value.typeOf(isolate), isolate);
try std.fmt.format(arr.writer(arena), "{d}: {s} ({s})\n", .{ i + 1, value_string, value_type }); try std.fmt.format(arr.writer(arena), "{s}{d}: {s} ({s})", .{
log.separator(),
i + 1,
value_string,
value_type,
});
} }
return arr.items; return arr.items;
} }

View File

@@ -66,7 +66,7 @@ const Server = struct {
} }
fn queueAccept(self: *Server) void { fn queueAccept(self: *Server) void {
log.debug(.server, "accepting connection", .{}); log.debug(.app, "accepting connection", .{});
self.loop.io.accept( self.loop.io.accept(
*Server, *Server,
self, self,
@@ -83,7 +83,7 @@ const Server = struct {
) void { ) void {
std.debug.assert(completion == &self.accept_completion); std.debug.assert(completion == &self.accept_completion);
self.doCallbackAccept(result) catch |err| { self.doCallbackAccept(result) catch |err| {
log.err(.server, "accept error", .{ .err = err }); log.err(.app, "server accept error", .{ .err = err });
self.queueAccept(); self.queueAccept();
}; };
} }
@@ -97,11 +97,11 @@ const Server = struct {
client.* = Client.init(socket, self); client.* = Client.init(socket, self);
client.start(); client.start();
if (log.enabled(.server, .info)) { if (log.enabled(.app, .info)) {
var address: std.net.Address = undefined; var address: std.net.Address = undefined;
var socklen: posix.socklen_t = @sizeOf(net.Address); var socklen: posix.socklen_t = @sizeOf(net.Address);
try std.posix.getsockname(socket, &address.any, &socklen); try std.posix.getsockname(socket, &address.any, &socklen);
log.info(.server, "client connected", .{ .ip = address }); log.info(.app, "client connected", .{ .ip = address });
} }
} }
@@ -223,7 +223,7 @@ pub const Client = struct {
} }
fn close(self: *Self) void { fn close(self: *Self) void {
log.info(.server, "client disconected", .{}); log.info(.app, "client disconected", .{});
self.connected = false; self.connected = false;
// recv only, because we might have pending writes we'd like to get // recv only, because we might have pending writes we'd like to get
// out (like the HTTP error response) // out (like the HTTP error response)
@@ -256,7 +256,7 @@ pub const Client = struct {
} }
const size = result catch |err| { const size = result catch |err| {
log.err(.server, "read error", .{ .err = err }); log.err(.app, "server read error", .{ .err = err });
self.close(); self.close();
return; return;
}; };
@@ -319,7 +319,7 @@ pub const Client = struct {
error.InvalidVersionHeader => self.writeHTTPErrorResponse(400, "Invalid websocket version"), error.InvalidVersionHeader => self.writeHTTPErrorResponse(400, "Invalid websocket version"),
error.InvalidConnectionHeader => self.writeHTTPErrorResponse(400, "Invalid connection header"), error.InvalidConnectionHeader => self.writeHTTPErrorResponse(400, "Invalid connection header"),
else => { else => {
log.err(.server, "http 500", .{ .err = err }); log.err(.app, "server 500", .{ .err = err, .req = request[0..@min(100, request.len)] });
self.writeHTTPErrorResponse(500, "Internal Server Error"); self.writeHTTPErrorResponse(500, "Internal Server Error");
}, },
} }
@@ -600,7 +600,7 @@ pub const Client = struct {
if (result) |_| { if (result) |_| {
if (now().since(self.last_active) >= self.server.timeout) { if (now().since(self.last_active) >= self.server.timeout) {
log.info(.server, "connection timeout", .{}); log.info(.app, "client connection timeout", .{});
if (self.mode == .websocket) { if (self.mode == .websocket) {
self.send(null, &CLOSE_TIMEOUT) catch {}; self.send(null, &CLOSE_TIMEOUT) catch {};
} }
@@ -608,7 +608,7 @@ pub const Client = struct {
return; return;
} }
} else |err| { } else |err| {
log.err(.server, "timeout error", .{ .err = err }); log.err(.app, "server timeout error", .{ .err = err });
} }
self.queueTimeout(); self.queueTimeout();
@@ -657,7 +657,7 @@ pub const Client = struct {
} }
const sent = result catch |err| { const sent = result catch |err| {
log.warn(.server, "send error", .{ .err = err }); log.warn(.app, "server send error", .{ .err = err });
self.close(); self.close();
return; return;
}; };
@@ -1043,7 +1043,7 @@ pub fn run(
// accept an connection // accept an connection
server.queueAccept(); server.queueAccept();
log.info(.server, "running", .{ .address = address }); log.info(.app, "server running", .{ .address = address });
// infinite loop on I/O events, either: // infinite loop on I/O events, either:
// - cmd from incoming connection on server socket // - cmd from incoming connection on server socket