Merge pull request #1119 from lightpanda-io/cdp_log_entry

Emit Log.addEntry

Author: karlseguin

src/browser/events/mouse_event.zig

@@ -68,7 +68,7 @@ pub const MouseEvent = struct {
         });
 
         if (!std.mem.eql(u8, event_type, "click")) {
-            log.warn(.mouse_event, "unsupported mouse event", .{ .event = event_type });
+            log.warn(.browser, "unsupported mouse event", .{ .event = event_type });
         }
 
         return mouse_event;

src/cdp/cdp.zig

@@ -30,6 +30,7 @@ const Session = @import("../browser/session.zig").Session;
 const Page = @import("../browser/page.zig").Page;
 const Incrementing = @import("../id.zig").Incrementing;
 const Notification = @import("../notification.zig").Notification;
+const LogInterceptor = @import("domains/log.zig").LogInterceptor;
 const InterceptState = @import("domains/fetch.zig").InterceptState;
 
 pub const URL_BASE = "chrome://newtab/";
@@ -338,6 +339,8 @@ pub fn BrowserContext(comptime CDP_T: type) type {
 
         intercept_state: InterceptState,
 
+        log_interceptor: LogInterceptor(Self),
+
         // When network is enabled, we'll capture the transfer.id -> body
         // This is awfully memory intensive, but our underlying http client and
         // its users (script manager and page) correctly do not hold the body
@@ -378,6 +381,7 @@ pub fn BrowserContext(comptime CDP_T: type) type {
                 .notification_arena = cdp.notification_arena.allocator(),
                 .intercept_state = try InterceptState.init(allocator),
                 .captured_responses = .empty,
+                .log_interceptor = LogInterceptor(Self).init(allocator, self),
             };
             self.node_search_list = Node.Search.List.init(allocator, &self.node_registry);
             errdefer self.deinit();
@@ -389,6 +393,10 @@ pub fn BrowserContext(comptime CDP_T: type) type {
         }
 
         pub fn deinit(self: *Self) void {
+            // safe to call even if never registered
+            log.unregisterInterceptor();
+            self.log_interceptor.deinit();
+
             self.inspector.deinit();
 
             // abort all intercepted requests before closing the sesion/page
@@ -496,6 +504,18 @@ pub fn BrowserContext(comptime CDP_T: type) type {
             self.cdp.browser.notification.unregister(.page_network_almost_idle, self);
         }
 
+        pub fn logEnable(self: *Self) void {
+            log.registerInterceptor(.{
+                .ctx = &self.log_interceptor,
+                .done = LogInterceptor(Self).done,
+                .writer = LogInterceptor(Self).writer,
+            });
+        }
+
+        pub fn logDisable(_: *const Self) void {
+            log.unregisterInterceptor();
+        }
+
         pub fn onPageRemove(ctx: *anyopaque, _: Notification.PageRemove) !void {
             const self: *Self = @ptrCast(@alignCast(ctx));
             try @import("domains/page.zig").pageRemove(self);

src/cdp/domains/log.zig

@@ -17,13 +17,97 @@
 // along with this program.  If not, see <https://www.gnu.org/licenses/>.
 
 const std = @import("std");
+const log = @import("../../log.zig");
+
+const Allocator = std.mem.Allocator;
 
 pub fn processMessage(cmd: anytype) !void {
     const action = std.meta.stringToEnum(enum {
         enable,
+        disable,
     }, cmd.input.action) orelse return error.UnknownMethod;
 
     switch (action) {
-        .enable => return cmd.sendResult(null, .{}),
+        .enable => return enable(cmd),
+        .disable => return disable(cmd),
     }
 }
+fn enable(cmd: anytype) !void {
+    const bc = cmd.browser_context orelse return error.BrowserContextNotLoaded;
+    bc.logEnable();
+    return cmd.sendResult(null, .{});
+}
+
+fn disable(cmd: anytype) !void {
+    const bc = cmd.browser_context orelse return error.BrowserContextNotLoaded;
+    bc.logDisable();
+    return cmd.sendResult(null, .{});
+}
+
+pub fn LogInterceptor(comptime BC: type) type {
+    return struct {
+        bc: *BC,
+        allocating: std.Io.Writer.Allocating,
+
+        const Self = @This();
+
+        pub fn init(allocator: Allocator, bc: *BC) Self {
+            return .{
+                .bc = bc,
+                .allocating = .init(allocator),
+            };
+        }
+
+        pub fn deinit(self: *Self) void {
+            return self.allocating.deinit();
+        }
+
+        pub fn writer(ctx: *anyopaque, scope: log.Scope, level: log.Level) ?*std.Io.Writer {
+            if (scope == .unknown_prop or scope == .telemetry) {
+                return null;
+            }
+
+            // DO NOT REMOVE this. This prevents a log message caused from a failure
+            // to intercept to trigger another intercept, which could result in an
+            // endless cycle.
+            if (scope == .interceptor) {
+                return null;
+            }
+
+            if (level == .debug) {
+                return null;
+            }
+            const self: *Self = @ptrCast(@alignCast(ctx));
+            return &self.allocating.writer;
+        }
+
+        pub fn done(ctx: *anyopaque, scope: log.Scope, level: log.Level) void {
+            const self: *Self = @ptrCast(@alignCast(ctx));
+            defer self.allocating.clearRetainingCapacity();
+
+            self.bc.cdp.sendEvent("Log.entryAdded", .{
+                .entry = .{
+                    .source = switch (scope) {
+                        .js, .user_script, .console, .web_api, .script_event => "javascript",
+                        .http, .fetch, .xhr => "network",
+                        .telemetry, .unknown_prop, .interceptor => unreachable, // filtered out in writer above
+                        else => "other",
+                    },
+                    .level = switch (level) {
+                        .debug => "verbose",
+                        .info => "info",
+                        .warn => "warning",
+                        .err => "error",
+                        .fatal => "error",
+                    },
+                    .text = self.allocating.written(),
+                    .timestamp = @import("../../datetime.zig").milliTimestamp(),
+                },
+            }, .{
+                .session_id = self.bc.session_id,
+            }) catch |err| {
+                log.err(.interceptor, "failed to send", .{.err = err});
+            };
+        }
+    };
+}

src/log.zig

@@ -29,7 +29,6 @@ pub const Scope = enum {
     cdp,
     console,
     http,
-    http_client,
     js,
     loop,
     script_event,
@@ -40,7 +39,7 @@ pub const Scope = enum {
     xhr,
     fetch,
     polyfill,
-    mouse_event,
+    interceptor,
 };
 
 const Opts = struct {
@@ -148,6 +147,13 @@ fn logTo(comptime scope: Scope, level: Level, comptime msg: []const u8, data: an
         .pretty => try logPretty(scope, level, msg, data, out),
     }
     out.flush() catch return;
+
+    const interceptor = _interceptor orelse return;
+    if (interceptor.writer(interceptor.ctx, scope, level)) |iwriter| {
+        try logLogfmt(scope, level, msg, data, iwriter);
+        try iwriter.flush();
+        interceptor.done(interceptor.ctx, scope, level);
+    }
 }
 
 fn logLogfmt(comptime scope: Scope, level: Level, comptime msg: []const u8, data: anytype, writer: anytype) !void {
@@ -346,6 +352,24 @@ fn elapsed() struct { time: f64, unit: []const u8 } {
     return .{ .time = @as(f64, @floatFromInt(e)) / @as(f64, 1000), .unit = "s" };
 }
 
+var _interceptor: ?Interceptor = null;
+pub fn registerInterceptor(interceptor: Interceptor) void {
+    _interceptor = interceptor;
+}
+
+pub fn unregisterInterceptor() void {
+    _interceptor = null;
+}
+
+const Interceptor = struct {
+    ctx: *anyopaque,
+    done: DoneFunc,
+    writer: WriterFunc,
+
+    const DoneFunc = *const fn (ctx: *anyopaque, scope: Scope, level: Level) void;
+    const WriterFunc = *const fn (ctx: *anyopaque, scope: Scope, level: Level) ?*std.Io.Writer;
+};
+
 const testing = @import("testing.zig");
 test "log: data" {
     opts.format = .logfmt;