diff --git a/build.zig b/build.zig index 65c3bef6..6f3906f3 100644 --- a/build.zig +++ b/build.zig @@ -44,21 +44,6 @@ pub fn build(b: *std.Build) !void { 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 optimize = b.standardOptimizeOption(.{}); diff --git a/src/browser/console/console.zig b/src/browser/console/console.zig index 1edbc612..2d857103 100644 --- a/src/browser/console/console.zig +++ b/src/browser/console/console.zig @@ -278,7 +278,7 @@ const TestCapture = struct { inline for (@typeInfo(@TypeOf(args)).@"struct".fields) |f| { try buf.appendSlice(allocator, f.name); 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, ' '); } self.captured.append(testing.arena_allocator, std.mem.trimRight(u8, buf.items, " ")) catch unreachable; diff --git a/src/browser/dom/element.zig b/src/browser/dom/element.zig index c3a7e545..f640686d 100644 --- a/src/browser/dom/element.zig +++ b/src/browser/dom/element.zig @@ -147,7 +147,7 @@ pub const Element = struct { while (true) { if (try select.match(current)) { 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 parser.nodeToElement(current.node); diff --git a/src/browser/dom/intersection_observer.zig b/src/browser/dom/intersection_observer.zig index 12de3bae..c14c5faa 100644 --- a/src/browser/dom/intersection_observer.zig +++ b/src/browser/dom/intersection_observer.zig @@ -86,7 +86,11 @@ pub const IntersectionObserver = struct { var result: Env.Function.Result = undefined; 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", + }); }; } diff --git a/src/browser/dom/mutation_observer.zig b/src/browser/dom/mutation_observer.zig index c651c851..f5394ba8 100644 --- a/src/browser/dom/mutation_observer.zig +++ b/src/browser/dom/mutation_observer.zig @@ -114,7 +114,11 @@ pub const MutationObserver = struct { const records = [_]MutationRecord{r.*}; var result: Env.Function.Result = undefined; 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 { const self: *Observer = @fieldParentPtr("event_node", en); self._handle(event) catch |err| { - log.err(.mut_obs, "handle error", .{ .err = err }); + log.err(.web_api, "handle error", .{ .err = err, .source = "mutation observer" }); }; } diff --git a/src/browser/dom/node.zig b/src/browser/dom/node.zig index 90ee72d0..78a9e1f0 100644 --- a/src/browser/dom/node.zig +++ b/src/browser/dom/node.zig @@ -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 pub fn _getRootNode(self: *parser.Node, options: ?struct { composed: bool = false }) !Union { 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)); } diff --git a/src/browser/dom/nodelist.zig b/src/browser/dom/nodelist.zig index 602419ec..56194c2f 100644 --- a/src/browser/dom/nodelist.zig +++ b/src/browser/dom/nodelist.zig @@ -145,7 +145,7 @@ pub const NodeList = struct { const ii: u32 = @intCast(i); var result: Function.Result = undefined; 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 }); }; } } diff --git a/src/browser/dom/token_list.zig b/src/browser/dom/token_list.zig index 532b9109..6f12c406 100644 --- a/src/browser/dom/token_list.zig +++ b/src/browser/dom/token_list.zig @@ -142,7 +142,11 @@ pub const DOMTokenList = struct { while (try entries._next()) |entry| { var result: Function.Result = undefined; 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", + }); }; } } diff --git a/src/browser/events/event.zig b/src/browser/events/event.zig index fcbede39..1a75f116 100644 --- a/src/browser/events/event.zig +++ b/src/browser/events/event.zig @@ -237,14 +237,18 @@ pub const EventHandler = struct { fn handle(node: *parser.EventNode, event: *parser.Event) void { const ievent = Event.toInterface(event) catch |err| { - log.err(.event, "toInterface error", .{ .err = err }); + log.err(.app, "toInterface error", .{ .err = err }); return; }; const self: *EventHandler = @fieldParentPtr("node", node); var result: Function.Result = undefined; 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) { diff --git a/src/browser/html/document.zig b/src/browser/html/document.zig index 85926a65..5c74fe7e 100644 --- a/src/browser/html/document.zig +++ b/src/browser/html/document.zig @@ -18,6 +18,7 @@ const std = @import("std"); +const log = @import("../../log.zig"); const parser = @import("../netsurf.zig"); const Page = @import("../page.zig").Page; @@ -276,6 +277,10 @@ pub const HTMLDocument = struct { const evt = try parser.eventCreate(); 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.eventTargetDispatchEvent(parser.toEventTarget(parser.DocumentHTML, html_doc), evt); } diff --git a/src/browser/html/window.zig b/src/browser/html/window.zig index afc27410..bd28ed49 100644 --- a/src/browser/html/window.zig +++ b/src/browser/html/window.zig @@ -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. var result: Function.Result = undefined; 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. } @@ -215,7 +219,7 @@ pub const Window = struct { fn createTimeout(self: *Window, cbk: Function, delay_: ?u32, page: *Page, comptime repeat: bool) !u32 { const delay = delay_ orelse 0; 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 // 1_073_741_824. Returning 2_000_000_000 makes sure that clients // can call cancelTimer/cancelInterval without breaking anything. @@ -288,7 +292,11 @@ const TimerCallback = struct { var result: Function.Result = undefined; 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| { diff --git a/src/browser/page.zig b/src/browser/page.zig index 3e05d577..5366fb7a 100644 --- a/src/browser/page.zig +++ b/src/browser/page.zig @@ -164,12 +164,12 @@ pub const Page = struct { try self.session.browser.app.loop.run(); if (try_catch.hasCaught() == false) { - log.debug(.page, "wait complete", .{}); + log.debug(.browser, "page wait complete", .{}); return; } 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 { @@ -184,7 +184,7 @@ pub const Page = struct { const session = self.session; 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 (std.mem.eql(u8, "about:blank", request_url.raw)) { @@ -233,7 +233,7 @@ pub const Page = struct { break :blk Mime.sniff(try response.peek()); } orelse .unknown; - log.info(.page, "navigation", .{ + log.info(.http, "navigation", .{ .status = header.status, .content_type = content_type, .charset = mime.charset, @@ -257,7 +257,9 @@ pub const Page = struct { .url = &self.url, .timestamp = timestamp(), }); - log.debug(.page, "navigation complete", .{}); + log.debug(.http, "navigation complete", .{ + .url = request_url, + }); } // https://html.spec.whatwg.org/#read-html @@ -383,6 +385,7 @@ pub const Page = struct { const loadevt = try parser.eventCreate(); defer parser.eventDestroy(loadevt); + log.debug(.script_event, "dispatch event", .{ .type = "load", .source = "page" }); try parser.eventInit(loadevt, "load", .{}); _ = try parser.eventTargetDispatchEvent( parser.toEventTarget(Window, &self.window), @@ -392,7 +395,7 @@ pub const Page = struct { fn evalScript(self: *Page, script: *const Script) void { 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)); 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 { @@ -457,8 +460,8 @@ pub const Page = struct { var origin_url = &self.url; const url = try origin_url.resolve(arena, res_src); - log.debug(.page, "fetching script", .{ .url = url }); - errdefer |err| log.err(.page, "fetch error", .{ .err = err, .url = url }); + log.debug(.http, "fetching script", .{ .url = url }); + errdefer |err| log.err(.http, "fetch error", .{ .err = err, .url = url }); var request = try self.newHTTPRequest(.GET, &url, .{ .origin_uri = &origin_url.uri, @@ -486,7 +489,7 @@ pub const Page = struct { return null; } - log.info(.page, "fetch complete", .{ + log.info(.http, "fetch complete", .{ .url = url, .status = header.status, .content_length = arr.items.len, @@ -542,7 +545,7 @@ pub const Page = struct { fn windowClicked(node: *parser.EventNode, event: *parser.Event) void { const self: *Page = @fieldParentPtr("window_clicked_event_node", node); 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; const self: *DelayedNavigation = @fieldParentPtr("navigate_node", node); 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)) { .value => |v| break :blk v, .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; }, } }, } catch { 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); return error.JsErr; @@ -811,7 +817,7 @@ const Script = struct { defer try_catch.deinit(); _ = page.scope.exec(str, typ) catch { if (try try_catch.err(page.arena)) |msg| { - log.warn(.page, "script callback", .{ + log.warn(.user_script, "script callback", .{ .src = self.src, .err = msg, .type = typ, @@ -827,7 +833,7 @@ const Script = struct { var result: Env.Function.Result = undefined; f.tryCall(void, .{try Event.toInterface(loadevt)}, &result) catch { - log.warn(.page, "script callback", .{ + log.warn(.user_script, "script callback", .{ .src = self.src, .type = typ, .err = result.exception, @@ -869,7 +875,7 @@ fn timestamp() u32 { pub export fn scriptAddedCallback(ctx: ?*anyopaque, element: ?*parser.Element) callconv(.C) void { const self: *Page = @alignCast(@ptrCast(ctx.?)); 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; } orelse return; diff --git a/src/browser/polyfill/polyfill.zig b/src/browser/polyfill/polyfill.zig index 03175b12..5fc41c5d 100644 --- a/src/browser/polyfill/polyfill.zig +++ b/src/browser/polyfill/polyfill.zig @@ -39,7 +39,7 @@ pub fn load(allocator: Allocator, scope: *Env.Scope) !void { _ = scope.exec(m.source, m.name) catch |err| { if (try try_catch.err(allocator)) |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; }; diff --git a/src/browser/session.zig b/src/browser/session.zig index 532a3907..edc818db 100644 --- a/src/browser/session.zig +++ b/src/browser/session.zig @@ -95,7 +95,7 @@ pub const Session = struct { const page = &self.page.?; try Page.init(page, page_arena.allocator(), self); - log.debug(.session, "create page", .{}); + log.debug(.browser, "create page", .{}); // start JS env // 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); @@ -116,7 +116,7 @@ pub const Session = struct { // clear netsurf memory arena. parser.deinit(); - log.debug(.session, "remove page", .{}); + log.debug(.browser, "remove page", .{}); } pub fn currentPage(self: *Session) ?*Page { diff --git a/src/browser/storage/cookie.zig b/src/browser/storage/cookie.zig index c944e8f9..bdd93e3f 100644 --- a/src/browser/storage/cookie.zig +++ b/src/browser/storage/cookie.zig @@ -155,7 +155,7 @@ pub const Jar = struct { var it = header.iterate("set-cookie"); while (it.next()) |set_cookie| { 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; }; try self.add(c, now); diff --git a/src/browser/xhr/form_data.zig b/src/browser/xhr/form_data.zig index ed9e1ebe..25f31bb5 100644 --- a/src/browser/xhr/form_data.zig +++ b/src/browser/xhr/form_data.zig @@ -148,7 +148,7 @@ pub const FormData = struct { 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; } }; @@ -334,7 +334,7 @@ fn collectForm(form: *parser.Form, submitter_: ?*parser.ElementHTML, page: *Page } }, else => { - log.warn(.form_data, "unsupported element", .{ .tag = @tagName(tag) }); + log.warn(.web_api, "unsupported form element", .{ .tag = @tagName(tag) }); continue; }, } diff --git a/src/browser/xhr/xhr.zig b/src/browser/xhr/xhr.zig index 04cecb72..d65f9db8 100644 --- a/src/browser/xhr/xhr.zig +++ b/src/browser/xhr/xhr.zig @@ -334,9 +334,9 @@ pub const XMLHttpRequest = struct { // dispatch request event. // errors are logged only. 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| { - 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, opts: ProgressEvent.EventInit, ) 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| { - 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.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; @@ -469,7 +469,11 @@ pub const XMLHttpRequest = struct { if (progress.first) { 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| { try self.response_headers.append(hdr.name, hdr.value); } @@ -515,7 +519,8 @@ pub const XMLHttpRequest = struct { return; } - log.info(.xhr, "request complete", .{ + log.info(.http, "request complete", .{ + .source = "xhr", .url = self.url, .status = progress.header.status, }); @@ -541,7 +546,12 @@ pub const XMLHttpRequest = struct { self.dispatchProgressEvent("error", .{}); 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 { @@ -646,7 +656,7 @@ pub const XMLHttpRequest = struct { // response object to a new ArrayBuffer object representing this’s // received bytes. If this throws an exception, then set this’s // 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; } @@ -655,7 +665,7 @@ pub const XMLHttpRequest = struct { // response object to a new Blob object representing this’s // received bytes with type set to the result of get a final MIME // 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; } @@ -730,7 +740,7 @@ pub const XMLHttpRequest = struct { self.response_bytes.items, .{}, ) 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 = {} }; return; }; diff --git a/src/http/client.zig b/src/http/client.zig index 4aba5fb2..81b11cd7 100644 --- a/src/http/client.zig +++ b/src/http/client.zig @@ -647,7 +647,7 @@ pub const Request = struct { // to a 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 we have a body and the method is a GET, then we must be following diff --git a/src/log.zig b/src/log.zig index 51764ee9..2bc15e12 100644 --- a/src/log.zig +++ b/src/log.zig @@ -18,30 +18,64 @@ const std = @import("std"); const builtin = @import("builtin"); -const build_config = @import("build_config"); const Thread = std.Thread; const Allocator = std.mem.Allocator; -const log_evel: Level = blk: { - if (builtin.is_test) break :blk .err; - break :blk @enumFromInt(@intFromEnum(build_config.log_level)); +const is_debug = builtin.mode == .Debug; + +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; - break :blk .pretty; + +const Opts = struct { + 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 var out_lock: Thread.Mutex = .{}; // synchronizes access to last_log var last_log_lock: Thread.Mutex = .{}; -pub fn enabled(comptime scope: @Type(.enum_literal), comptime level: Level) bool { - // TODO scope disabling - _ = scope; - return @intFromEnum(level) >= @intFromEnum(log_evel); +pub fn enabled(comptime scope: Scope, level: Level) bool { + if (@intFromEnum(level) < @intFromEnum(opts.level)) { + return false; + } + + 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 { @@ -57,28 +91,28 @@ pub const Format = enum { 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); } -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); } -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); } -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); } -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); } -pub fn log(comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: anytype) void { - if (comptime enabled(scope, level) == false) { +pub fn log(comptime scope: Scope, level: Level, comptime msg: []const u8, data: anytype) void { + if (enabled(scope, level) == false) { 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 { if (msg.len > 30) { @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| { switch (b) { '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); - switch (format) { + switch (opts.format) { .logfmt => try logLogfmt(scope, level, msg, data, bw.writer()), .pretty => try logPretty(scope, level, msg, data, bw.writer()), } 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.print("{d}", .{timestamp()}); try writer.writeAll(" $scope="); try writer.writeAll(@tagName(scope)); - const level_and_msg = comptime blk: { - const l = if (level == .err) "error" else @tagName(level); + try writer.writeAll(" $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 - const lm = " $level=" ++ l ++ " $msg="; + const prefix = " $msg="; 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| { const key = " " ++ f.name ++ "="; try writer.writeAll(key); - try writeValue(true, @field(data, f.name), writer); + try writeValue(.logfmt, @field(data, f.name), writer); } 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) { .debug => "\x1b[0;36mDEBUG\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| { const key = " " ++ f.name ++ " = "; 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'); } -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); switch (@typeInfo(T)) { .optional => { if (value) |v| { - return writeValue(escape_string, v, writer); + return writeValue(format, v, writer); } 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)), .@"enum" => return writer.writeAll(@tagName(value)), - .array => return writeValue(escape_string, &value, writer), + .array => return writeValue(format, &value, writer), .pointer => |ptr| switch (ptr.size) { .slice => switch (ptr.child) { - u8 => return writeString(escape_string, value, writer), + u8 => return writeString(format, value, writer), else => {}, }, .one => switch (@typeInfo(ptr.child)) { .array => |arr| if (arr.child == u8) { - return writeString(escape_string, value, writer); + return writeString(format, value, writer); }, 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}), else => {}, } + @compileError("cannot log a: " ++ @typeName(T)); } -fn writeString(escape: bool, value: []const u8, writer: anytype) !void { - if (escape == false) { +fn writeString(comptime format: Format, value: []const u8, writer: anytype) !void { + if (format == .pretty) { return writer.writeAll(value); } @@ -297,8 +331,8 @@ test "log: data" { defer buf.deinit(testing.allocator); { - try logTo(.t_scope, .err, "nope", .{}, buf.writer(testing.allocator)); - try testing.expectEqual("$time=1739795092929 $scope=t_scope $level=error $msg=nope\n", buf.items); + try logTo(.browser, .err, "nope", .{}, buf.writer(testing.allocator)); + 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"); defer testing.allocator.free(string); - try logTo(.scope_2, .warn, "a msg", .{ + try logTo(.http, .warn, "a msg", .{ .cint = 5, .cfloat = 3.43, .int = @as(i16, -49), @@ -321,7 +355,7 @@ test "log: data" { .level = Level.warn, }, 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 " ++ "nn=33 n=null lit=over9000! slice=spice_must_flow " ++ "err=Nope level=warn\n", buf.items); @@ -332,15 +366,15 @@ test "log: string escape" { var buf: std.ArrayListUnmanaged(u8) = .{}; 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); } { 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); } } diff --git a/src/main.zig b/src/main.zig index 765523ec..753e84fa 100644 --- a/src/main.zig +++ b/src/main.zig @@ -33,7 +33,7 @@ pub fn main() !void { // allocator // - in Debug mode we use the General Purpose Allocator to detect memory leaks // - 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; defer if (builtin.mode == .Debug) { @@ -41,7 +41,7 @@ pub fn main() !void { }; run(alloc) catch |err| { - log.fatal(.main, "exit", .{ .err = err }); + log.fatal(.app, "exit", .{ .err = err }); std.posix.exit(1); }; } @@ -63,6 +63,16 @@ fn run(alloc: Allocator) !void { 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(); defer platform.deinit(); @@ -76,20 +86,20 @@ fn run(alloc: Allocator) !void { switch (args.mode) { .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| { - 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); }; const timeout = std.time.ns_per_s * @as(u64, opts.timeout); server.run(app, address, timeout) catch |err| { - log.fatal(.main, "server run", .{ .err = err }); + log.fatal(.app, "server run error", .{ .err = err }); return err; }; }, .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); // browser @@ -103,11 +113,11 @@ fn run(alloc: Allocator) !void { _ = page.navigate(url, .{}) catch |err| switch (err) { 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); }, else => { - log.fatal(.main, "fetch error", .{ .err = err, .url = url }); + log.fatal(.app, "fetch error", .{ .err = err, .url = url }); return err; }, }; @@ -129,15 +139,36 @@ const Command = struct { fn tlsVerifyHost(self: *const Command) bool { return switch (self.mode) { - inline .serve, .fetch => |opts| opts.tls_verify_host, - else => true, + inline .serve, .fetch => |opts| opts.common.tls_verify_host, + else => unreachable, }; } fn httpProxy(self: *const Command) ?std.Uri { return switch (self.mode) { - inline .serve, .fetch => |opts| opts.http_proxy, - else => null, + inline .serve, .fetch => |opts| opts.common.http_proxy, + 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, port: u16, timeout: u16, - tls_verify_host: bool, - http_proxy: ?std.Uri, + common: Common, }; const Fetch = struct { url: []const u8, dump: bool = false, - tls_verify_host: bool, - http_proxy: ?std.Uri, + common: Common, + }; + + 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 { + 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 = \\usage: {s} command [options] [URL] \\ @@ -177,14 +237,7 @@ const Command = struct { \\--dump Dumps document to stdout. \\ Defaults to false. \\ - \\--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. + ++ common_options ++ \\ \\serve command \\Starts a websocket CDP server @@ -200,14 +253,7 @@ const Command = struct { \\--timeout Inactivity timeout in seconds before disconnecting clients \\ Defaults to 3 (seconds) \\ - \\--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. + ++ common_options ++ \\ \\version command \\Displays the version of {s} @@ -293,13 +339,12 @@ fn parseServeArgs( var host: []const u8 = "127.0.0.1"; var port: u16 = 9222; var timeout: u16 = 3; - var tls_verify_host = true; - var http_proxy: ?std.Uri = null; + var common: Command.Common = .{}; while (args.next()) |opt| { if (std.mem.eql(u8, "--host", opt)) { const str = args.next() orelse { - log.fatal(.main, "missing argument value", .{ .arg = "--host" }); + log.fatal(.app, "missing argument value", .{ .arg = "--host" }); return error.InvalidArgument; }; host = try allocator.dupe(u8, str); @@ -308,12 +353,12 @@ fn parseServeArgs( if (std.mem.eql(u8, "--port", opt)) { const str = args.next() orelse { - log.fatal(.main, "missing argument value", .{ .arg = "--port" }); + log.fatal(.app, "missing argument value", .{ .arg = "--port" }); return error.InvalidArgument; }; 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; }; continue; @@ -321,40 +366,30 @@ fn parseServeArgs( if (std.mem.eql(u8, "--timeout", opt)) { const str = args.next() orelse { - log.fatal(.main, "missing argument value", .{ .arg = "--timeout" }); + log.fatal(.app, "missing argument value", .{ .arg = "--timeout" }); return error.InvalidArgument; }; 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; }; continue; } - if (std.mem.eql(u8, "--insecure_disable_tls_host_verification", opt)) { - tls_verify_host = false; + if (try parseCommonArg(allocator, opt, args, &common)) { 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; - } - log.fatal(.main, "unknown argument", .{ .mode = "serve", .arg = opt }); + log.fatal(.app, "unknown argument", .{ .mode = "serve", .arg = opt }); return error.UnkownOption; } return .{ .host = host, .port = port, + .common = common, .timeout = timeout, - .http_proxy = http_proxy, - .tls_verify_host = tls_verify_host, }; } @@ -364,8 +399,7 @@ fn parseFetchArgs( ) !Command.Fetch { var dump: bool = false; var url: ?[]const u8 = null; - var tls_verify_host = true; - var http_proxy: ?std.Uri = null; + var common: Command.Common = .{}; while (args.next()) |opt| { if (std.mem.eql(u8, "--dump", opt)) { @@ -373,45 +407,111 @@ fn parseFetchArgs( continue; } - if (std.mem.eql(u8, "--insecure_disable_tls_host_verification", opt)) { - 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)); + if (try parseCommonArg(allocator, opt, args, &common)) { continue; } 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; } 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; } url = try allocator.dupe(u8, opt); } 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 .{ .url = url.?, .dump = dump, - .http_proxy = http_proxy, - .tls_verify_host = tls_verify_host, + .common = common, }; } +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 { std.testing.refAllDecls(@This()); } @@ -419,6 +519,8 @@ test { var test_wg: std.Thread.WaitGroup = .{}; test "tests:beforeAll" { try parser.init(); + log.opts.level = .err; + log.opts.format = .logfmt; test_wg.startMany(3); _ = try Platform.init(); diff --git a/src/notification.zig b/src/notification.zig index 8ccce0a3..5cb198f7 100644 --- a/src/notification.zig +++ b/src/notification.zig @@ -206,9 +206,10 @@ pub const Notification = struct { const listener = n.data; const func: EventFunc(event) = @alignCast(@ptrCast(listener.func)); func(listener.receiver, data) catch |err| { - log.err(.notification, "dispatch error", .{ + log.err(.app, "dispatch error", .{ .err = err, .event = event, + .source = "notification", .listener = listener.struct_name, }); }; diff --git a/src/runtime/js.zig b/src/runtime/js.zig index 7165e360..9e10a2c8 100644 --- a/src/runtime/js.zig +++ b/src/runtime/js.zig @@ -1851,7 +1851,7 @@ pub fn Env(comptime State: type, comptime WebApis: type) type { fn generateNamedIndexer(comptime Struct: type, template_proto: v8.ObjectTemplate) void { 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); } 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 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; } }.callback, @@ -2635,9 +2635,9 @@ 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 (log.enabled(.js, .debug)) { - const args_dump = self.dumpFunctionArgs(info) catch "failed to serialize args"; - log.debug(.js, "function call error", .{ + 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, @@ -2706,7 +2706,7 @@ fn Caller(comptime E: type, comptime State: type) type { 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 context = self.context; 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 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), "{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; } diff --git a/src/server.zig b/src/server.zig index f365da0d..a14ff305 100644 --- a/src/server.zig +++ b/src/server.zig @@ -66,7 +66,7 @@ const Server = struct { } fn queueAccept(self: *Server) void { - log.debug(.server, "accepting connection", .{}); + log.debug(.app, "accepting connection", .{}); self.loop.io.accept( *Server, self, @@ -83,7 +83,7 @@ const Server = struct { ) void { std.debug.assert(completion == &self.accept_completion); self.doCallbackAccept(result) catch |err| { - log.err(.server, "accept error", .{ .err = err }); + log.err(.app, "server accept error", .{ .err = err }); self.queueAccept(); }; } @@ -97,11 +97,11 @@ const Server = struct { client.* = Client.init(socket, self); client.start(); - if (log.enabled(.server, .info)) { + if (log.enabled(.app, .info)) { var address: std.net.Address = undefined; var socklen: posix.socklen_t = @sizeOf(net.Address); 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 { - log.info(.server, "client disconected", .{}); + log.info(.app, "client disconected", .{}); self.connected = false; // recv only, because we might have pending writes we'd like to get // out (like the HTTP error response) @@ -256,7 +256,7 @@ pub const Client = struct { } const size = result catch |err| { - log.err(.server, "read error", .{ .err = err }); + log.err(.app, "server read error", .{ .err = err }); self.close(); return; }; @@ -319,7 +319,7 @@ pub const Client = struct { error.InvalidVersionHeader => self.writeHTTPErrorResponse(400, "Invalid websocket version"), error.InvalidConnectionHeader => self.writeHTTPErrorResponse(400, "Invalid connection header"), 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"); }, } @@ -600,7 +600,7 @@ pub const Client = struct { if (result) |_| { if (now().since(self.last_active) >= self.server.timeout) { - log.info(.server, "connection timeout", .{}); + log.info(.app, "client connection timeout", .{}); if (self.mode == .websocket) { self.send(null, &CLOSE_TIMEOUT) catch {}; } @@ -608,7 +608,7 @@ pub const Client = struct { return; } } else |err| { - log.err(.server, "timeout error", .{ .err = err }); + log.err(.app, "server timeout error", .{ .err = err }); } self.queueTimeout(); @@ -657,7 +657,7 @@ pub const Client = struct { } const sent = result catch |err| { - log.warn(.server, "send error", .{ .err = err }); + log.warn(.app, "server send error", .{ .err = err }); self.close(); return; }; @@ -1043,7 +1043,7 @@ pub fn run( // accept an connection server.queueAccept(); - log.info(.server, "running", .{ .address = address }); + log.info(.app, "server running", .{ .address = address }); // infinite loop on I/O events, either: // - cmd from incoming connection on server socket