From fa5b3f240e1017a1cd0ef81b29ee3d5b028eabcb Mon Sep 17 00:00:00 2001 From: Bob Farrell Date: Wed, 30 Oct 2024 21:42:56 +0000 Subject: [PATCH] WIP --- build.zig | 18 +++- cli/cli.zig | 2 + cli/commands/database.zig | 2 +- src/jetzig.zig | 2 + src/jetzig/App.zig | 17 ++-- src/jetzig/Environment.zig | 108 +++++++++++++++----- src/jetzig/database.zig | 12 ++- src/jetzig/loggers.zig | 6 ++ src/jetzig/loggers/DevelopmentLogger.zig | 121 +++++++++++++++++++++++ src/jetzig/loggers/JsonLogger.zig | 11 +++ src/jetzig/loggers/TestLogger.zig | 4 + 11 files changed, 265 insertions(+), 38 deletions(-) diff --git a/build.zig b/build.zig index 629f5e8..05ee386 100644 --- a/build.zig +++ b/build.zig @@ -128,9 +128,19 @@ pub fn jetzigInit(b: *std.Build, exe: *std.Build.Step.Compile, options: JetzigIn if (optimize != .Debug) exe.linkLibC(); + const Environment = enum { development, testing, production }; + const environment = b.option( + Environment, + "environment", + "Jetzig server environment.", + ) orelse .development; + const jetzig_dep = b.dependency( "jetzig", - .{ .optimize = optimize, .target = target }, + .{ + .optimize = optimize, + .target = target, + }, ); const jetzig_module = jetzig_dep.module("jetzig"); const zmpl_module = jetzig_dep.module("zmpl"); @@ -140,6 +150,12 @@ pub fn jetzigInit(b: *std.Build, exe: *std.Build.Step.Compile, options: JetzigIn const jetcommon_module = jetzig_dep.module("jetcommon"); const jetquery_migrate_module = jetzig_dep.module("jetquery_migrate"); + { + const build_options = b.addOptions(); + build_options.addOption(Environment, "environment", environment); + jetzig_module.addOptions("build_config", build_options); + } + exe.root_module.addImport("jetzig", jetzig_module); exe.root_module.addImport("zmpl", zmpl_module); exe.root_module.addImport("zmd", zmd_module); diff --git a/cli/cli.zig b/cli/cli.zig index 0e88616..db99492 100644 --- a/cli/cli.zig +++ b/cli/cli.zig @@ -11,9 +11,11 @@ const database = @import("commands/database.zig"); const Options = struct { help: bool = false, + environment: enum { development, testing, production }, pub const shorthands = .{ .h = "help", + .e = "environment", }; pub const meta = .{ diff --git a/cli/commands/database.zig b/cli/commands/database.zig index 23efb90..e29a92d 100644 --- a/cli/commands/database.zig +++ b/cli/commands/database.zig @@ -7,7 +7,7 @@ const Migrate = @import("jetquery_migrate"); /// Command line options for the `database` command. pub const Options = struct { pub const meta = .{ - .usage_summary = "[migrate]", + .usage_summary = "[migrate|rollback|create|drop]", .full_text = \\Manage the application's database. \\ diff --git a/src/jetzig.zig b/src/jetzig.zig index 77f743d..72cffff 100644 --- a/src/jetzig.zig +++ b/src/jetzig.zig @@ -26,6 +26,8 @@ pub const DateTime = jetcommon.types.DateTime; pub const Time = jetcommon.types.Time; pub const Date = jetcommon.types.Date; +pub const environment = @import("build_config").environment; + /// The primary interface for a Jetzig application. Create an `App` in your application's /// `src/main.zig` and call `start` to launch the application. pub const App = @import("jetzig/App.zig"); diff --git a/src/jetzig/App.zig b/src/jetzig/App.zig index 153bbe9..22c57ca 100644 --- a/src/jetzig/App.zig +++ b/src/jetzig/App.zig @@ -36,10 +36,13 @@ pub fn start(self: *const App, routes_module: type, options: AppOptions) !void { try mime_map.build(); const routes = try createRoutes(self.allocator, &routes_module.routes); - defer for (routes) |var_route| { - var_route.deinitParams(); - self.allocator.destroy(var_route); - }; + defer { + for (routes) |var_route| { + var_route.deinitParams(); + self.allocator.destroy(var_route); + } + self.allocator.free(routes); + } defer for (self.custom_routes.items) |custom_route| { self.allocator.free(custom_route.template); @@ -63,6 +66,9 @@ pub fn start(self: *const App, routes_module: type, options: AppOptions) !void { ); defer cache.deinit(); + var repo = try jetzig.database.repo(self.allocator, self); + defer repo.deinit(); + var log_thread = try std.Thread.spawn( .{ .allocator = self.allocator }, jetzig.loggers.LogQueue.Reader.publish, @@ -70,9 +76,6 @@ pub fn start(self: *const App, routes_module: type, options: AppOptions) !void { ); defer log_thread.join(); - var repo = try jetzig.database.repo(self.allocator, self); - defer repo.deinit(); - if (self.env.detach) { const argv = try std.process.argsAlloc(self.allocator); defer std.process.argsFree(self.allocator, argv); diff --git a/src/jetzig/Environment.zig b/src/jetzig/Environment.zig index ae02ca1..72b4081 100644 --- a/src/jetzig/Environment.zig +++ b/src/jetzig/Environment.zig @@ -7,6 +7,8 @@ const jetzig = @import("../jetzig.zig"); const Environment = @This(); allocator: std.mem.Allocator, +parent_allocator: std.mem.Allocator, +arena: *std.heap.ArenaAllocator, logger: jetzig.loggers.Logger, bind: []const u8, port: u16, @@ -60,10 +62,10 @@ const Options = struct { help: bool = false, bind: []const u8 = "127.0.0.1", port: u16 = 8080, - environment: EnvironmentName = .development, log: []const u8 = "-", @"log-error": []const u8 = "-", @"log-level": ?jetzig.loggers.LogLevel = null, + // TODO: Create a production logger and select default logger based on environment. @"log-format": jetzig.loggers.LogFormat = .development, detach: bool = false, @@ -71,7 +73,6 @@ const Options = struct { .h = "help", .b = "bind", .p = "port", - .e = "environment", .d = "detach", }; @@ -81,7 +82,6 @@ const Options = struct { .option_docs = .{ .bind = "IP address/hostname to bind to (default: 127.0.0.1)", .port = "Port to listen on (default: 8080)", - .environment = "Set the server environment. Must be one of: { development, production } (default: development)", .log = "Path to log file. Use '-' for stdout (default: '-')", .@"log-error" = \\Optional path to separate error log file. Use '-' for stderr. If omitted, errors are logged to the location specified by the `log` option (or stderr if `log` is '-'). @@ -100,7 +100,30 @@ const Options = struct { }; }; -pub fn init(allocator: std.mem.Allocator) !Environment { +const LaunchLogger = struct { + stdout: std.fs.File, + stderr: std.fs.File, + + pub fn log( + self: LaunchLogger, + comptime level: jetzig.loggers.LogLevel, + comptime message: []const u8, + log_args: anytype, + ) !void { + const target = @field(self, @tagName(jetzig.loggers.logTarget(level))); + const writer = target.writer(); + try writer.print( + std.fmt.comptimePrint("[startup:{s}] {s}\n", .{ @tagName(level), message }), + log_args, + ); + } +}; + +pub fn init(parent_allocator: std.mem.Allocator) !Environment { + const arena = try parent_allocator.create(std.heap.ArenaAllocator); + arena.* = std.heap.ArenaAllocator.init(parent_allocator); + const allocator = arena.allocator(); + const options = try args.parseForCurrentProcess(Options, allocator, .print); defer options.deinit(); @@ -117,10 +140,15 @@ pub fn init(allocator: std.mem.Allocator) !Environment { std.process.exit(0); } - const environment = options.options.environment; + const environment = std.enums.nameCast(EnvironmentName, jetzig.environment); const vars = Vars{ .env_map = try std.process.getEnvMap(allocator) }; - var logger = switch (options.options.@"log-format") { + var launch_logger = LaunchLogger{ + .stdout = try getLogFile(.stdout, options.options), + .stderr = try getLogFile(.stdout, options.options), + }; + + const logger = switch (options.options.@"log-format") { .development => jetzig.loggers.Logger{ .development_logger = jetzig.loggers.DevelopmentLogger.init( allocator, @@ -138,30 +166,51 @@ pub fn init(allocator: std.mem.Allocator) !Environment { }; if (options.options.detach and std.mem.eql(u8, options.options.log, "-")) { - try logger.ERROR("Must pass `--log` when using `--detach`.", .{}); + try launch_logger.log(.ERROR, "Must pass `--log` when using `--detach`.", .{}); std.process.exit(1); } const secret_len = jetzig.http.Session.Cipher.key_length; - const secret = (try getSecret(allocator, &logger, secret_len, environment))[0..secret_len]; + const secret_value = try getSecret(allocator, launch_logger, secret_len, environment); + const secret = if (secret_value.len > secret_len) secret_value[0..secret_len] else secret_value; if (secret.len != secret_len) { - try logger.ERROR("Expected secret length: {}, found: {}.", .{ secret_len, secret.len }); - try logger.ERROR("Use `jetzig generate secret` to create a secure secret value.", .{}); + try launch_logger.log( + .ERROR, + "Expected secret length: {}, found: {}.", + .{ secret_len, secret.len }, + ); + try launch_logger.log( + .ERROR, + "Use `jetzig generate secret` to create a secure secret value.", + .{}, + ); std.process.exit(1); } if (jetzig.database.adapter == .null) { - try logger.WARN("No database configured in `config/database.zig`. Database operations are not available.", .{}); + try launch_logger.log( + .WARN, + "No database configured in `config/database.zig`. Database operations are not available.", + .{}, + ); } else { - try logger.INFO( + try launch_logger.log( + .INFO, "Using `{s}` database adapter with database: `{s}`.", - .{ @tagName(jetzig.database.adapter), jetzig.jetquery.config.database.database }, + .{ + @tagName(jetzig.database.adapter), + switch (environment) { + inline else => |tag| @field(jetzig.jetquery.config.database, @tagName(tag)).database, + }, + }, ); } return .{ .allocator = allocator, + .parent_allocator = parent_allocator, + .arena = arena, .logger = logger, .secret = secret, .bind = try allocator.dupe(u8, options.options.bind), @@ -174,9 +223,8 @@ pub fn init(allocator: std.mem.Allocator) !Environment { } pub fn deinit(self: Environment) void { - self.vars.deinit(); - self.allocator.free(self.bind); - self.allocator.free(self.secret); + self.arena.deinit(); + self.parent_allocator.destroy(self.arena); } fn getLogFile(stream: enum { stdout, stderr }, options: Options) !std.fs.File { @@ -200,7 +248,7 @@ fn getLogFile(stream: enum { stdout, stderr }, options: Options) !std.fs.File { fn getSecret( allocator: std.mem.Allocator, - logger: *jetzig.loggers.Logger, + logger: LaunchLogger, comptime len: u10, environment: EnvironmentName, ) ![]const u8 { @@ -209,18 +257,28 @@ fn getSecret( return std.process.getEnvVarOwned(allocator, env_var) catch |err| { switch (err) { error.EnvironmentVariableNotFound => { - if (environment != .development) { - try logger.ERROR("Environment variable `{s}` must be defined in production mode.", .{env_var}); - try logger.ERROR("Run `jetzig generate secret` to generate an appropriate value.", .{}); + if (environment == .production) { + try logger.log( + .ERROR, + "Environment variable `{s}` must be defined in production mode.", + .{env_var}, + ); + try logger.log( + .ERROR, + "Run `jetzig generate secret` to generate an appropriate value.", + .{}, + ); std.process.exit(1); } const secret = try jetzig.util.generateSecret(allocator, len); - try logger.WARN( - "Running in development mode, using auto-generated cookie encryption key: {s}", - .{secret}, + try logger.log( + .WARN, + "Running in {s} mode, using auto-generated cookie encryption key: {s}", + .{ @tagName(environment), secret }, ); - try logger.WARN( + try logger.log( + .WARN, "Run `jetzig generate secret` and set `JETZIG_SECRET` to remove this warning.", .{}, ); @@ -236,6 +294,6 @@ fn resolveLogLevel(level: ?jetzig.loggers.LogLevel, environment: EnvironmentName return level orelse switch (environment) { .testing => .DEBUG, .development => .DEBUG, - .production => .INFO, + .production => .DEBUG, }; } diff --git a/src/jetzig/database.zig b/src/jetzig/database.zig index 51638bc..c30df34 100644 --- a/src/jetzig/database.zig +++ b/src/jetzig/database.zig @@ -2,9 +2,9 @@ const std = @import("std"); const jetzig = @import("../jetzig.zig"); +pub const adapter = @field(jetzig.jetquery.config.database, @tagName(jetzig.environment)).adapter; pub const Schema = jetzig.config.get(type, "Schema"); -pub const adapter = jetzig.jetquery.config.database.adapter; -pub const Repo = jetzig.jetquery.Repo(jetzig.jetquery.config.database.adapter, Schema); +pub const Repo = jetzig.jetquery.Repo(adapter, Schema); pub fn Query(comptime model: anytype) type { return jetzig.jetquery.Query(adapter, Schema, model); @@ -22,12 +22,16 @@ pub fn repo(allocator: std.mem.Allocator, app: *const jetzig.App) !Repo { return try Repo.loadConfig( allocator, - .{ .eventCallback = Callback.callbackFn, .lazy_connect = true }, + std.enums.nameCast(jetzig.jetquery.Environment, jetzig.environment), + .{ + .eventCallback = Callback.callbackFn, + .lazy_connect = jetzig.environment == .development, + }, ); } fn eventCallback(event: jetzig.jetquery.events.Event, app: *const jetzig.App) !void { - try app.server.logger.INFO("[database] {?s}", .{event.sql}); + try app.server.logger.logSql(event); if (event.err) |err| { try app.server.logger.ERROR("[database] {?s}", .{err.message}); } diff --git a/src/jetzig/loggers.zig b/src/jetzig/loggers.zig index 95fc583..7c8502c 100644 --- a/src/jetzig/loggers.zig +++ b/src/jetzig/loggers.zig @@ -72,6 +72,12 @@ pub const Logger = union(enum) { } } + pub fn logSql(self: *const Logger, request: jetzig.jetquery.events.Event) !void { + switch (self.*) { + inline else => |*logger| try logger.logSql(request), + } + } + pub fn logError(self: *const Logger, err: anyerror) !void { switch (self.*) { inline else => |*logger| try logger.logError(err), diff --git a/src/jetzig/loggers/DevelopmentLogger.zig b/src/jetzig/loggers/DevelopmentLogger.zig index 44d65dd..34b58b1 100644 --- a/src/jetzig/loggers/DevelopmentLogger.zig +++ b/src/jetzig/loggers/DevelopmentLogger.zig @@ -104,6 +104,127 @@ pub fn logRequest(self: DevelopmentLogger, request: *const jetzig.http.Request) }, .stdout); } +pub fn logSql(self: *const DevelopmentLogger, event: jetzig.jetquery.events.Event) !void { + // XXX: This function does not make any effort to prevent log messages clobbering each other + // from multiple threads. JSON logger etc. write in one call and the logger's mutex prevents + // clobbering, but this is not the case here. + const formatted_level = if (self.stdout_colorized) colorizedLogLevel(.INFO) else @tagName(.INFO); + try self.log_queue.print( + "{s} [database] ", + .{formatted_level}, + .stdout, + ); + try self.printSql(event.sql orelse ""); + + var duration_buf: [256]u8 = undefined; + const formatted_duration = if (event.duration) |duration| try jetzig.colors.duration( + &duration_buf, + duration, + self.stdout_colorized, + ) else ""; + + try self.log_queue.print( + std.fmt.comptimePrint(" [{s}]\n", .{jetzig.colors.cyan("{s}")}), + .{formatted_duration}, + .stdout, + ); +} + +const sql_tokens = .{ + "SELECT", + "INSERT", + "UPDATE", + "DELETE", + "WHERE", + "ANY", + "FROM", + "INTO", + "IN", + "IS", + "NOT", + "NULL", + "LIMIT", + "ORDER BY", + "GROUP BY", + "HAVING", + "LEFT OUTER JOIN", + "INNER JOIN", + "ASC", + "DESC", + "MAX", + "MIN", + "COUNT", + "SUM", +}; + +fn printSql(self: *const DevelopmentLogger, sql: []const u8) !void { + const string_color = jetzig.colors.codes.escape ++ jetzig.colors.codes.green; + const identifier_color = jetzig.colors.codes.escape ++ jetzig.colors.codes.yellow; + const reset_color = jetzig.colors.codes.escape ++ jetzig.colors.codes.reset; + + var index: usize = 0; + var single_quote: bool = false; + var double_quote: bool = false; + while (index < sql.len) { + // TODO: Escapes + switch (sql[index]) { + '"' => { + if (!single_quote) { + double_quote = !double_quote; + if (double_quote) { + try self.log_queue.print(identifier_color ++ "\"", .{}, .stdout); + } else { + try self.log_queue.print("\"" ++ reset_color, .{}, .stdout); + } + index += 1; + } + }, + '\'' => { + if (!double_quote) { + single_quote = !single_quote; + if (single_quote) { + try self.log_queue.print(string_color ++ "'", .{}, .stdout); + } else { + try self.log_queue.print("'" ++ reset_color, .{}, .stdout); + } + } + index += 1; + }, + '$' => { + if (double_quote or single_quote) { + try self.log_queue.print("{c}", .{sql[index]}, .stdout); + index += 1; + } else { + const param = sql[index..][0 .. std.mem.indexOfAny( + u8, + sql[index..], + &std.ascii.whitespace, + ) orelse sql.len - index]; + try self.log_queue.print(jetzig.colors.magenta("{s}"), .{param}, .stdout); + index += param.len; + } + }, + else => { + if (double_quote or single_quote) { + try self.log_queue.print("{c}", .{sql[index]}, .stdout); + index += 1; + } else { + inline for (sql_tokens) |token| { + if (std.mem.startsWith(u8, sql[index..], token)) { + try self.log_queue.print(jetzig.colors.cyan(token), .{}, .stdout); + index += token.len; + break; + } + } else { + try self.log_queue.print("{c}", .{sql[index]}, .stdout); + index += 1; + } + } + }, + } + } +} + pub fn logError(self: *const DevelopmentLogger, err: anyerror) !void { if (@errorReturnTrace()) |stack| { try self.log(.ERROR, "\nStack Trace:\n{}", .{stack}); diff --git a/src/jetzig/loggers/JsonLogger.zig b/src/jetzig/loggers/JsonLogger.zig index eb960d3..a17612f 100644 --- a/src/jetzig/loggers/JsonLogger.zig +++ b/src/jetzig/loggers/JsonLogger.zig @@ -101,6 +101,17 @@ pub fn logRequest(self: *const JsonLogger, request: *const jetzig.http.Request) try self.log_queue.print("{s}\n", .{stream.getWritten()}, .stdout); } +pub fn logSql(self: *const JsonLogger, event: jetzig.jetquery.events.Event) !void { + var buf: [4096]u8 = undefined; + var stream = std.io.fixedBufferStream(&buf); + try std.json.stringify( + .{ .sql = event.sql, .duration = event.duration }, + .{ .whitespace = .minified }, + stream.writer(), + ); + try self.log_queue.print("{s}\n", .{stream.getWritten()}, .stdout); +} + pub fn logError(self: *const JsonLogger, err: anyerror) !void { try self.log(.ERROR, "Encountered error: {s}", .{@errorName(err)}); } diff --git a/src/jetzig/loggers/TestLogger.zig b/src/jetzig/loggers/TestLogger.zig index 65cae9a..6ffe5ff 100644 --- a/src/jetzig/loggers/TestLogger.zig +++ b/src/jetzig/loggers/TestLogger.zig @@ -41,6 +41,10 @@ pub fn logRequest(self: TestLogger, request: *const jetzig.http.Request) !void { }); } +pub fn logSql(self: TestLogger, event: jetzig.jetquery.events.Event) !void { + try self.log(.INFO, "[database] {?s}", .{event.sql}); +} + pub fn logError(self: TestLogger, err: anyerror) !void { try self.log(.ERROR, "Encountered error: {s}", .{@errorName(err)}); }