| @@ -9,6 +9,15 @@ pub const LogLevel = enum { |
| 9 | 9 | Warning, |
| 10 | 10 | Error, |
| 11 | 11 | Fatal, |
| 12 | + /// Record nothing. |
| 13 | + /// |
| 14 | + /// Last, so the existing `level >= min_level` comparison silences |
| 15 | + /// everything when it is the minimum — no branch anywhere else has to know |
| 16 | + /// about it. `logging.zig` has had an `off` for as long as it has existed; |
| 17 | + /// this side had no way to say the same thing, so an app that wanted |
| 18 | + /// quiet had to not configure logging at all, which is not the same as |
| 19 | + /// asking for it. |
| 20 | + Off, |
| 12 | 21 | |
| 13 | 22 | pub fn toString(self: LogLevel) []const u8 { |
| 14 | 23 | return switch (self) { |
| @@ -17,6 +26,7 @@ pub const LogLevel = enum { |
| 17 | 26 | .Warning => "WARN", |
| 18 | 27 | .Error => "ERROR", |
| 19 | 28 | .Fatal => "FATAL", |
| 29 | + .Off => "OFF", |
| 20 | 30 | }; |
| 21 | 31 | } |
| 22 | 32 | |
| @@ -27,6 +37,8 @@ pub const LogLevel = enum { |
| 27 | 37 | .Warning => "\x1B[33m", // Yellow |
| 28 | 38 | .Error => "\x1B[31m", // Red |
| 29 | 39 | .Fatal => "\x1B[35m", // Magenta |
| 40 | + // Never emitted; a record at this level is filtered before formatting. |
| 41 | + .Off => "", |
| 30 | 42 | }; |
| 31 | 43 | } |
| 32 | 44 | }; |
| @@ -96,6 +108,12 @@ threadlocal var in_log: bool = false; |
| 96 | 108 | /// reachable from inside a log call. Captured once instead. |
| 97 | 109 | var log_io: ?std.Io = null; |
| 98 | 110 | |
| 111 | +/// Whether stderr is a terminal, decided once at `init`. |
| 112 | +/// |
| 113 | +/// Per-record would mean an `isatty` on every line, and the answer cannot |
| 114 | +/// change for a running process anyway. |
| 115 | +var stderr_is_tty: bool = false; |
| 116 | + |
| 99 | 117 | pub fn init(config: LogConfig) !void { |
| 100 | 118 | log_mutex.lock(); |
| 101 | 119 | defer log_mutex.unlock(); |
| @@ -110,6 +128,7 @@ pub fn init(config: LogConfig) !void { |
| 110 | 128 | current_config = config; |
| 111 | 129 | log_file_offset = 0; |
| 112 | 130 | log_io = io_context.get(); |
| 131 | + stderr_is_tty = std.Io.File.stderr().isTty(log_io.?) catch false; |
| 113 | 132 | |
| 114 | 133 | // Take copies before anything else can free the originals. |
| 115 | 134 | if (config.output_file) |path| { |
| @@ -297,28 +316,41 @@ pub fn log( |
| 297 | 316 | } |
| 298 | 317 | |
| 299 | 318 | output_len = formatTruncating(&output_buf, "\n", .{ timestamp, level.toString(), esc_buf[0..esc_len] }).len; |
| 319 | + } else if (current_config.enable_timestamps) { |
| 320 | + output_len = formatTruncating(&output_buf, "[{s}] {s} {s}\n", .{ timestamp, level.toString(), message }).len; |
| 300 | 321 | } else { |
| 301 | | - // Standard output |
| 302 | | - const reset = "\x1B[0m"; |
| 303 | | - const dim = "\x1B[2m"; |
| 304 | | - |
| 305 | | - if (current_config.enable_timestamps and current_config.enable_colors) { |
| 306 | | - output_len = formatTruncating(&output_buf, "{s}[{s}]{s} {s}{s}{s} {s}\n", .{ dim, timestamp, reset, level.color(), level.toString(), reset, message }).len; |
| 307 | | - } else if (current_config.enable_timestamps) { |
| 308 | | - output_len = formatTruncating(&output_buf, "[{s}] {s} {s}\n", .{ timestamp, level.toString(), message }).len; |
| 309 | | - } else if (current_config.enable_colors) { |
| 310 | | - output_len = formatTruncating(&output_buf, "{s}{s}{s} {s}\n", .{ level.color(), level.toString(), reset, message }).len; |
| 311 | | - } else { |
| 312 | | - output_len = formatTruncating(&output_buf, "{s} {s}\n", .{ level.toString(), message }).len; |
| 313 | | - } |
| 322 | + output_len = formatTruncating(&output_buf, "{s} {s}\n", .{ level.toString(), message }).len; |
| 314 | 323 | } |
| 315 | 324 | |
| 316 | 325 | const output = output_buf[0..output_len]; |
| 317 | 326 | |
| 327 | + // Colour is formatted separately, for stderr only. |
| 328 | + // |
| 329 | + // Both sinks used to receive the same bytes, so a run with `--log-file` |
| 330 | + // either put ANSI escapes in the file or — the workaround this replaces — |
| 331 | + // turned colour off for the terminal as well, to keep the file clean. A |
| 332 | + // log file full of `\x1b[2m` is unreadable to `grep`, and a terminal that |
| 333 | + // loses its colours because a file was requested is a strange trade. |
| 334 | + // |
| 335 | + // Only when stderr is a terminal, decided once at `init` rather than per |
| 336 | + // record: colour written into a redirected stderr is the same problem as |
| 337 | + // colour written into the file. |
| 338 | + var colour_buf: [4096]u8 = undefined; |
| 339 | + var colour_len: usize = 0; |
| 340 | + if (current_config.enable_colors and stderr_is_tty and !current_config.json_output) { |
| 341 | + const reset = "\x1B[0m"; |
| 342 | + const dim = "\x1B[2m"; |
| 343 | + colour_len = if (current_config.enable_timestamps) |
| 344 | + formatTruncating(&colour_buf, "{s}[{s}]{s} {s}{s}{s} {s}\n", .{ dim, timestamp, reset, level.color(), level.toString(), reset, message }).len |
| 345 | + else |
| 346 | + formatTruncating(&colour_buf, "{s}{s}{s} {s}\n", .{ level.color(), level.toString(), reset, message }).len; |
| 347 | + } |
| 348 | + |
| 318 | 349 | const io = log_io orelse io_context.get(); |
| 319 | 350 | |
| 320 | 351 | if (current_config.mirror_to_stderr) { |
| 321 | | - _ = std.Io.File.stderr().writeStreamingAll(io, output) catch {}; |
| 352 | + const for_stderr = if (colour_len > 0) colour_buf[0..colour_len] else output; |
| 353 | + _ = std.Io.File.stderr().writeStreamingAll(io, for_stderr) catch {}; |
| 322 | 354 | } |
| 323 | 355 | |
| 324 | 356 | // Appended at the tracked offset. `writeStreamingAll` writes from position |
| @@ -661,3 +693,72 @@ test "logging from inside logging drops the inner record instead of hanging" { |
| 661 | 693 | resetInLogForTesting(); |
| 662 | 694 | try testing.expect(!in_log); |
| 663 | 695 | } |
| 696 | + |
| 697 | +test "off silences every level" { |
| 698 | + // `logging.zig` has always had an `off`; this side had no way to say the |
| 699 | + // same thing, so an app that wanted quiet had to not configure logging at |
| 700 | + // all — which is not the same as asking for it. |
| 701 | + const io = io_context.get(); |
| 702 | + const path = "craft-log-off-test.txt"; |
| 703 | + std.Io.Dir.cwd().deleteFile(io, path) catch {}; |
| 704 | + defer std.Io.Dir.cwd().deleteFile(io, path) catch {}; |
| 705 | + |
| 706 | + try init(.{ .output_file = path, .min_level = .Off, .mirror_to_stderr = false }); |
| 707 | + log(.Debug, "no", .{}); |
| 708 | + log(.Info, "no", .{}); |
| 709 | + log(.Warning, "no", .{}); |
| 710 | + log(.Error, "no", .{}); |
| 711 | + log(.Fatal, "not even this", .{}); |
| 712 | + deinit(); |
| 713 | + |
| 714 | + var read_buf: [256]u8 = undefined; |
| 715 | + const file = try std.Io.Dir.cwd().openFile(io, path, .{}); |
| 716 | + defer file.close(io); |
| 717 | + const n = try file.readPositionalAll(io, &read_buf, 0); |
| 718 | + try testing.expectEqual(@as(usize, 0), n); |
| 719 | +} |
| 720 | + |
| 721 | +test "off is the highest level, so the ordering check silences by itself" { |
| 722 | + // Placed last in the enum on purpose: `level >= min_level` then does the |
| 723 | + // work and no other branch has to know the concept exists. |
| 724 | + const values = std.enums.values(LogLevel); |
| 725 | + try testing.expectEqual(LogLevel.Off, values[values.len - 1]); |
| 726 | + for (values) |level| { |
| 727 | + if (level == .Off) continue; |
| 728 | + try testing.expect(@backingInt(level) < @backingInt(LogLevel.Off)); |
| 729 | + } |
| 730 | +} |
| 731 | + |
| 732 | +test "the file never receives colour, even when the terminal is getting it" { |
| 733 | + // Both sinks used to be handed the same bytes, so a run with --log-file |
| 734 | + // either wrote ANSI escapes into the file or turned colour off for the |
| 735 | + // terminal too. A log full of \x1b[2m is unreadable to grep. |
| 736 | + // |
| 737 | + // `stderr_is_tty` is forced, because a test process is piped and would |
| 738 | + // otherwise produce no coloured line at all — the first version of this |
| 739 | + // test passed against a deliberately reverted fix for exactly that reason. |
| 740 | + const io = io_context.get(); |
| 741 | + const path = "craft-log-colour-test.txt"; |
| 742 | + std.Io.Dir.cwd().deleteFile(io, path) catch {}; |
| 743 | + defer std.Io.Dir.cwd().deleteFile(io, path) catch {}; |
| 744 | + |
| 745 | + try init(.{ |
| 746 | + .output_file = path, |
| 747 | + .min_level = .Debug, |
| 748 | + .enable_colors = true, // asked for, and still must not reach the file |
| 749 | + .mirror_to_stderr = false, |
| 750 | + }); |
| 751 | + stderr_is_tty = true; // after init, which computes it |
| 752 | + defer stderr_is_tty = false; |
| 753 | + log(.Error, "a red line on a terminal", .{}); |
| 754 | + deinit(); |
| 755 | + |
| 756 | + var read_buf: [1024]u8 = undefined; |
| 757 | + const file = try std.Io.Dir.cwd().openFile(io, path, .{}); |
| 758 | + defer file.close(io); |
| 759 | + const n = try file.readPositionalAll(io, &read_buf, 0); |
| 760 | + const contents = read_buf[0..n]; |
| 761 | + |
| 762 | + try testing.expect(std.mem.indexOf(u8, contents, "a red line on a terminal") != null); |
| 763 | + try testing.expect(std.mem.indexOfScalar(u8, contents, 0x1B) == null); |
| 764 | +} |