public/browser
1
0
Fork 0
mirror of https://github.com/lightpanda-io/browser.git synced 2025-10-29 07:03:29 +00:00
Code Issues Actions 4 Packages Projects Releases Wiki Activity

Replace std.log with a structured logger

Browse Source 
Outputs in logfmt in release and a "pretty" print in debug mode. The format
along with the log level will become arguments to the binary at some point in
the future.
This commit is contained in:
Karl Seguin
2025-05-25 19:23:53 +08:00
parent e9920caa69
commit 2feba3182a
31 changed files with 792 additions and 325 deletions
Download Patch File Download Diff File Expand all files Collapse all files

7
build.zig
View File

@@ -44,11 +44,14 @@ 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(
std.log.Level,
log.Level,
"log_level",
b.option(std.log.Level, "log_level", "The log level") orelse std.log.Level.info,
b.option(log.Level, "log_level", "The log level") orelse .info,
);
}
opts.addOption(
bool,

7
src/app.zig
View File

@@ -1,13 +1,12 @@
const std = @import("std");
const Allocator = std.mem.Allocator;
const log = @import("log.zig");
const Loop = @import("runtime/loop.zig").Loop;
const HttpClient = @import("http/client.zig").Client;
const Telemetry = @import("telemetry/telemetry.zig").Telemetry;
const Notification = @import("notification.zig").Notification;
const log = std.log.scoped(.app);
// Container for global state / objects that various parts of the system
// might need.
pub const App = struct {
@@ -84,7 +83,7 @@ fn getAndMakeAppDir(allocator: Allocator) ?[]const u8 {
return allocator.dupe(u8, "/tmp") catch unreachable;
}
const app_dir_path = std.fs.getAppDataDir(allocator, "lightpanda") catch |err| {
log.warn("failed to get lightpanda data dir: {}", .{err});
log.warn(.app, "get data dir", .{ .err = err });
return null;
};
@@ -92,7 +91,7 @@ fn getAndMakeAppDir(allocator: Allocator) ?[]const u8 {
error.PathAlreadyExists => return app_dir_path,
else => {
allocator.free(app_dir_path);
log.warn("failed to create lightpanda data dir: {}", .{err});
log.warn(.app, "create data dir", .{ .err = err, .path = app_dir_path });
return null;
},
};

130
src/browser/console/console.zig
View File

@@ -22,7 +22,7 @@ const builtin = @import("builtin");
const JsObject = @import("../env.zig").Env.JsObject;
const SessionState = @import("../env.zig").SessionState;
const log = if (builtin.is_test) &test_capture else std.log.scoped(.console);
const log = if (builtin.is_test) &test_capture else @import("../../log.zig");
pub const Console = struct {
// TODO: configurable writer
@@ -33,7 +33,7 @@ pub const Console = struct {
if (values.len == 0) {
return;
}
log.info("{s}", .{try serializeValues(values, state)});
log.info(.console, "info", .{ .args = try serializeValues(values, state) });
}
pub fn _info(console: *const Console, values: []JsObject, state: *SessionState) !void {
@@ -44,21 +44,21 @@ pub const Console = struct {
if (values.len == 0) {
return;
}
log.debug("{s}", .{try serializeValues(values, state)});
log.debug(.console, "debug", .{ .args = try serializeValues(values, state) });
}
pub fn _warn(_: *const Console, values: []JsObject, state: *SessionState) !void {
if (values.len == 0) {
return;
}
log.warn("{s}", .{try serializeValues(values, state)});
log.warn(.console, "warn", .{ .args = try serializeValues(values, state) });
}
pub fn _error(_: *const Console, values: []JsObject, state: *SessionState) !void {
if (values.len == 0) {
return;
}
log.err("{s}", .{try serializeValues(values, state)});
log.info(.console, "error", .{ .args = try serializeValues(values, state) });
}
pub fn _clear(_: *const Console) void {}
@@ -77,17 +77,16 @@ pub const Console = struct {
const count = current + 1;
gop.value_ptr.* = count;
log.info("{s}: {d}", .{ label, count });
log.info(.console, "count", .{ .label = label, .count = count });
}
pub fn _countReset(self: *Console, label_: ?[]const u8) !void {
const label = label_ orelse "default";
const kv = self.counts.fetchRemove(label) orelse {
log.warn("Counter \"{s}\" doesn't exist.", .{label});
log.info(.console, "invalid counter", .{ .label = label });
return;
};
log.info("{s}: {d}", .{ label, kv.value });
log.info(.console, "count reset", .{ .label = label, .count = kv.value });
}
pub fn _time(self: *Console, label_: ?[]const u8, state: *SessionState) !void {
@@ -95,7 +94,7 @@ pub const Console = struct {
const gop = try self.timers.getOrPut(state.arena, label);
if (gop.found_existing) {
log.warn("Timer \"{s}\" already exists.", .{label});
log.info(.console, "duplicate timer", .{ .label = label });
return;
}
gop.key_ptr.* = try state.arena.dupe(u8, label);
@@ -106,22 +105,21 @@ pub const Console = struct {
const elapsed = timestamp();
const label = label_ orelse "default";
const start = self.timers.get(label) orelse {
log.warn("Timer \"{s}\" doesn't exist.", .{label});
log.info(.console, "invalid timer", .{ .label = label });
return;
};
log.info("\"{s}\": {d}ms", .{ label, elapsed - start });
log.info(.console, "timer", .{ .label = label, .elapsed = elapsed - start });
}
pub fn _timeStop(self: *Console, label_: ?[]const u8) void {
const elapsed = timestamp();
const label = label_ orelse "default";
const kv = self.timers.fetchRemove(label) orelse {
log.warn("Timer \"{s}\" doesn't exist.", .{label});
log.info(.console, "invalid timer", .{ .label = label });
return;
};
log.info("\"{s}\": {d}ms - timer ended", .{ label, elapsed - kv.value });
log.warn(.console, "timer stop", .{ .label = label, .elapsed = elapsed - kv.value });
}
pub fn _assert(_: *Console, assertion: JsObject, values: []JsObject, state: *SessionState) !void {
@@ -132,7 +130,7 @@ pub const Console = struct {
if (values.len > 0) {
serialized_values = try serializeValues(values, state);
}
log.err("Assertion failed: {s}", .{serialized_values});
log.info(.console, "assertion failed", .{ .values = serialized_values });
}
fn serializeValues(values: []JsObject, state: *SessionState) ![]const u8 {
@@ -155,11 +153,11 @@ fn timestamp() u32 {
var test_capture = TestCapture{};
const testing = @import("../../testing.zig");
test "Browser.Console" {
defer testing.reset();
var runner = try testing.jsRunner(testing.tracking_allocator, .{});
defer runner.deinit();
defer testing.reset();
{
try runner.testCases(&.{
.{ "console.log('a')", "undefined" },
@@ -167,8 +165,8 @@ test "Browser.Console" {
}, .{});
const captured = test_capture.captured.items;
try testing.expectEqual("a", captured[0]);
try testing.expectEqual("hello world 23 true [object Object]", captured[1]);
try testing.expectEqual("[info] args=a", captured[0]);
try testing.expectEqual("[warn] args=hello world 23 true [object Object]", captured[1]);
}
{
@@ -186,15 +184,15 @@ test "Browser.Console" {
}, .{});
const captured = test_capture.captured.items;
try testing.expectEqual("Counter \"default\" doesn't exist.", captured[0]);
try testing.expectEqual("default: 1", captured[1]);
try testing.expectEqual("teg: 1", captured[2]);
try testing.expectEqual("teg: 2", captured[3]);
try testing.expectEqual("teg: 3", captured[4]);
try testing.expectEqual("default: 2", captured[5]);
try testing.expectEqual("teg: 3", captured[6]);
try testing.expectEqual("default: 2", captured[7]);
try testing.expectEqual("default: 1", captured[8]);
try testing.expectEqual("[invalid counter] label=default", captured[0]);
try testing.expectEqual("[count] label=default count=1", captured[1]);
try testing.expectEqual("[count] label=teg count=1", captured[2]);
try testing.expectEqual("[count] label=teg count=2", captured[3]);
try testing.expectEqual("[count] label=teg count=3", captured[4]);
try testing.expectEqual("[count] label=default count=2", captured[5]);
try testing.expectEqual("[count reset] label=teg count=3", captured[6]);
try testing.expectEqual("[count reset] label=default count=2", captured[7]);
try testing.expectEqual("[count] label=default count=1", captured[8]);
}
{
@@ -208,12 +206,11 @@ test "Browser.Console" {
}, .{});
const captured = test_capture.captured.items;
try testing.expectEqual("Assertion failed: ", captured[0]);
try testing.expectEqual("Assertion failed: x true", captured[1]);
try testing.expectEqual("Assertion failed: x", captured[2]);
try testing.expectEqual("[assertion failed] values=", captured[0]);
try testing.expectEqual("[assertion failed] values=x true", captured[1]);
try testing.expectEqual("[assertion failed] values=x", captured[2]);
}
}
const TestCapture = struct {
captured: std.ArrayListUnmanaged([]const u8) = .{},
@@ -221,20 +218,69 @@ const TestCapture = struct {
self.captured = .{};
}
fn debug(self: *TestCapture, comptime fmt: []const u8, args: anytype) void {
const str = std.fmt.allocPrint(testing.arena_allocator, fmt, args) catch unreachable;
self.captured.append(testing.arena_allocator, str) catch unreachable;
fn debug(
self: *TestCapture,
comptime scope: @Type(.enum_literal),
comptime msg: []const u8,
args: anytype,
) void {
self.capture(scope, msg, args);
}
fn info(self: *TestCapture, comptime fmt: []const u8, args: anytype) void {
self.debug(fmt, args);
fn info(
self: *TestCapture,
comptime scope: @Type(.enum_literal),
comptime msg: []const u8,
args: anytype,
) void {
self.capture(scope, msg, args);
}
fn warn(self: *TestCapture, comptime fmt: []const u8, args: anytype) void {
self.debug(fmt, args);
fn warn(
self: *TestCapture,
comptime scope: @Type(.enum_literal),
comptime msg: []const u8,
args: anytype,
) void {
self.capture(scope, msg, args);
}
fn err(self: *TestCapture, comptime fmt: []const u8, args: anytype) void {
self.debug(fmt, args);
fn err(
self: *TestCapture,
comptime scope: @Type(.enum_literal),
comptime msg: []const u8,
args: anytype,
) void {
self.capture(scope, msg, args);
}
fn capture(
self: *TestCapture,
comptime scope: @Type(.enum_literal),
comptime msg: []const u8,
args: anytype,
) void {
self._capture(scope, msg, args) catch unreachable;
}
fn _capture(
self: *TestCapture,
comptime scope: @Type(.enum_literal),
comptime msg: []const u8,
args: anytype,
) !void {
std.debug.assert(scope == .console);
const allocator = testing.arena_allocator;
var buf: std.ArrayListUnmanaged(u8) = .empty;
try buf.appendSlice(allocator, "[" ++ msg ++ "] ");
inline for (@typeInfo(@TypeOf(args)).@"struct".fields) |f| {
try buf.appendSlice(allocator, f.name);
try buf.append(allocator, '=');
try @import("../../log.zig").writeValue(allocator, &buf, false, @field(args, f.name));
try buf.append(allocator, ' ');
}
self.captured.append(testing.arena_allocator, std.mem.trimRight(u8, buf.items, " ")) catch unreachable;
}
};

9
src/browser/dom/element.zig
View File

@@ -21,9 +21,10 @@ const std = @import("std");
const parser = @import("../netsurf.zig");
const SessionState = @import("../env.zig").SessionState;
const collection = @import("html_collection.zig");
const dump = @import("../dump.zig");
const css = @import("css.zig");
const log = @import("../../log.zig");
const dump = @import("../dump.zig");
const collection = @import("html_collection.zig");
const Node = @import("node.zig").Node;
const Walker = @import("walker.zig").WalkerDepthFirst;
@@ -31,8 +32,6 @@ const NodeList = @import("nodelist.zig").NodeList;
const HTMLElem = @import("../html/elements.zig");
pub const Union = @import("../html/elements.zig").Union;
const log = std.log.scoped(.element);
// WEB IDL https://dom.spec.whatwg.org/#element
pub const Element = struct {
pub const Self = parser.Element;
@@ -148,7 +147,7 @@ pub const Element = struct {
while (true) {
if (try select.match(current)) {
if (!current.isElement()) {
log.err("closest: is not an element: {s}", .{try current.tag()});
log.err(.element, "closest invalid type", .{ .type = try current.tag() });
return null;
}
return parser.nodeToElement(current.node);

6
src/browser/dom/intersection_observer.zig
View File

@@ -18,6 +18,7 @@
const std = @import("std");
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const SessionState = @import("../env.zig").SessionState;
@@ -29,8 +30,6 @@ pub const Interfaces = .{
IntersectionObserverEntry,
};
const log = std.log.scoped(.events);
// This is supposed to listen to change between the root and observation targets.
// However, our rendered stores everything as 1 pixel sized boxes in a long row that never changes.
// As such, there are no changes to intersections between the root and any target.
@@ -87,8 +86,7 @@ pub const IntersectionObserver = struct {
var result: Env.Function.Result = undefined;
self.callback.tryCall(void, .{self.observed_entries.items}, &result) catch {
log.err("intersection observer callback error: {s}", .{result.exception});
log.debug("stack:\n{s}", .{result.stack orelse "???"});
log.debug(.int_obs, "callback error", .{ .err = result.exception, .stack = result.stack });
};
}

36
src/browser/dom/mutation_observer.zig
View File

@@ -19,6 +19,7 @@
const std = @import("std");
const Allocator = std.mem.Allocator;
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const SessionState = @import("../env.zig").SessionState;
@@ -32,8 +33,6 @@ pub const Interfaces = .{
const Walker = @import("../dom/walker.zig").WalkerChildren;
const log = std.log.scoped(.events);
// WEB IDL https://dom.spec.whatwg.org/#interface-mutationobserver
pub const MutationObserver = struct {
cbk: Env.Function,
@@ -115,8 +114,7 @@ pub const MutationObserver = struct {
const records = [_]MutationRecord{r.*};
var result: Env.Function.Result = undefined;
self.cbk.tryCall(void, .{records}, &result) catch {
log.err("mutation observer callback error: {s}", .{result.exception});
log.debug("stack:\n{s}", .{result.stack orelse "???"});
log.debug(.mut_obs, "callback error", .{ .err = result.exception, .stack = result.stack });
};
}
}
@@ -243,15 +241,16 @@ 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 });
};
}
fn _handle(self: *Observer, event: *parser.Event) !void {
var mutation_observer = self.mutation_observer;
const node = blk: {
const event_target = parser.eventTarget(event) catch |e| {
log.err("mutation observer event target: {any}", .{e});
return;
} orelse return;
const event_target = try parser.eventTarget(event) orelse return;
break :blk parser.eventTargetToNode(event_target);
};
@@ -260,10 +259,7 @@ const Observer = struct {
}
const event_type = blk: {
const t = parser.eventType(event) catch |e| {
log.err("mutation observer event type: {any}", .{e});
return;
};
const t = try parser.eventType(event);
break :blk std.meta.stringToEnum(MutationEventType, t) orelse return;
};
@@ -273,9 +269,7 @@ const Observer = struct {
.target = self.node,
.type = event_type.recordType(),
};
mutation_observer.observed.append(arena, &self.record.?) catch |err| {
log.err("mutation_observer append: {}", .{err});
};
try mutation_observer.observed.append(arena, &self.record.?);
}
var record = &self.record.?;
@@ -295,18 +289,12 @@ const Observer = struct {
},
.DOMNodeInserted => {
if (parser.mutationEventRelatedNode(mutation_event) catch null) |related_node| {
record.added_nodes.append(arena, related_node) catch |e| {
log.err("mutation event handler error: {any}", .{e});
return;
};
try record.added_nodes.append(arena, related_node);
}
},
.DOMNodeRemoved => {
if (parser.mutationEventRelatedNode(mutation_event) catch null) |related_node| {
record.removed_nodes.append(arena, related_node) catch |e| {
log.err("mutation event handler error: {any}", .{e});
return;
};
try record.removed_nodes.append(arena, related_node);
}
},
}

5
src/browser/dom/node.zig
View File

@@ -18,6 +18,7 @@
const std = @import("std");
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const generate = @import("../../runtime/generate.zig");
@@ -41,8 +42,6 @@ const Walker = @import("walker.zig").WalkerDepthFirst;
const HTML = @import("../html/html.zig");
const HTMLElem = @import("../html/elements.zig");
const log = std.log.scoped(.node);
// Node interfaces
pub const Interfaces = .{
Attr,
@@ -270,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("getRootNode composed is not implemented yet", .{});
log.warn(.node, "not implemented", .{ .feature = "getRootNode composed" });
};
return try Node.toInterface(try parser.nodeGetRootNode(self));
}

6
src/browser/dom/nodelist.zig
View File

@@ -18,6 +18,7 @@
const std = @import("std");
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const JsThis = @import("../env.zig").JsThis;
@@ -28,8 +29,6 @@ const Node = @import("node.zig").Node;
const U32Iterator = @import("../iterator/iterator.zig").U32Iterator;
const log = std.log.scoped(.nodelist);
const DOMException = @import("exceptions.zig").DOMException;
pub const Interfaces = .{
@@ -146,8 +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.err("callback error: {s}", .{result.exception});
log.debug("stack:\n{s}", .{result.stack orelse "???"});
log.debug(.node_list, "forEach callback", .{ .err = result.exception, .stack = result.stack });
};
}
}

6
src/browser/dom/token_list.zig
View File

@@ -18,6 +18,7 @@
const std = @import("std");
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const iterator = @import("../iterator/iterator.zig");
@@ -25,8 +26,6 @@ const Function = @import("../env.zig").Function;
const JsObject = @import("../env.zig").JsObject;
const DOMException = @import("exceptions.zig").DOMException;
const log = std.log.scoped(.token_list);
pub const Interfaces = .{
DOMTokenList,
DOMTokenListIterable,
@@ -143,8 +142,7 @@ 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.err("callback error: {s}", .{result.exception});
log.debug("stack:\n{s}", .{result.stack orelse "???"});
log.debug(.token_list, "foreach callback error", .{ .err = result.exception, .stack = result.stack });
};
}
}

8
src/browser/events/event.zig
View File

@@ -19,6 +19,7 @@
const std = @import("std");
const Allocator = std.mem.Allocator;
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const Function = @import("../env.zig").Function;
const generate = @import("../../runtime/generate.zig");
@@ -30,8 +31,6 @@ const EventTargetUnion = @import("../dom/event_target.zig").Union;
const CustomEvent = @import("custom_event.zig").CustomEvent;
const ProgressEvent = @import("../xhr/progress_event.zig").ProgressEvent;
const log = std.log.scoped(.events);
// Event interfaces
pub const Interfaces = .{
Event,
@@ -157,15 +156,14 @@ pub const EventHandler = struct {
fn handle(node: *parser.EventNode, event: *parser.Event) void {
const ievent = Event.toInterface(event) catch |err| {
log.err("Event.toInterface: {}", .{err});
log.err(.event, "toInterface error", .{ .err = err });
return;
};
const self: *EventHandler = @fieldParentPtr("node", node);
var result: Function.Result = undefined;
self.callback.tryCall(void, .{ievent}, &result) catch {
log.err("event handler error: {s}", .{result.exception});
log.debug("stack:\n{s}", .{result.stack orelse "???"});
log.debug(.event, "handle callback error", .{ .err = result.exception, .stack = result.stack });
};
}
};

9
src/browser/html/window.zig
View File

@@ -18,6 +18,7 @@
const std = @import("std");
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const Function = @import("../env.zig").Function;
const SessionState = @import("../env.zig").SessionState;
@@ -35,8 +36,6 @@ const CSSStyleDeclaration = @import("../cssom/css_style_declaration.zig").CSSSty
const storage = @import("../storage/storage.zig");
const log = std.log.scoped(.window);
// https://dom.spec.whatwg.org/#interface-window-extensions
// https://html.spec.whatwg.org/multipage/nav-history-apis.html#window
pub const Window = struct {
@@ -171,8 +170,7 @@ 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.err("Window.requestAnimationFrame(): {s}", .{result.exception});
log.debug("stack:\n{s}", .{result.stack orelse "???"});
log.debug(.window, "requestAnimationFrame error", .{ .err = result.exception, .stack = result.stack });
};
return 99; // not unique, but user cannot make assumptions about it. cancelAnimationFrame will be too late anyway.
}
@@ -277,8 +275,7 @@ const TimerCallback = struct {
var result: Function.Result = undefined;
self.cbk.tryCall(void, .{}, &result) catch {
log.err("timeout callback error: {s}", .{result.exception});
log.debug("stack:\n{s}", .{result.stack orelse "???"});
log.debug(.window, "timeout callback error", .{ .err = result.exception, .stack = result.stack });
};
if (self.repeat) |r| {

68
src/browser/page.zig
View File

@@ -35,14 +35,13 @@ const HTMLDocument = @import("html/document.zig").HTMLDocument;
const URL = @import("../url.zig").URL;
const log = @import("../log.zig");
const parser = @import("netsurf.zig");
const http = @import("../http/client.zig");
const storage = @import("storage/storage.zig");
const polyfill = @import("polyfill/polyfill.zig");
const log = std.log.scoped(.page);
// Page navigates to an url.
// You can navigates multiple urls with the same page, but you have to call
// end() to stop the previous navigation before starting a new one.
@@ -130,9 +129,6 @@ pub const Page = struct {
pub fn fetchModuleSource(ctx: *anyopaque, specifier: []const u8) !?[]const u8 {
const self: *Page = @ptrCast(@alignCast(ctx));
log.debug("fetch module: specifier: {s}", .{specifier});
const base = if (self.current_script) |s| s.src else null;
const file_src = blk: {
@@ -156,12 +152,12 @@ pub const Page = struct {
try self.session.browser.app.loop.run();
if (try_catch.hasCaught() == false) {
log.debug("wait: OK", .{});
log.debug(.page, "wait complete", .{});
return;
}
const msg = (try try_catch.err(self.arena)) orelse "unknown";
log.info("wait error: {s}", .{msg});
log.err(.page, "wait error", .{ .err = msg });
}
pub fn origin(self: *const Page, arena: Allocator) ![]const u8 {
@@ -176,7 +172,7 @@ pub const Page = struct {
const session = self.session;
const notification = session.browser.notification;
log.debug("starting GET {s}", .{request_url});
log.info(.page, "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)) {
@@ -215,8 +211,6 @@ pub const Page = struct {
// TODO handle fragment in url.
try self.window.replaceLocation(.{ .url = try self.url.toWebApi(arena) });
log.info("GET {any} {d}", .{ self.url, header.status });
const content_type = header.get("content-type");
const mime: Mime = blk: {
@@ -226,12 +220,13 @@ pub const Page = struct {
break :blk Mime.sniff(try response.peek());
} orelse .unknown;
log.info(.page, "navigation header", .{ .status = header.status, .content_type = content_type, .charset = mime.charset });
if (mime.isHTML()) {
self.raw_data = null;
try self.loadHTMLDoc(&response, mime.charset orelse "utf-8");
try self.processHTMLDoc();
} else {
log.info("non-HTML document: {s}", .{content_type orelse "null"});
var arr: std.ArrayListUnmanaged(u8) = .{};
while (try response.next()) |data| {
try arr.appendSlice(arena, try arena.dupe(u8, data));
@@ -244,12 +239,11 @@ pub const Page = struct {
.url = &self.url,
.timestamp = timestamp(),
});
log.info(.page, "navigation complete", .{});
}
// https://html.spec.whatwg.org/#read-html
fn loadHTMLDoc(self: *Page, reader: anytype, charset: []const u8) !void {
log.debug("parse html with charset {s}", .{charset});
const ccharset = try self.arena.dupeZ(u8, charset);
const html_doc = try parser.documentHTMLParse(reader, ccharset);
@@ -341,13 +335,17 @@ pub const Page = struct {
// > page.
// https://developer.mozilla.org/en-US/docs/Web/HTML/Element/script#notes
try parser.documentHTMLSetCurrentScript(html_doc, @ptrCast(e));
self.evalScript(&script) catch |err| log.warn("evaljs: {any}", .{err});
self.evalScript(&script) catch |err| {
log.err(.page, "eval script error", .{ .err = err });
};
try parser.documentHTMLSetCurrentScript(html_doc, null);
}
for (defer_scripts.items) |s| {
try parser.documentHTMLSetCurrentScript(html_doc, @ptrCast(s.element));
self.evalScript(&s) catch |err| log.warn("evaljs: {any}", .{err});
for (defer_scripts.items) |script| {
try parser.documentHTMLSetCurrentScript(html_doc, @ptrCast(script.element));
self.evalScript(&script) catch |err| {
log.err(.page, "eval script error", .{ .err = err });
};
try parser.documentHTMLSetCurrentScript(html_doc, null);
}
// dispatch DOMContentLoaded before the transition to "complete",
@@ -357,9 +355,11 @@ pub const Page = struct {
try HTMLDocument.documentIsLoaded(html_doc, &self.state);
// eval async scripts.
for (async_scripts.items) |s| {
try parser.documentHTMLSetCurrentScript(html_doc, @ptrCast(s.element));
self.evalScript(&s) catch |err| log.warn("evaljs: {any}", .{err});
for (async_scripts.items) |script| {
try parser.documentHTMLSetCurrentScript(html_doc, @ptrCast(script.element));
self.evalScript(&script) catch |err| {
log.err(.page, "eval script error", .{ .err = err });
};
try parser.documentHTMLSetCurrentScript(html_doc, null);
}
@@ -392,8 +392,6 @@ pub const Page = struct {
self.current_script = script;
defer self.current_script = null;
log.debug("starting GET {s}", .{src});
// https://html.spec.whatwg.org/multipage/webappapis.html#fetch-a-classic-script
const body = (try self.fetchData(src, null)) orelse {
// TODO If el's result is null, then fire an event named error at
@@ -415,8 +413,6 @@ pub const Page = struct {
// If a base path is given, src is resolved according to the base first.
// the caller owns the returned string
fn fetchData(self: *const Page, src: []const u8, base: ?[]const u8) !?[]const u8 {
log.debug("starting fetch {s}", .{src});
const arena = self.arena;
// Handle data URIs.
@@ -434,6 +430,9 @@ pub const Page = struct {
var origin_url = &self.url;
const url = try origin_url.resolve(arena, res_src);
log.info(.page, "fetching script", .{ .url = url });
errdefer |err| log.err(.page, "fetch error", .{ .err = err });
var request = try self.newHTTPRequest(.GET, &url, .{
.origin_uri = &origin_url.uri,
.navigation = false,
@@ -444,8 +443,6 @@ pub const Page = struct {
var header = response.header;
try self.session.cookie_jar.populateFromResponse(&url.uri, &header);
log.info("fetch {any}: {d}", .{ url, header.status });
if (header.status != 200) {
return error.BadStatusCode;
}
@@ -462,6 +459,7 @@ pub const Page = struct {
return null;
}
log.info(.page, "fetch complete", .{ .status = header.status, .content_length = arr.items.len });
return arr.items;
}
@@ -513,7 +511,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("window click handler: {}", .{err});
log.err(.page, "click handler error", .{ .err = err });
};
}
@@ -543,15 +541,16 @@ pub const Page = struct {
}
const DelayedNavigation = struct {
navigate_node: Loop.CallbackNode = .{ .func = DelayedNavigation.delay_navigate },
navigate_node: Loop.CallbackNode = .{ .func = DelayedNavigation.delayNavigate },
session: *Session,
href: []const u8,
fn delay_navigate(node: *Loop.CallbackNode, repeat_delay: *?u63) void {
fn delayNavigate(node: *Loop.CallbackNode, repeat_delay: *?u63) void {
_ = repeat_delay;
const self: *DelayedNavigation = @fieldParentPtr("navigate_node", node);
self.session.pageNavigate(self.href) catch |err| {
log.err("Delayed navigation error {}", .{err}); // TODO: should we trigger a specific event here?
// TODO: should we trigger a specific event here?
log.err(.page, "delayed navigation error", .{ .err = err });
};
}
};
@@ -632,17 +631,14 @@ pub const Page = struct {
switch (try page.scope.module(body, src)) {
.value => |v| break :blk v,
.exception => |e| {
log.info("eval module {s}: {s}", .{
src,
try e.exception(page.arena),
});
log.warn(.page, "eval module", .{ .src = src, .err = try e.exception(page.arena) });
return error.JsErr;
},
}
},
} catch {
if (try try_catch.err(page.arena)) |msg| {
log.info("eval script {s}: {s}", .{ src, msg });
log.warn(.page, "eval script", .{ .src = src, .err = msg });
}
return error.JsErr;
};
@@ -651,7 +647,7 @@ pub const Page = struct {
if (self.onload) |onload| {
_ = page.scope.exec(onload, "script_on_load") catch {
if (try try_catch.err(page.arena)) |msg| {
log.info("eval script onload {s}: {s}", .{ src, msg });
log.warn(.page, "eval onload", .{ .src = src, .err = msg });
}
return error.JsErr;
};

13
src/browser/polyfill/polyfill.zig
View File

@@ -19,11 +19,10 @@
const std = @import("std");
const builtin = @import("builtin");
const log = @import("../../log.zig");
const Allocator = std.mem.Allocator;
const Env = @import("../env.zig").Env;
const log = std.log.scoped(.polyfill);
const modules = [_]struct {
name: []const u8,
source: []const u8,
@@ -37,18 +36,12 @@ pub fn load(allocator: Allocator, scope: *Env.Scope) !void {
defer try_catch.deinit();
for (modules) |m| {
const res = scope.exec(m.source, m.name) catch |err| {
_ = scope.exec(m.source, m.name) catch |err| {
if (try try_catch.err(allocator)) |msg| {
defer allocator.free(msg);
log.err("load {s}: {s}", .{ m.name, msg });
log.err(.polyfill, "exec error", .{ .name = m.name, .err = msg });
}
return err;
};
if (builtin.mode == .Debug) {
const msg = try res.toString(allocator);
defer allocator.free(msg);
log.debug("load {s}: {s}", .{ m.name, msg });
}
}
}

7
src/browser/session.zig
View File

@@ -24,11 +24,10 @@ const Env = @import("env.zig").Env;
const Page = @import("page.zig").Page;
const Browser = @import("browser.zig").Browser;
const log = @import("../log.zig");
const parser = @import("netsurf.zig");
const storage = @import("storage/storage.zig");
const log = std.log.scoped(.session);
// Session is like a browser's tab.
// It owns the js env and the loader for all the pages of the session.
// You can create successively multiple pages for a session, but you must
@@ -95,8 +94,8 @@ pub const Session = struct {
const page = &self.page.?;
try Page.init(page, page_arena.allocator(), self);
log.debug(.session, "create page", .{});
// start JS env
log.debug("start new js scope", .{});
// 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);
@@ -115,6 +114,8 @@ pub const Session = struct {
// clear netsurf memory arena.
parser.deinit();
log.debug(.session, "remove page", .{});
}
pub fn currentPage(self: *Session) ?*Page {

5
src/browser/storage/cookie.zig
View File

@@ -3,12 +3,11 @@ const Uri = std.Uri;
const Allocator = std.mem.Allocator;
const ArenaAllocator = std.heap.ArenaAllocator;
const log = @import("../../log.zig");
const http = @import("../../http/client.zig");
const DateTime = @import("../../datetime.zig").DateTime;
const public_suffix_list = @import("../../data/public_suffix_list.zig").lookup;
const log = std.log.scoped(.cookie);
pub const LookupOpts = struct {
request_time: ?i64 = null,
origin_uri: ?*const Uri = null,
@@ -156,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("Couldn't parse cookie '{s}': {}\n", .{ set_cookie, err });
log.warn(.cookie, "parse failed", .{ .raw = set_cookie, .err = err });
continue;
};
try self.add(c, now);

7
src/browser/storage/storage.zig
View File

@@ -20,8 +20,6 @@ const std = @import("std");
const DOMError = @import("../netsurf.zig").DOMError;
const log = std.log.scoped(.storage);
pub const cookie = @import("cookie.zig");
pub const Cookie = cookie.Cookie;
pub const CookieJar = cookie.Jar;
@@ -149,10 +147,7 @@ pub const Bottle = struct {
}
pub fn _setItem(self: *Bottle, k: []const u8, v: []const u8) !void {
const gop = self.map.getOrPut(self.alloc, k) catch |e| {
log.debug("set item: {any}", .{e});
return DOMError.QuotaExceeded;
};
const gop = try self.map.getOrPut(self.alloc, k);
if (gop.found_existing == false) {
gop.key_ptr.* = try self.alloc.dupe(u8, k);

9
src/browser/xhr/event_target.zig
View File

@@ -27,8 +27,6 @@ const EventHandler = @import("../events/event.zig").EventHandler;
const parser = @import("../netsurf.zig");
const SessionState = @import("../env.zig").SessionState;
const log = std.log.scoped(.xhr);
pub const XMLHttpRequestEventTarget = struct {
pub const prototype = *EventTarget;
@@ -118,11 +116,4 @@ pub const XMLHttpRequestEventTarget = struct {
try self.register(state.arena, "loadend", handler);
self.onloadend_cbk = handler;
}
pub fn deinit(self: *XMLHttpRequestEventTarget, state: *SessionState) void {
const arena = state.arena;
parser.eventTargetRemoveAllEventListeners(@as(*parser.EventTarget, @ptrCast(self)), arena) catch |e| {
log.err("remove all listeners: {any}", .{e});
};
}
};

5
src/browser/xhr/form_data.zig
View File

@@ -20,12 +20,11 @@ const std = @import("std");
const Allocator = std.mem.Allocator;
const log = @import("../../log.zig");
const parser = @import("../netsurf.zig");
const iterator = @import("../iterator/iterator.zig");
const SessionState = @import("../env.zig").SessionState;
const log = std.log.scoped(.form_data);
pub const Interfaces = .{
FormData,
KeyIterable,
@@ -267,7 +266,7 @@ fn collectForm(arena: Allocator, form: *parser.Form, submitter_: ?*parser.Elemen
}
},
else => {
log.warn("unsupported form element: {s}\n", .{@tagName(tag)});
log.warn(.form_data, "unsupported element", .{ .tag = @tagName(tag) });
continue;
},
}

69
src/browser/xhr/xhr.zig
View File

@@ -24,6 +24,7 @@ const DOMError = @import("../netsurf.zig").DOMError;
const ProgressEvent = @import("progress_event.zig").ProgressEvent;
const XMLHttpRequestEventTarget = @import("event_target.zig").XMLHttpRequestEventTarget;
const log = @import("../../log.zig");
const URL = @import("../../url.zig").URL;
const Mime = @import("../mime.zig").Mime;
const parser = @import("../netsurf.zig");
@@ -31,8 +32,6 @@ const http = @import("../../http/client.zig");
const SessionState = @import("../env.zig").SessionState;
const CookieJar = @import("../storage/storage.zig").CookieJar;
const log = std.log.scoped(.xhr);
// XHR interfaces
// https://xhr.spec.whatwg.org/#interface-xmlhttprequest
pub const Interfaces = .{
@@ -82,8 +81,6 @@ pub const XMLHttpRequest = struct {
arena: Allocator,
request: ?http.Request = null,
priv_state: PrivState = .new,
method: http.Request.Method,
state: State,
url: ?URL = null,
@@ -272,8 +269,6 @@ pub const XMLHttpRequest = struct {
self.response_status = 0;
self.send_flag = false;
self.priv_state = .new;
}
pub fn get_readyState(self: *XMLHttpRequest) u16 {
@@ -323,8 +318,6 @@ pub const XMLHttpRequest = struct {
const arena = self.arena;
self.url = try self.origin_url.resolve(arena, url);
log.debug("open url ({s})", .{self.url.?});
self.sync = if (asyn) |b| !b else false;
self.state = .opened;
@@ -334,19 +327,19 @@ pub const XMLHttpRequest = struct {
// dispatch request event.
// errors are logged only.
fn dispatchEvt(self: *XMLHttpRequest, typ: []const u8) void {
const evt = parser.eventCreate() catch |e| {
return log.err("dispatch event create: {any}", .{e});
log.debug(.xhr, "dispatch event", .{ .type = typ });
self._dispatchEvt(typ) catch |err| {
log.err(.xhr, "dispatch event error", .{ .err = err, .type = typ });
};
}
fn _dispatchEvt(self: *XMLHttpRequest, typ: []const u8) !void {
const evt = try parser.eventCreate();
// We can we defer event destroy once the event is dispatched.
defer parser.eventDestroy(evt);
parser.eventInit(evt, typ, .{ .bubbles = true, .cancelable = true }) catch |e| {
return log.err("dispatch event init: {any}", .{e});
};
_ = parser.eventTargetDispatchEvent(@as(*parser.EventTarget, @ptrCast(self)), evt) catch |e| {
return log.err("dispatch event: {any}", .{e});
};
try parser.eventInit(evt, typ, .{ .bubbles = true, .cancelable = true });
_ = try parser.eventTargetDispatchEvent(@as(*parser.EventTarget, @ptrCast(self)), evt);
}
fn dispatchProgressEvent(
@@ -354,22 +347,28 @@ pub const XMLHttpRequest = struct {
typ: []const u8,
opts: ProgressEvent.EventInit,
) void {
log.debug("dispatch progress event: {s}", .{typ});
var evt = ProgressEvent.constructor(typ, .{
log.debug(.xhr, "dispatch progress event", .{ .type = typ });
self._dispatchProgressEvent(typ, opts) catch |err| {
log.err(.xhr, "dispatch progress event error", .{ .err = err, .type = typ });
};
}
fn _dispatchProgressEvent(
self: *XMLHttpRequest,
typ: []const u8,
opts: ProgressEvent.EventInit,
) !void {
var evt = try ProgressEvent.constructor(typ, .{
// https://xhr.spec.whatwg.org/#firing-events-using-the-progressevent-interface
.lengthComputable = opts.total > 0,
.total = opts.total,
.loaded = opts.loaded,
}) catch |e| {
return log.err("construct progress event: {any}", .{e});
};
});
_ = parser.eventTargetDispatchEvent(
_ = try parser.eventTargetDispatchEvent(
@as(*parser.EventTarget, @ptrCast(self)),
@as(*parser.Event, @ptrCast(&evt)),
) catch |e| {
return log.err("dispatch progress event: {any}", .{e});
};
);
}
const methods = [_]struct {
@@ -413,10 +412,9 @@ pub const XMLHttpRequest = struct {
if (self.state != .opened) return DOMError.InvalidState;
if (self.send_flag) return DOMError.InvalidState;
log.debug("{any} {any}", .{ self.method, self.url });
log.info(.xhr, "request", .{ .method = self.method, .url = self.url });
self.send_flag = true;
self.priv_state = .open;
self.request = try session_state.request_factory.create(self.method, &self.url.?.uri);
var request = &self.request.?;
@@ -460,10 +458,8 @@ pub const XMLHttpRequest = struct {
if (progress.first) {
const header = progress.header;
log.info("{any} {any} {d}", .{ self.method, self.url, header.status });
self.priv_state = .done;
log.info(.xhr, "request header", .{ .status = header.status });
for (header.headers.items) |hdr| {
try self.response_headers.append(hdr.name, hdr.value);
}
@@ -509,6 +505,8 @@ pub const XMLHttpRequest = struct {
return;
}
log.info(.xhr, "request complete", .{});
self.state = .done;
self.send_flag = false;
self.dispatchEvt("readystatechange");
@@ -520,16 +518,13 @@ pub const XMLHttpRequest = struct {
}
fn onErr(self: *XMLHttpRequest, err: anyerror) void {
self.priv_state = .done;
self.err = err;
self.state = .done;
self.send_flag = false;
self.dispatchEvt("readystatechange");
self.dispatchProgressEvent("error", .{});
self.dispatchProgressEvent("loadend", .{});
log.debug("{any} {any} {any}", .{ self.method, self.url, self.err });
log.warn(.xhr, "error", .{ .method = self.method, .url = self.url, .err = err });
}
pub fn _abort(self: *XMLHttpRequest) void {
@@ -633,7 +628,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("response type ArrayBuffer not implemented", .{});
log.err(.xhr, "not implemented", .{ .feature = "ArrayBuffer resposne type" });
return null;
}
@@ -642,7 +637,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("response type Blob not implemented", .{});
log.err(.xhr, "not implemented", .{ .feature = "Blog resposne type" });
return null;
}
@@ -717,7 +712,7 @@ pub const XMLHttpRequest = struct {
self.response_bytes.items,
.{},
) catch |e| {
log.err("parse JSON: {}", .{e});
log.warn(.xhr, "invalid json", .{ .err = e });
self.response_obj = .{ .Failure = {} };
return;
};

5
src/cdp/Node.zig
View File

@@ -19,12 +19,11 @@
const std = @import("std");
const Allocator = std.mem.Allocator;
const log = @import("../log.zig");
const parser = @import("../browser/netsurf.zig");
pub const Id = u32;
const log = std.log.scoped(.cdp_node);
const Node = @This();
id: Id,
@@ -213,7 +212,7 @@ pub const Writer = struct {
// The only error our jsonStringify method can return is
// @TypeOf(w).Error. In other words, our code can't return its own
// error, we can only return a writer error. Kinda sucks.
log.err("json stringify: {}", .{err});
log.err(.cdp, "json stringify", .{ .err = err });
return error.OutOfMemory;
};
}

26
src/cdp/cdp.zig
View File

@@ -20,6 +20,7 @@ const std = @import("std");
const Allocator = std.mem.Allocator;
const json = std.json;
const log = @import("../log.zig");
const App = @import("../app.zig").App;
const Env = @import("../browser/env.zig").Env;
const asUint = @import("../str/parser.zig").asUint;
@@ -30,8 +31,6 @@ const Inspector = @import("../browser/env.zig").Env.Inspector;
const Incrementing = @import("../id.zig").Incrementing;
const Notification = @import("../notification.zig").Notification;
const log = std.log.scoped(.cdp);
pub const URL_BASE = "chrome://newtab/";
pub const LOADER_ID = "LOADERID24DD2FD56CF1EF33C965C79C";
@@ -463,36 +462,25 @@ pub fn BrowserContext(comptime CDP_T: type) type {
}
pub fn onInspectorResponse(ctx: *anyopaque, _: u32, msg: []const u8) void {
if (std.log.defaultLogEnabled(.debug)) {
// msg should be {"id":<id>,...
std.debug.assert(std.mem.startsWith(u8, msg, "{\"id\":"));
const id_end = std.mem.indexOfScalar(u8, msg, ',') orelse {
log.warn("invalid inspector response message: {s}", .{msg});
return;
};
const id = msg[6..id_end];
log.debug("Res (inspector) > id {s}", .{id});
}
sendInspectorMessage(@alignCast(@ptrCast(ctx)), msg) catch |err| {
log.err("Failed to send inspector response: {any}", .{err});
log.err(.cdp, "send inspector response", .{ .err = err });
};
}
pub fn onInspectorEvent(ctx: *anyopaque, msg: []const u8) void {
if (std.log.defaultLogEnabled(.debug)) {
if (log.enabled(.cdp, .debug)) {
// msg should be {"method":<method>,...
std.debug.assert(std.mem.startsWith(u8, msg, "{\"method\":"));
const method_end = std.mem.indexOfScalar(u8, msg, ',') orelse {
log.warn("invalid inspector event message: {s}", .{msg});
log.err(.cdp, "invalid inspector event", .{ .msg = msg });
return;
};
const method = msg[10..method_end];
log.debug("Event (inspector) > method {s}", .{method});
log.debug(.cdp, "inspector event", .{ .method = method });
}
sendInspectorMessage(@alignCast(@ptrCast(ctx)), msg) catch |err| {
log.err("Failed to send inspector event: {any}", .{err});
log.err(.cdp, "send inspector event", .{ .err = err });
};
}
@@ -518,7 +506,7 @@ pub fn BrowserContext(comptime CDP_T: type) type {
var buf: std.ArrayListUnmanaged(u8) = .{};
buf.ensureTotalCapacity(arena.allocator(), message_len) catch |err| {
log.err("Failed to expand inspector buffer: {any}", .{err});
log.err(.cdp, "inspector buffer", .{ .err = err });
return;
};

5
src/cdp/domains/target.zig
View File

@@ -17,8 +17,7 @@
// along with this program. If not, see <https://www.gnu.org/licenses/>.
const std = @import("std");
const log = std.log.scoped(.cdp);
const log = @import("../../log.zig");
// TODO: hard coded IDs
const LOADER_ID = "LOADERID42AA389647D702B4D805F49A";
@@ -301,7 +300,7 @@ fn sendMessageToTarget(cmd: anytype) !void {
};
cmd.cdp.dispatch(cmd.arena, &capture, params.message) catch |err| {
log.err("send message {d} ({s}): {any}", .{ cmd.input.id orelse -1, params.message, err });
log.err(.cdp, "internal dispatch error", .{ .err = err, .id = cmd.input.id, .message = params.message });
return err;
};

28
src/http/client.zig
View File

@@ -27,12 +27,11 @@ const MemoryPool = std.heap.MemoryPool;
const ArenaAllocator = std.heap.ArenaAllocator;
const tls = @import("tls");
const log = @import("../log.zig");
const IO = @import("../runtime/loop.zig").IO;
const Loop = @import("../runtime/loop.zig").Loop;
const Notification = @import("../notification.zig").Notification;
const log = std.log.scoped(.http_client);
// We might need to peek at the body to try and sniff the content-type.
// While we only need a few bytes, in most cases we need to ignore leading
// whitespace, so we want to get a reasonable-sized chunk.
@@ -352,7 +351,7 @@ pub const Request = struct {
self._client.connection_manager.keepIdle(connection) catch |err| {
self.destroyConnection(connection);
log.err("failed to release connection to pool: {}", .{err});
log.err(.http_client, "release to pool error", .{ .err = err });
};
}
@@ -457,7 +456,12 @@ pub const Request = struct {
var handler = SyncHandler{ .request = self };
return handler.send() catch |err| {
log.warn("HTTP error: {any} ({any} {any} {d})", .{ err, self.method, self.request_uri, self._redirect_count });
log.warn(.http_client, "sync error", .{
.err = err,
.method = self.method,
.url = self.request_uri,
.redirects = self._redirect_count,
});
return err;
};
}
@@ -526,7 +530,7 @@ pub const Request = struct {
.host = self._connect_host,
.root_ca = self._client.root_ca,
.insecure_skip_verify = self._tls_verify_host == false,
.key_log_callback = tls.config.key_log.callback,
// .key_log_callback = tls.config.key_log.callback,
}),
};
@@ -603,7 +607,7 @@ pub const Request = struct {
// to a GET.
self.method = .GET;
}
log.info("redirecting to: {any} {any}", .{ self.method, self.request_uri });
log.debug(.http_client, "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
@@ -1076,7 +1080,12 @@ fn AsyncHandler(comptime H: type, comptime L: type) type {
}
fn handleError(self: *Self, comptime msg: []const u8, err: anyerror) void {
log.err(msg ++ ": {any} ({any} {any})", .{ err, self.request.method, self.request.request_uri });
log.err(.http_client, msg, .{
.err = err,
.method = self.request.method,
.url = self.request.request_uri,
});
self.handler.onHttpResponse(err) catch {};
// just to be safe
self.request._keepalive = false;
@@ -1297,7 +1306,10 @@ const SyncHandler = struct {
// See CompressedReader for an explanation. This isn't great code. Sorry.
if (reader.response.get("content-encoding")) |ce| {
if (std.ascii.eqlIgnoreCase(ce, "gzip") == false) {
log.warn("unsupported content encoding '{s}' for: {}", .{ ce, request.request_uri });
log.warn(.http_client, "unsupported content encoding", .{
.content_encoding = ce,
.uri = request.request_uri,
});
return error.UnsupportedContentEncoding;
}

480
src/log.zig Normal file
View File

@@ -0,0 +1,480 @@
const std = @import("std");
const builtin = @import("builtin");
const build_config = @import("build_config");
const Thread = std.Thread;
const Allocator = std.mem.Allocator;
const LogLevel: Level = blk: {
if (builtin.is_test) break :blk .err;
break :blk @enumFromInt(@intFromEnum(build_config.log_level));
};
var pool: Pool = undefined;
pub fn init(allocator: Allocator, opts: Opts) !void {
pool = try Pool.init(allocator, 3, opts);
}
pub fn deinit(allocator: Allocator) void {
pool.deinit(allocator);
}
// 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(LogLevel);
}
pub const Level = enum {
debug,
info,
warn,
err,
fatal,
};
const Opts = struct {
format: Format = if (!builtin.is_test and builtin.mode == .Debug) .pretty else .logfmt,
};
pub const Format = enum {
logfmt,
pretty,
};
pub fn debug(comptime scope: @Type(.enum_literal), 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 {
log(scope, .info, msg, data);
}
pub fn warn(comptime scope: @Type(.enum_literal), 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 {
log(scope, .err, msg, data);
}
pub fn fatal(comptime scope: @Type(.enum_literal), 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) {
return;
}
const logger = pool.acquire();
defer pool.release(logger);
logger.log(scope, level, msg, data) catch |log_err| {
std.debug.print("$time={d} $level=fatal $scope={s} $msg=\"log err\" err={s} log_msg=\"{s}\"", .{ timestamp(), @errorName(log_err), @tagName(scope), msg });
};
}
// Generic so that we can test it against an ArrayList
fn LogT(comptime Out: type) type {
return struct {
out: Out,
format: Format,
allocator: Allocator,
buffer: std.ArrayListUnmanaged(u8),
const Self = @This();
fn init(allocator: Allocator, opts: Opts) !Self {
return initTo(allocator, opts, std.io.getStdOut());
}
// Used for tests
fn initTo(allocator: Allocator, opts: Opts, out: Out) !Self {
var buffer: std.ArrayListUnmanaged(u8) = .{};
try buffer.ensureTotalCapacity(allocator, 2048);
return .{
.out = out,
.buffer = buffer,
.format = opts.format,
.allocator = allocator,
};
}
fn deinit(self: *Self) void {
self.buffer.deinit(self.allocator);
}
fn log(self: *Self, comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: 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', '_', '-', '.', '{', '}' => {},
else => @compileError("log msg contains an invalid character '" ++ msg ++ "'"),
}
}
}
defer self.buffer.clearRetainingCapacity();
switch (self.format) {
.logfmt => try self.logfmt(scope, level, msg, data),
.pretty => try self.pretty(scope, level, msg, data),
}
out_lock.lock();
defer out_lock.unlock();
try self.out.writeAll(self.buffer.items);
}
fn logfmt(self: *Self, comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: anytype) !void {
const buffer = &self.buffer;
const allocator = self.allocator;
buffer.appendSliceAssumeCapacity("$time=");
try std.fmt.format(buffer.writer(allocator), "{d}", .{timestamp()});
buffer.appendSliceAssumeCapacity(" $scope=");
buffer.appendSliceAssumeCapacity(@tagName(scope));
const level_and_msg = comptime blk: {
const l = if (level == .err) "error" else @tagName(level);
// only wrap msg in quotes if it contains a space
const lm = " $level=" ++ l ++ " $msg=";
if (std.mem.indexOfScalar(u8, msg, ' ') == null) {
break :blk lm ++ msg;
}
break :blk lm ++ "\"" ++ msg ++ "\"";
};
buffer.appendSliceAssumeCapacity(level_and_msg);
inline for (@typeInfo(@TypeOf(data)).@"struct".fields) |f| {
const key = " " ++ f.name ++ "=";
// + 5 covers null/true/false
try buffer.ensureUnusedCapacity(allocator, key.len + 5);
buffer.appendSliceAssumeCapacity(key);
try writeValue(allocator, buffer, true, @field(data, f.name));
}
try buffer.append(allocator, '\n');
}
fn pretty(self: *Self, comptime scope: @Type(.enum_literal), comptime level: Level, comptime msg: []const u8, data: anytype) !void {
const buffer = &self.buffer;
const allocator = self.allocator;
buffer.appendSliceAssumeCapacity(switch (level) {
.debug => "\x1b[0;36mDEBUG\x1b[0m ",
.info => "\x1b[0;32mINFO\x1b[0m ",
.warn => "\x1b[0;33mWARN\x1b[0m ",
.err => "\x1b[0;31mERROR\x1b[0m ",
.fatal => "\x1b[0;35mFATAL\x1b[0m ",
});
const prefix = @tagName(scope) ++ " : " ++ msg;
buffer.appendSliceAssumeCapacity(prefix);
{
// msg.len cannot be > 30, and @tagName(scope).len cannot be > 15
// so this is safe
const padding = 55 - prefix.len;
for (0..padding / 2) |_| {
buffer.appendSliceAssumeCapacity(" .");
}
if (@mod(padding, 2) == 1) {
buffer.appendAssumeCapacity(' ');
}
try buffer.writer(allocator).print(" [+{d}ms]", .{elapsed()});
buffer.appendAssumeCapacity('\n');
}
inline for (@typeInfo(@TypeOf(data)).@"struct".fields) |f| {
const key = " " ++ f.name ++ " = ";
// + 5 covers null/true/false
try buffer.ensureUnusedCapacity(allocator, key.len + 5);
buffer.appendSliceAssumeCapacity(key);
try writeValue(allocator, buffer, false, @field(data, f.name));
try buffer.append(allocator, '\n');
}
try buffer.append(allocator, '\n');
}
};
}
const Pool = struct {
loggers: []*Log,
available: usize,
mutex: Thread.Mutex,
cond: Thread.Condition,
const Self = @This();
const Log = LogT(std.fs.File);
pub fn init(allocator: Allocator, count: usize, opts: Opts) !Self {
const loggers = try allocator.alloc(*Log, count);
errdefer allocator.free(loggers);
var started: usize = 0;
errdefer for (0..started) |i| {
loggers[i].deinit();
allocator.destroy(loggers[i]);
};
const out = std.io.getStdOut();
for (0..count) |i| {
const logger = try allocator.create(Log);
errdefer allocator.destroy(logger);
logger.* = try Log.initTo(allocator, opts, out);
loggers[i] = logger;
started += 1;
}
return .{
.cond = .{},
.mutex = .{},
.loggers = loggers,
.available = count,
};
}
pub fn deinit(self: *Self, allocator: Allocator) void {
for (self.loggers) |logger| {
logger.deinit();
allocator.destroy(logger);
}
allocator.free(self.loggers);
}
pub fn acquire(self: *Self) *Log {
self.mutex.lock();
while (true) {
const loggers = self.loggers;
const available = self.available;
if (available == 0) {
self.cond.wait(&self.mutex);
continue;
}
const index = available - 1;
const logger = loggers[index];
self.available = index;
self.mutex.unlock();
return logger;
}
}
pub fn release(self: *Self, logger: *Log) void {
self.mutex.lock();
var loggers = self.loggers;
const available = self.available;
loggers[available] = logger;
self.available = available + 1;
self.mutex.unlock();
self.cond.signal();
}
};
pub fn writeValue(allocator: Allocator, buffer: *std.ArrayListUnmanaged(u8), escape_string: bool, value: anytype) !void {
const T = @TypeOf(value);
switch (@typeInfo(T)) {
.optional => {
if (value) |v| {
return writeValue(allocator, buffer, escape_string, v);
}
// in _log, we reserved space for a value of up to 5 bytes.
return buffer.appendSliceAssumeCapacity("null");
},
.comptime_int, .int, .comptime_float, .float => {
return std.fmt.format(buffer.writer(allocator), "{d}", .{value});
},
.bool => {
// in _log, we reserved space for a value of up to 5 bytes.
return buffer.appendSliceAssumeCapacity(if (value) "true" else "false");
},
.error_set => return buffer.appendSlice(allocator, @errorName(value)),
.@"enum" => return buffer.appendSlice(allocator, @tagName(value)),
.array => return writeValue(allocator, buffer, escape_string, &value),
.pointer => |ptr| switch (ptr.size) {
.slice => switch (ptr.child) {
u8 => return writeString(allocator, buffer, escape_string, value),
else => {},
},
.one => switch (@typeInfo(ptr.child)) {
.array => |arr| if (arr.child == u8) {
return writeString(allocator, buffer, escape_string, value);
},
else => {
var writer = buffer.writer(allocator);
return writer.print("{}", .{value});
},
},
else => {},
},
.@"union" => {
var writer = buffer.writer(allocator);
return writer.print("{}", .{value});
},
.@"struct" => {
var writer = buffer.writer(allocator);
return writer.print("{}", .{value});
},
else => {},
}
@compileError("cannot log a: " ++ @typeName(T));
}
fn writeString(allocator: Allocator, buffer: *std.ArrayListUnmanaged(u8), escape: bool, value: []const u8) !void {
if (escape == false) {
return buffer.appendSlice(allocator, value);
}
var space_count: usize = 0;
var escape_count: usize = 0;
var binary_count: usize = 0;
for (value) |b| {
switch (b) {
'\r', '\n', '"' => escape_count += 1,
' ' => space_count += 1,
'\t', '!', '#'...'~' => {}, // printable characters
else => binary_count += 1,
}
}
if (binary_count > 0) {
// TODO: use a different encoding if the ratio of binary data / printable is low
return std.base64.standard_no_pad.Encoder.encodeWriter(buffer.writer(allocator), value);
}
if (escape_count == 0) {
if (space_count == 0) {
return buffer.appendSlice(allocator, value);
}
try buffer.ensureUnusedCapacity(allocator, 2 + value.len);
buffer.appendAssumeCapacity('"');
buffer.appendSliceAssumeCapacity(value);
buffer.appendAssumeCapacity('"');
return;
}
// + 2 for the quotes
// + escape_count because every character that needs escaping is + 1
try buffer.ensureUnusedCapacity(allocator, 2 + value.len + escape_count);
buffer.appendAssumeCapacity('"');
var rest = value;
while (rest.len > 0) {
const pos = std.mem.indexOfAny(u8, rest, "\r\n\"") orelse {
buffer.appendSliceAssumeCapacity(rest);
break;
};
buffer.appendSliceAssumeCapacity(rest[0..pos]);
buffer.appendAssumeCapacity('\\');
switch (rest[pos]) {
'"' => buffer.appendAssumeCapacity('"'),
'\r' => buffer.appendAssumeCapacity('r'),
'\n' => buffer.appendAssumeCapacity('n'),
else => unreachable,
}
rest = rest[pos + 1 ..];
}
buffer.appendAssumeCapacity('"');
}
fn timestamp() i64 {
if (comptime @import("builtin").is_test) {
return 1739795092929;
}
return std.time.milliTimestamp();
}
var last_log: i64 = 0;
fn elapsed() i64 {
const now = timestamp();
last_log_lock.lock();
const previous = last_log;
last_log = now;
last_log_lock.unlock();
if (previous == 0) {
return 0;
}
if (previous > now) {
return 0;
}
return now - previous;
}
const testing = @import("testing.zig");
test "log: data" {
var buf: std.ArrayListUnmanaged(u8) = .{};
defer buf.deinit(testing.allocator);
var logger = try TestLogger.initTo(testing.allocator, .{ .format = .logfmt }, buf.writer(testing.allocator));
defer logger.deinit();
{
try logger.log(.t_scope, .err, "nope", .{});
try testing.expectEqual("$time=1739795092929 $scope=t_scope $level=error $msg=nope\n", buf.items);
}
{
buf.clearRetainingCapacity();
const string = try testing.allocator.dupe(u8, "spice_must_flow");
defer testing.allocator.free(string);
try logger.log(.scope_2, .warn, "a msg", .{
.cint = 5,
.cfloat = 3.43,
.int = @as(i16, -49),
.float = @as(f32, 0.0003232),
.bt = true,
.bf = false,
.nn = @as(?i32, 33),
.n = @as(?i32, null),
.lit = "over9000!",
.slice = string,
.err = error.Nope,
.level = Level.warn,
});
try testing.expectEqual("$time=1739795092929 $scope=scope_2 $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);
}
}
test "log: string escape" {
var buf: std.ArrayListUnmanaged(u8) = .{};
defer buf.deinit(testing.allocator);
var logger = try TestLogger.initTo(testing.allocator, .{ .format = .logfmt }, buf.writer(testing.allocator));
defer logger.deinit();
const prefix = "$time=1739795092929 $scope=scope $level=error $msg=test ";
{
try logger.log(.scope, .err, "test", .{ .string = "hello world" });
try testing.expectEqual(prefix ++ "string=\"hello world\"\n", buf.items);
}
{
buf.clearRetainingCapacity();
try logger.log(.scope, .err, "test", .{ .string = "\n \thi \" \" " });
try testing.expectEqual(prefix ++ "string=\"\\n \thi \\\" \\\" \"\n", buf.items);
}
}
const TestLogger = LogT(std.ArrayListUnmanaged(u8).Writer);

72
src/main.zig
View File

@@ -20,6 +20,7 @@ const std = @import("std");
const builtin = @import("builtin");
const Allocator = std.mem.Allocator;
const log = @import("log.zig");
const server = @import("server.zig");
const App = @import("app.zig").App;
const Platform = @import("runtime/js.zig").Platform;
@@ -28,16 +29,6 @@ const Browser = @import("browser/browser.zig").Browser;
const build_config = @import("build_config");
const parser = @import("browser/netsurf.zig");
const log = std.log.scoped(.cli);
pub const std_options = std.Options{
// Set the log level to info
.log_level = @enumFromInt(@intFromEnum(build_config.log_level)),
// Define logFn to override the std implementation
.logFn = logFn,
};
pub fn main() !void {
// allocator
// - in Debug mode we use the General Purpose Allocator to detect memory leaks
@@ -49,6 +40,16 @@ pub fn main() !void {
if (gpa.detectLeaks()) std.posix.exit(1);
};
try log.init(alloc, .{});
defer log.deinit(alloc);
run(alloc) catch |err| {
log.fatal(.main, "exit", .{ .err = err });
std.posix.exit(1);
};
}
fn run(alloc: Allocator) !void {
var args_arena = std.heap.ArenaAllocator.init(alloc);
defer args_arena.deinit();
const args = try parseArgs(args_arena.allocator());
@@ -78,19 +79,20 @@ pub fn main() !void {
switch (args.mode) {
.serve => |opts| {
log.debug(.main, "startup", .{ .mode = "serve" });
const address = std.net.Address.parseIp4(opts.host, opts.port) catch |err| {
log.err("address (host:port) {any}\n", .{err});
log.fatal(.main, "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.err("Server error", .{});
log.fatal(.main, "server run", .{ .err = err });
return err;
};
},
.fetch => |opts| {
log.debug("Fetch mode: url {s}, dump {any}", .{ opts.url, opts.dump });
log.debug(.main, "startup", .{ .mode = "fetch", .dump = opts.dump, .url = opts.url });
const url = try @import("url.zig").URL.parse(opts.url, null);
// browser
@@ -104,11 +106,11 @@ pub fn main() !void {
_ = page.navigate(url, .{}) catch |err| switch (err) {
error.UnsupportedUriScheme, error.UriMissingHost => {
log.err("'{s}' is not a valid URL ({any})\n", .{ url, err });
log.fatal(.main, "fetch invalid URL", .{ .err = err, .url = url });
return args.printUsageAndExit(false);
},
else => {
log.err("'{s}' fetching error ({any})\n", .{ url, err });
log.fatal(.main, "fetch error", .{ .err = err, .url = url });
return err;
},
};
@@ -300,7 +302,7 @@ fn parseServeArgs(
while (args.next()) |opt| {
if (std.mem.eql(u8, "--host", opt)) {
const str = args.next() orelse {
log.err("--host argument requires an value", .{});
log.fatal(.main, "missing argument value", .{ .arg = "--host" });
return error.InvalidArgument;
};
host = try allocator.dupe(u8, str);
@@ -309,12 +311,12 @@ fn parseServeArgs(
if (std.mem.eql(u8, "--port", opt)) {
const str = args.next() orelse {
log.err("--port argument requires an value", .{});
log.fatal(.main, "missing argument value", .{ .arg = "--port" });
return error.InvalidArgument;
};
port = std.fmt.parseInt(u16, str, 10) catch |err| {
log.err("--port value is invalid: {}", .{err});
log.fatal(.main, "invalid argument value", .{ .arg = "--port", .err = err });
return error.InvalidArgument;
};
continue;
@@ -322,12 +324,12 @@ fn parseServeArgs(
if (std.mem.eql(u8, "--timeout", opt)) {
const str = args.next() orelse {
log.err("--timeout argument requires an value", .{});
log.fatal(.main, "missing argument value", .{ .arg = "--timeout" });
return error.InvalidArgument;
};
timeout = std.fmt.parseInt(u16, str, 10) catch |err| {
log.err("--timeout value is invalid: {}", .{err});
log.fatal(.main, "invalid argument value", .{ .arg = "--timeout", .err = err });
return error.InvalidArgument;
};
continue;
@@ -340,14 +342,13 @@ fn parseServeArgs(
if (std.mem.eql(u8, "--http_proxy", opt)) {
const str = args.next() orelse {
log.err("--http_proxy argument requires an value", .{});
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.err("Unknown option to serve command: '{s}'", .{opt});
log.fatal(.main, "unknown argument", .{ .mode = "serve", .arg = opt });
return error.UnkownOption;
}
@@ -382,7 +383,7 @@ fn parseFetchArgs(
if (std.mem.eql(u8, "--http_proxy", opt)) {
const str = args.next() orelse {
log.err("--http_proxy argument requires an value", .{});
log.fatal(.main, "missing argument value", .{ .arg = "--http_proxy" });
return error.InvalidArgument;
};
http_proxy = try std.Uri.parse(try allocator.dupe(u8, str));
@@ -390,19 +391,19 @@ fn parseFetchArgs(
}
if (std.mem.startsWith(u8, opt, "--")) {
log.err("Unknown option to serve command: '{s}'", .{opt});
log.fatal(.main, "unknown argument", .{ .mode = "fetch", .arg = opt });
return error.UnkownOption;
}
if (url != null) {
log.err("Can only fetch 1 URL", .{});
log.fatal(.main, "duplicate fetch url", .{ .help = "only 1 URL can be specified" });
return error.TooManyURLs;
}
url = try allocator.dupe(u8, opt);
}
if (url == null) {
log.err("A URL must be provided to the fetch command", .{});
log.fatal(.main, "duplicate fetch url", .{ .help = "URL to fetch must be provided" });
return error.MissingURL;
}
@@ -414,21 +415,6 @@ fn parseFetchArgs(
};
}
var verbose: bool = builtin.mode == .Debug; // In debug mode, force verbose.
fn logFn(
comptime level: std.log.Level,
comptime scope: @Type(.enum_literal),
comptime format: []const u8,
args: anytype,
) void {
if (!verbose) {
// hide all messages with level greater of equal to debug level.
if (@intFromEnum(level) >= @intFromEnum(std.log.Level.debug)) return;
}
// default std log function.
std.log.defaultLog(level, scope, format, args);
}
test {
std.testing.refAllDecls(@This());
}
@@ -436,6 +422,8 @@ test {
var test_wg: std.Thread.WaitGroup = .{};
test "tests:beforeAll" {
try parser.init();
try log.init(std.testing.allocator, .{});
test_wg.startMany(3);
_ = try Platform.init();

9
src/notification.zig
View File

@@ -1,13 +1,12 @@
const std = @import("std");
const log = @import("log.zig");
const URL = @import("url.zig").URL;
const page = @import("browser/page.zig");
const http_client = @import("http/client.zig");
const Allocator = std.mem.Allocator;
const log = std.log.scoped(.notification);
const List = std.DoublyLinkedList(Listener);
const Node = List.Node;
@@ -207,7 +206,11 @@ pub const Notification = struct {
const listener = n.data;
const func: EventFunc(event) = @alignCast(@ptrCast(listener.func));
func(listener.receiver, data) catch |err| {
log.err("{s} '{s}' dispatch error: {}", .{ listener.struct_name, @tagName(event), err });
log.err(.notification, "dispatch error", .{
.err = err,
.event = event,
.listener = listener.struct_name,
});
};
node = n.next;
}

24
src/runtime/js.zig
View File

@@ -20,13 +20,12 @@ const std = @import("std");
const builtin = @import("builtin");
const v8 = @import("v8");
const log = @import("../log.zig");
const SubType = @import("subtype.zig").SubType;
const Allocator = std.mem.Allocator;
const ArenaAllocator = std.heap.ArenaAllocator;
const log = std.log.scoped(.js);
const CALL_ARENA_RETAIN = 1024 * 16;
const SCOPE_ARENA_RETAIN = 1024 * 64;
@@ -1189,17 +1188,14 @@ pub fn Env(comptime State: type, comptime WebApis: type) type {
const self: *Scope = @ptrFromInt(context.getEmbedderData(1).castTo(v8.BigInt).getUint64());
var buf: [1024]u8 = undefined;
var fba = std.heap.FixedBufferAllocator.init(&buf);
// build the specifier value.
const specifier = valueToString(
fba.allocator(),
self.call_arena,
.{ .handle = c_specifier.? },
self.isolate,
context,
) catch |e| {
log.err("resolveModuleCallback: get ref str: {any}", .{e});
log.err(.js, "resolve module specifier", .{ .err = e });
return null;
};
@@ -1207,12 +1203,12 @@ pub fn Env(comptime State: type, comptime WebApis: type) type {
// const referrer_module = if (referrer) |ref| v8.Module{ .handle = ref } else null;
const module_loader = self.module_loader;
const source = module_loader.func(module_loader.ptr, specifier) catch |err| {
log.err("fetchModuleSource for '{s}' fetch error: {}", .{ specifier, err });
log.err(.js, "resolve module fetch error", .{ .specifier = specifier, .err = err });
return null;
} orelse return null;
const m = compileModule(self.isolate, source, specifier) catch |err| {
log.err("fetchModuleSource for '{s}' compile error: {}", .{ specifier, err });
log.err(.js, "resolve module compile error", .{ .specifier = specifier, .err = err });
return null;
};
return m.handle;
@@ -1875,7 +1871,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("unknwon named property {s}.{s}", .{ @typeName(Struct), property });
log.debug(.js, "unkown named property", .{ .@"struct" = @typeName(Struct), .property = property });
return v8.Intercepted.No;
}
}.callback,
@@ -2605,9 +2601,13 @@ 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 (std.log.logEnabled(.debug, .js)) {
errdefer |err| if (log.enabled(.js, .debug)) {
const args_dump = self.dumpFunctionArgs(info) catch "failed to serialize args";
log.debug("Failed to call '{s}'. Error: {}.\nArgs:\n{s}", .{ named_function.full_name, err, args_dump });
log.debug(.js, "function call error", .{
.name = named_function.full_name,
.err = err,
.args = args_dump,
});
};
{

7
src/runtime/loop.zig
View File

@@ -20,10 +20,9 @@ const std = @import("std");
const builtin = @import("builtin");
const MemoryPool = std.heap.MemoryPool;
const log = @import("../log.zig");
pub const IO = @import("tigerbeetle-io").IO;
const log = std.log.scoped(.loop);
// SingleThreaded I/O Loop based on Tigerbeetle io_uring loop.
// On Linux it's using io_uring.
// On MacOS and Windows it's using kqueue/IOCP with a ring design.
@@ -81,7 +80,7 @@ pub const Loop = struct {
// contexts are correcly free.
while (self.eventsNb() > 0) {
self.io.run_for_ns(10 * std.time.ns_per_ms) catch |err| {
log.err("deinit run tail events: {any}", .{err});
log.err(.loop, "deinit", .{ .err = err });
break;
};
}
@@ -176,7 +175,7 @@ pub const Loop = struct {
result catch |err| {
switch (err) {
error.Canceled => {},
else => log.err("timeout callback: {any}", .{err}),
else => log.err(.loop, "timeout callback error", .{ .err = err }),
}
return;
};

25
src/server.zig
View File

@@ -25,6 +25,7 @@ const posix = std.posix;
const Allocator = std.mem.Allocator;
const ArenaAllocator = std.heap.ArenaAllocator;
const log = @import("log.zig");
const IO = @import("runtime/loop.zig").IO;
const Completion = IO.Completion;
const AcceptError = IO.AcceptError;
@@ -38,8 +39,6 @@ const CDP = @import("cdp/cdp.zig").CDP;
const TimeoutCheck = std.time.ns_per_ms * 100;
const log = std.log.scoped(.server);
const MAX_HTTP_REQUEST_SIZE = 2048;
// max message size
@@ -67,7 +66,7 @@ const Server = struct {
}
fn queueAccept(self: *Server) void {
log.info("accepting new conn...", .{});
log.debug(.server, "accepting connection", .{});
self.loop.io.accept(
*Server,
self,
@@ -84,7 +83,7 @@ const Server = struct {
) void {
std.debug.assert(completion == &self.accept_completion);
self.doCallbackAccept(result) catch |err| {
log.err("accept error: {any}", .{err});
log.err(.server, "accept error", .{ .err = err });
self.queueAccept();
};
}
@@ -97,7 +96,13 @@ const Server = struct {
const client = try self.allocator.create(Client);
client.* = Client.init(socket, self);
client.start();
log.info("client connected", .{});
if (log.enabled(.server, .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 });
}
}
fn releaseClient(self: *Server, client: *Client) void {
@@ -250,7 +255,7 @@ pub const Client = struct {
}
const size = result catch |err| {
log.err("read error: {any}", .{err});
log.err(.server, "read error", .{ .err = err });
self.close();
return;
};
@@ -313,7 +318,7 @@ pub const Client = struct {
error.InvalidVersionHeader => self.writeHTTPErrorResponse(400, "Invalid websocket version"),
error.InvalidConnectionHeader => self.writeHTTPErrorResponse(400, "Invalid connection header"),
else => {
log.err("error processing HTTP request: {any}", .{err});
log.err(.server, "http 500", .{ .err = err });
self.writeHTTPErrorResponse(500, "Internal Server Error");
},
}
@@ -594,6 +599,7 @@ pub const Client = struct {
if (result) |_| {
if (now().since(self.last_active) >= self.server.timeout) {
log.info(.server, "connection timeout", .{});
if (self.mode == .websocket) {
self.send(null, &CLOSE_TIMEOUT) catch {};
}
@@ -601,7 +607,7 @@ pub const Client = struct {
return;
}
} else |err| {
log.err("timeout error: {any}", .{err});
log.err(.server, "timeout error", .{ .err = err });
}
self.queueTimeout();
@@ -650,7 +656,7 @@ pub const Client = struct {
}
const sent = result catch |err| {
log.info("send error: {any}", .{err});
log.warn(.server, "send error", .{ .err = err });
self.close();
return;
};
@@ -1036,6 +1042,7 @@ pub fn run(
// accept an connection
server.queueAccept();
log.info(.server, "running", .{ .address = address });
// infinite loop on I/O events, either:
// - cmd from incoming connection on server socket

6
src/telemetry/lightpanda.zig
View File

@@ -5,11 +5,11 @@ const build_config = @import("build_config");
const Thread = std.Thread;
const Allocator = std.mem.Allocator;
const log = @import("../log.zig");
const App = @import("../app.zig").App;
const telemetry = @import("telemetry.zig");
const HttpClient = @import("../http/client.zig").Client;
const log = std.log.scoped(.telemetry);
const URL = "https://telemetry.lightpanda.io";
const MAX_BATCH_SIZE = 20;
@@ -83,7 +83,7 @@ pub const LightPanda = struct {
const b = self.collectBatch(&batch);
self.mutex.unlock();
self.postEvent(b, &arr) catch |err| {
log.warn("Telementry reporting error: {}", .{err});
log.warn(.telemetry, "post error", .{ .err = err });
};
self.mutex.lock();
}
@@ -110,7 +110,7 @@ pub const LightPanda = struct {
var res = try req.sendSync(.{});
while (try res.next()) |_| {}
if (res.header.status != 200) {
log.warn("server error status: {d}", .{res.header.status});
log.warn(.telemetry, "server error", .{ .status = res.header.status });
}
}

12
src/telemetry/telemetry.zig
View File

@@ -3,11 +3,11 @@ const builtin = @import("builtin");
const Allocator = std.mem.Allocator;
const log = @import("../log.zig");
const App = @import("../app.zig").App;
const Notification = @import("../notification.zig").Notification;
const uuidv4 = @import("../id.zig").uuidv4;
const log = std.log.scoped(.telemetry);
const IID_FILE = "iid";
pub const Telemetry = TelemetryT(blk: {
@@ -32,7 +32,7 @@ fn TelemetryT(comptime P: type) type {
pub fn init(app: *App, run_mode: App.RunMode) Self {
const disabled = std.process.hasEnvVarConstant("LIGHTPANDA_DISABLE_TELEMETRY");
if (builtin.mode != .Debug and builtin.is_test == false) {
log.info("telemetry {s}", .{if (disabled) "disabled" else "enabled"});
log.info(.telemetry, "telemetry status", .{ .disabled = disabled });
}
return .{
@@ -53,7 +53,7 @@ fn TelemetryT(comptime P: type) type {
}
const iid: ?[]const u8 = if (self.iid) |*iid| iid else null;
self.provider.send(iid, self.run_mode, event) catch |err| {
log.warn("failed to record event: {}", .{err});
log.warn(.telemetry, "record error", .{ .err = err, .type = @tagName(std.meta.activeTag(event)) });
};
}
@@ -94,7 +94,7 @@ fn getOrCreateId(app_dir_path_: ?[]const u8) ?[36]u8 {
var buf: [37]u8 = undefined;
var dir = std.fs.openDirAbsolute(app_dir_path, .{}) catch |err| {
log.warn("failed to open data directory '{s}': {}", .{ app_dir_path, err });
log.warn(.telemetry, "data directory open error", .{ .path = app_dir_path, .err = err });
return null;
};
defer dir.close();
@@ -102,7 +102,7 @@ fn getOrCreateId(app_dir_path_: ?[]const u8) ?[36]u8 {
const data = dir.readFile(IID_FILE, &buf) catch |err| switch (err) {
error.FileNotFound => &.{},
else => {
log.warn("failed to open id file: {}", .{err});
log.warn(.telemetry, "ID read error", .{ .path = app_dir_path, .err = err });
return null;
},
};
@@ -115,7 +115,7 @@ fn getOrCreateId(app_dir_path_: ?[]const u8) ?[36]u8 {
uuidv4(&id);
dir.writeFile(.{ .sub_path = IID_FILE, .data = &id }) catch |err| {
log.warn("failed to write to id file: {}", .{err});
log.warn(.telemetry, "ID write error", .{ .path = app_dir_path, .err = err });
return null;
};
return id;